banban525 / echonetlite2mqtt

ECHONET Lite to MQTT bridge.
MIT License
48 stars 7 forks source link

ECHONET Lite communication waits for the response of the previous command before sending the next command. #22

Closed banban525 closed 1 year ago

banban525 commented 1 year ago

Currently, EchonetLite2mqtt always sends commands at regular intervals using echonet-lite.js methods.

But there's a problem:

These issues are reported in #9 #18 #21.

banban525 commented 1 year ago

I think the problem can be solved by turning off the echonet-lite.js function and communicating independently.

In my experiments, Echonetelite2mqtt is able to reliably receive responses to commands. Device detection is also now more than twice as fast.

Since this is a major change, I am worried about backward bugs and loss of compatibility.

aftertommy commented 1 year ago

i’d be glad to test something if you decide to make the change. iPhoneから送信2023/10/10 8:22、banban @.***>のメール: I think the problem can be solved by turning off the echonet-lite.js function and communicating independently. In my experiments, Echonetelite2mqtt is able to reliably receive responses to commands. Device detection is also now more than twice as fast. Since this is a major change, I am worried about backward bugs and loss of compatibility.

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you are subscribed to this thread.Message ID: @.***>

banban525 commented 1 year ago

@aftertommy

The prototype for this feature is ready. In my environment it has been working fine for 3 days.

I remember that you needed TAG to use ECHONETLite2MQTT.

I created a tag "v2.4.0-alpha", could you please test it?

aftertommy commented 1 year ago

absolutely! thanks!2023/10/27 0:44、banban @.***>のメール: @aftertommy The prototype for this feature is ready. In my environment it has been working fine for 3 days. I remember that you needed TAG to use ECHONETLite2MQTT. I created a tag "v2.4.0-alpha", could you please test it?

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you were mentioned.Message ID: @.***>

grandevice commented 1 year ago

I'm always looking forward to the wonderful evolution.

The recognition of Panasonic lighting via converter is very fast.

I tried to update it after a long time,

The air conditioner has become unrecognizable all over the place.

I can't recognize EcoCute either, so I can't seem to see panasonic CF-TC7B or lower. I tried the timer from 100ms to 3000ms, but it was annihilated.

Are there any countermeasures?

grandevice commented 1 year ago

I don't know if it will be helpful, but the following logs are recorded 3 times every 3 minutes.

[ECHONETLite] prop changed: CF-TC7B_node DEL 0280d5

banban525 commented 1 year ago

@grandevice

This feature was a big change, so I was concerned about compatibility. It worked fine in my environment, but it may not work on some devices.

If possible, please attach internal logs. You can download the logs using the link at the bottom of the "Logs" page.

If you want to revert to the previous version, please use tag "v2.3.0".

Now, "latest" tag in Docker Hub has been updated to "v2.4.0-alpha". This is my mistake. I will change the "latest" tag back to "v2.3.0" tag.

banban525 commented 1 year ago

@grandevice

I don't know if it will be helpful, but the following logs are recorded 3 times every 3 minutes. [ECHONETLite] prop changed: CF-TC7B_node DEL 0280d5

This log seems to be receiving INF from "CF-TC7B_node". "DEL" seems to be a name given to an unused property. I think it's probably a property list in "Node Profile".

With this information, I don't know the cause. I would like internal logs if possible.

grandevice commented 1 year ago

I'm ashamed to say that I can't find the link to the log page.

At the bottom is only the string of ECHONETLite2MQTT ver2.0.0.

banban525 commented 1 year ago

@grandevice

Log download feature is available after v.2.0.1. Perhaps you reverted EchonetLite2mqtt to a version that was working properly.

I wanted logs running with docker's v2.4.0-alpha tag or master tag. If you can't do it now, do it at your convenience.

grandevice commented 1 year ago

As long as I check the version, it seems to be 2.3.0, but I can't find the log link.

grandevice commented 1 year ago

sorry i use node.js now

banban525 commented 1 year ago

@grandevice

If you are using v.2.0.1 or higher, there should be a link on the Log page for "Donwload Logs and internal statues for debug." If it display "ver.2.0.0" then I think you are using old code.

image

banban525 commented 1 year ago

@grandevice @aftertommy

I made a new alpha version. git tag: v2.4.0-alpha.3 docker tag: v2.4.0-alpha.3 or master

Since the command response checking rules have been changed, devices that could not be detected last time may become normal.

grandevice commented 1 year ago

error: uncaughtException: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#". UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#".

When accessing from apple home using homebridge-mqtthing with v2.4.0-alpha3, it stopped with the error mentioned above.

environment: raspberry pi 4 bookworm 64bit node.js 20.9.0

Also, when operating the electronic lock via HF-JA1-W from Echonetlite2mqtt, the Current State was no longer updated automatically. It will be updated upon request.

banban525 commented 1 year ago

@grandevice

Thank you for your report.

However, this error alone does not reveal the cause. If possible, could you please send me the logs?

You can't find the log page link, right? Can't you attach the "logs" folder in "echonetlite2mqtt" folder instead?

This may be caused by Node.js ver.20.9.0. My environment is Node.js ver.14.21.3 and Node.js ver.16.20.2. I will check if the same problem occurs with ver.20.9.0.

grandevice commented 1 year ago

Thank you for your reply. In the end, the environment was corrupted, so I replaced it with bullseye and set Node.js to v16.20.2, but the result did not change.

I can operate the electric lock connected to HF-JA with Echonetlite2MQTT v2.3.0, but the status remains unchanged.

I tried v.2.0.0-v.2.3.0, but the result was the same. The status of air conditioners, eco-cutes, and lighting will be changed immediately.

I have attached the log. thank you.

echonetlite2mqtt_logs_internalsStatus (3).zip

banban525 commented 1 year ago

@grandevice

thank you for your reply.

The device in question is "Id: fe00000b000005fd014c364effecefc68" that you were operating on 2023-11-05 23:39 (JST), right? I think this is a Panasonic switch.

{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\tfalse","timestamp":"2023-11-05T14:39:27.284Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus false","timestamp":"2023-11-05T14:39:27.287Z"}
{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\tfalse","timestamp":"2023-11-05T14:39:37.304Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus false","timestamp":"2023-11-05T14:39:37.306Z"}
{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\ttrue","timestamp":"2023-11-05T14:39:41.271Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus true","timestamp":"2023-11-05T14:39:41.273Z"}
{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\tfalse","timestamp":"2023-11-05T14:39:50.601Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus false","timestamp":"2023-11-05T14:39:50.603Z"}
{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\ttrue","timestamp":"2023-11-05T14:39:57.373Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus true","timestamp":"2023-11-05T14:39:57.374Z"}
{"category":"[RESTAPI]","level":"info","message":"request property: fe00000b000005fd014c364efffecefc68\toperationStatus","timestamp":"2023-11-05T14:40:00.838Z"}
{"level":"info","message":"[RESTAPI]     prop reuqest: fe00000b000005fd014c364efffecefc68 operationStatus","timestamp":"2023-11-05T14:40:00.839Z"}
{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\tfalse","timestamp":"2023-11-05T14:40:06.205Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus false","timestamp":"2023-11-05T14:40:06.207Z"}
{"category":"[RESTAPI]","level":"info","message":"request property: fe00000b000005fd014c364efffecefc68\toperationStatus","timestamp":"2023-11-05T14:40:09.648Z"}
{"level":"info","message":"[RESTAPI]     prop reuqest: fe00000b000005fd014c364efffecefc68 operationStatus","timestamp":"2023-11-05T14:40:09.649Z"}
{"level":"info","message":"[ECHONETLite] prop changed: fe00000b000005fd014c364efffecefc68 operationStatus false","timestamp":"2023-11-05T14:40:09.955Z"}
{"category":"[RESTAPI]","level":"info","message":"put property: fe00000b000005fd014c364efffecefc68\toperationStatus\ttrue","timestamp":"2023-11-05T14:40:12.971Z"}
{"level":"info","message":"[RESTAPI]     prop changed: fe00000b000005fd014c364efffecefc68 operationStatus true","timestamp":"2023-11-05T14:40:12.973Z"}
{"category":"[RESTAPI]","level":"info","message":"request property: fe00000b000005fd014c364efffecefc68\toperationStatus","timestamp":"2023-11-05T14:40:18.032Z"}
{"level":"info","message":"[RESTAPI]     prop reuqest: fe00000b000005fd014c364efffecefc68 operationStatus","timestamp":"2023-11-05T14:40:18.033Z"}
{"level":"info","message":"[ECHONETLite] prop changed: fe00000b000005fd014c364efffecefc68 operationStatus true","timestamp":"2023-11-05T14:40:18.339Z"}

There are two possible causes.

First cause:

ECHONETLite2MQTT is getting the properties immediately after sending the command. Maybe this device doesn't change oerationStatus immediately after receiving the command. It seems to be resolved by waiting a while after sending the command and then obtaining oerationStatus. But, ECHONETLite2MQTT does not have that feature.

Second cause:

Maybe ECHONETLite2MQTT is not receiving all notifications from all devices. The oerationStatus of this Id:fe00000b000005fd014c364efffecefc68 has notification enabled. This means that when you turn ON/OFF on a physical switch, the switch will be notified of the oerationStatus.

For example, when you turn on the air conditioner with the remote control, does the oerationStatus in ECHONETLite2MQTT change automatically?

If ECHONETLite2MQTT is not receiving notifications for all devices, something is probably wrong. Could you please try the command options below?

"--echonetAltMultiNicMode 1"

banban525 commented 1 year ago

@grandevice

error: uncaughtException: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#". UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "#".

When accessing from apple home using homebridge-mqtthing with v2.4.0-alpha3, it stopped with the error mentioned above.

Did this problem improve after you recreated the environment? I tested with Node.js ver.20.9.0 and this error did not occur. So I believe this error was a problem in your environment.

grandevice commented 1 year ago

It was all my mistake.

The reason was that the POE hub I bought again had an IGMPsnooping function. I didn't check the specifications as if I bought a successor, and I didn't notice it at all because it was an unmanaged hub.

I'm sorry to have caused you so much trouble.

I bought it again on Managed Plus Hub, turned off igmp sopping, and there was no problem at all.

I would like to say that, but there is no error in 2.4.0aplha3, and 2.3.0 is currently operating normally.

I'm looking forward to 3.0.0.

banban525 commented 1 year ago

@grandevice

Thank you for your report.

I was relieved because there was no problem with ver.2.4.0aplha3.

I am currently implementing ver.3.0.0. I think it will be completed in about 2-3 weeks.

banban525 commented 1 year ago

This feature was implemented in v3.0.0.

aftertommy commented 1 year ago

i’m sorry for not testing this yet! it gets crazy around the holidays and it’s been hard to carve out time. looking forward to upgrading and checking out the new release!