Closed Benigans closed 1 year ago
Could you please paste the logs with their history and with their aftermath?
I don't have more than what's next :
[10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Launched child bridge with PID 1229620 [10/15/2023, 2:50:43 PM] Registering platform 'homebridge-midea-platform.midea' [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Loaded homebridge-midea-platform v0.3.1 child bridge successfully [10/15/2023, 2:50:43 PM] Loaded 1 cached accessories from cachedAccessories.0E1FBC8C05E1. [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Force login is set to false [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Verbose debug logging is set to true [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Device refresh interval set to 30 seconds [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Socket heartbeat interval set to 10 seconds [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Socket heartbeat interval set to 10 seconds [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Loading accessory from cache: Déshumidificateur [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] Start device discovery... [10/15/2023, 2:50:43 PM] [homebridge-midea-platform] [midea] Send discover for user configured device: Déshumidificateur (IP: 192.168.1.238) [10/15/2023, 2:50:43 PM] Homebridge v1.6.1 (HAP v0.11.1) (homebridge-midea-platform) is running on port 39017. [10/15/2023, 2:50:46 PM] [homebridge-midea-platform] Discovered device: {"ip":"192.168.1.238","port":6444,"id":*****,"model":"00000Q19","sn":"*****","name":"net_a1_817A","type":161,"version":3} [10/15/2023, 2:50:46 PM] [homebridge-midea-platform] Restoring existing accessory from cache: Déshumidificateur [10/15/2023, 2:50:46 PM] [homebridge-midea-platform] [Déshumidificateur] Cached device, using saved credentials [10/15/2023, 2:50:46 PM] [homebridge-midea-platform] Starting network listener for [Déshumidificateur] [10/15/2023, 2:50:49 PM] [homebridge-midea-platform] [Déshumidificateur] Status change: {"POWER":false,"CHILD_LOCK":false,"MODE":1,"FAN_SPEED":80,"SWING":false,"TARGET_HUMIDITY":60,"TANK_LEVEL":0,"WATER_LEVEL_SET":0,"CURRENT_HUMIDITY":69,"CURRENT_TEMPERATURE":17,"TANK_FULL":true} [10/15/2023, 2:50:58 PM] [homebridge-midea-platform] Device discovery complete after 4 network broadcasts. [10/15/2023, 2:52:47 PM] [homebridge-midea-platform] [2023-10-15, 12:52:47] [homebridge-midea-platform] Socket error: Error: read ECONNRESET at TCP.onStreamRead (node:internal/stream_base_commons:217:20) [10/15/2023, 2:52:47 PM] [homebridge-midea-platform] [Déshumidificateur | run] Error reading from socket: Error: read ECONNRESET at TCP.onStreamRead (node:internal/stream_base_commons:217:20) [2023-10-15, 12:52:47] [homebridge-midea-platform] Socket closed with error [10/15/2023, 2:52:50 PM] [homebridge-midea-platform] [Déshumidificateur] Does not supports the protocol MessageQuerySubtype, ignored, error: Error: [Déshumidificateur | refresh_status] Error when receiving data from device.
Juste after a reboot. But the dehumidifier is working. And the last 3 errors repeats.
If you need more, tell me how. I set verbose to true but I don't see more :(
You need to start your Homebridge instance with the debug flag to be able to see more messages. From the GUI, you can enable it from Settings -> Startup options submenu -> DEBUG
.
By the way the first two errors you sent are related and can be ignored. It should be a warning instead an error. The third error is also normal. There are different ways to communicate with a Midea device and the plugin tries a few of them. If your device does not support that type of message then an error will occur. The same can be applied as in the previous case: it should be a warning, not an error.
@Benigans First of all, THANK YOU for installing and testing. @kovapatrik summarized it well, and we can learn from your testing. I have some questions.
You are correct that the plugin should function even if your router is blocking internet access for either or both the dehumidifier and the system the plugin is running on (assuming you ran it once with both unblocked).
Also, @kovapatrik I wonder if there is a way to not log an error if we have already logged it.
Also, @kovapatrik I wonder if there is a way to not log an error if we have already logged it.
I don't think there is a way to do it.
@Benigans First of all, THANK YOU for installing and testing. @kovapatrik summarized it well, and we can learn from your testing. I have some questions.
1. Is this the full log of [homebridge-midea-platform], that is, you didn't remove anything (from this plugin) between 2:50:58 PM and 2:52:47 PM? If that is the case then the plugin was happy for almost 2 minutes and then the socket was reset. It would be good to try and find out why. Running with debug on may help. 2. Does the plugin continue to function? It should recover, but I don't see anything in the log to confirm that. Can you still control the dehumidifier from HomeKit? (@kovapatrik we should "upgrade" the debug log [here](https://github.com/dkerr64/homebridge-midea-platform/blob/e763022ecb22db15a4b42a3d8610ec47a9808566/src/core/MideaDevice.ts#L437) to a info) 3. Does this repeat... if you leave the plugin running does it regularly issue these messages?
You are correct that the plugin should function even if your router is blocking internet access for either or both the dehumidifier and the system the plugin is running on (assuming you ran it once with both unblocked).
Also, @kovapatrik I wonder if there is a way to not log an error if we have already logged it.
Hi ! Sorry, can't answer sooner...
1 - Yes it was the full log (without the verbose of homebridge - comming next). Didn't touch anything, juste watching the logs 2 - Yes it works after that. I can power it on, off, set a value etc... no problem. Maybe just a slight delay when trying to power it on after the errors. But I can't be sure it's linked. Need more testing 3 - Yes it repeats regularly after that. But as soon as I allow the device to access internet there is no errors. Maybe it's a coincidence but i tried 2 times and it was the same.
This plugin is more stable than the others so it's still a win for me ^^ Thx for the great work !
Here are the midea logs with homebridge verbose. Dehumidifier connected for a few hours, powered off :
[10/15/2023, 9:43:11 PM] [homebridge-midea-platform] Sending discovery message to 192.168.1.238, try 1... [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] Sending discovery message to 192.168.1.255, try 1... [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] Discovered device: {"ip":"192.168.1.238","port":6444,"id":*****,"model":"00000Q19","sn":"*****","name":"net_a1_817A","type":161,"version":3} [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] Restoring existing accessory from cache: Déshumidificateur [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] [Déshumidificateur] Cached device, using saved credentials [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] Connecting to device Déshumidificateur (192.168.1.238:6444)... [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] [Déshumidificateur] Authentication success. [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] Starting network listener for [Déshumidificateur] [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] [Déshumidificateur] Refreshing status... [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:11 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] Sending discovery message to 192.168.1.255, try 2... [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Decrypted data to parse: [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Body: [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for POWER changed from 'undefined' to 'false' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for CHILD_LOCK changed from 'undefined' to 'false' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for MODE changed from '99' to '1' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for FAN_SPEED changed from '999' to '80' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for SWING changed from 'undefined' to 'false' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for TARGET_HUMIDITY changed from '999' to '60' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for TANK_LEVEL changed from '999' to '0' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for WATER_LEVEL_SET changed from '999' to '0' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for CURRENT_HUMIDITY changed from '999' to '69' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for CURRENT_TEMPERATURE changed from '999' to '17' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Value for TANK_FULL changed from 'undefined' to 'true' [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Status change: {"POWER":false,"CHILD_LOCK":false,"MODE":1,"FAN_SPEED":80,"SWING":false,"TARGET_HUMIDITY":60,"TANK_LEVEL":0,"WATER_LEVEL_SET":0,"CURRENT_HUMIDITY":69,"CURRENT_TEMPERATURE":17,"TANK_FULL":true} [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute POWER to: false [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute CHILD_LOCK to: false [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute MODE to: 1 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute FAN_SPEED to: 80 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute SWING to: false [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute TARGET_HUMIDITY to: 60 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute TANK_LEVEL to: 0 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute WATER_LEVEL_SET to: 0 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute CURRENT_HUMIDITY to: 69 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute CURRENT_TEMPERATURE to: 17 [10/15/2023, 9:43:14 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute TANK_FULL to: true [10/15/2023, 9:43:17 PM] [homebridge-midea-platform] Sending discovery message to 192.168.1.255, try 3... [10/15/2023, 9:43:20 PM] [homebridge-midea-platform] Sending discovery message to 192.168.1.255, try 4... [10/15/2023, 9:43:23 PM] [homebridge-midea-platform] Device discovery complete after 4 network broadcasts. [10/15/2023, 9:43:23 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:26 PM] [homebridge-midea-platform] [2023-10-15, 19:43:26] [homebridge-midea-platform] Socket error: [10/15/2023, 9:43:26 PM] [homebridge-midea-platform] [Déshumidificateur | run] Error reading from socket: [2023-10-15, 19:43:26] [homebridge-midea-platform] Socket closed with error [10/15/2023, 9:43:26 PM] [homebridge-midea-platform] Create new socket, reconnect [10/15/2023, 9:43:26 PM] [homebridge-midea-platform] Connecting to device Déshumidificateur (192.168.1.238:6444)... [10/15/2023, 9:43:27 PM] [homebridge-midea-platform] [Déshumidificateur] Authentication success. [10/15/2023, 9:43:27 PM] [homebridge-midea-platform] [Déshumidificateur] Refreshing status... [10/15/2023, 9:43:27 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Does not supports the protocol MessageQuerySubtype, ignored, error: Error: [Déshumidificateur | refresh_status] Error when receiving data from device. [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Decrypted data to parse: [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Body: [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Value for CURRENT_HUMIDITY changed from '69' to '68' [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Status change: {"CURRENT_HUMIDITY":68} [10/15/2023, 9:43:30 PM] [homebridge-midea-platform] [Déshumidificateur] Set attribute CURRENT_HUMIDITY to: 68 [10/15/2023, 9:43:47 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:47 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:43:47 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:43:59 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:43:59 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:43:59 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:44:05 PM] [homebridge-midea-platform] [Déshumidificateur] Refreshing status... [10/15/2023, 9:44:05 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:05 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:08 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:44:08 PM] [homebridge-midea-platform] [Déshumidificateur] Decrypted data to parse: [10/15/2023, 9:44:08 PM] [homebridge-midea-platform] [Déshumidificateur] Body: [10/15/2023, 9:44:08 PM] [homebridge-midea-platform] [Déshumidificateur] Status unchanged [10/15/2023, 9:44:11 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:11 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:44:11 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:44:23 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:23 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:44:23 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:44:35 PM] [homebridge-midea-platform] [Déshumidificateur] Refreshing status... [10/15/2023, 9:44:35 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:35 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Decrypted data to parse: [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Body: [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Status unchanged [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:44:38 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:44:50 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:44:50 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:44:50 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:45:02 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:02 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:02 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:45:05 PM] [homebridge-midea-platform] [Déshumidificateur] Refreshing status... [10/15/2023, 9:45:05 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:05 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:08 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:08 PM] [homebridge-midea-platform] [Déshumidificateur] Decrypted data to parse: [10/15/2023, 9:45:08 PM] [homebridge-midea-platform] [Déshumidificateur] Body: [10/15/2023, 9:45:08 PM] [homebridge-midea-platform] [Déshumidificateur] Status unchanged [10/15/2023, 9:45:14 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:14 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:14 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:45:26 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:26 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:26 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:45:35 PM] [homebridge-midea-platform] [Déshumidificateur] Refreshing status... [10/15/2023, 9:45:35 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:35 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Decrypted data to parse: [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Body: [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Status unchanged [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:38 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat: [10/15/2023, 9:45:50 PM] [homebridge-midea-platform] [Déshumidificateur] Send message: [10/15/2023, 9:45:50 PM] [homebridge-midea-platform] [Déshumidificateur] Raw data to parse: [10/15/2023, 9:45:50 PM] [homebridge-midea-platform] [Déshumidificateur] Heartbeat:
I have blocked my dehumidifier from accessing the internet but am not able to reproduce your problem. Do you block just the dehumidifier or also the server running homebridge?
For the debug log, can you please download it (click on the down arrow icon next to the trash can icon at top right of Homebridge logs window) and attach the TXT file please rather than copy/paste the log. It looks like some data is missing.
Also, in the log you sent I only see once instance of the error at 9:43:26, it recovers within a second and then does not repeat before your log ends at 9:45:50.
ok, ignore my last comment. I did not correctly block my dehumidifier in my router. I have now blocked it and I am able to reproduce the problem... so I can now try and debug the issue.
Thanks.
Same with the my AC (although it's not suprising)
I have been looking at this for a couple of hours. The Midea device is closing the connection approximately every 3 minutes. I cannot see any logic to it... It is independent of heartbeats or refresh status. It just closes the connection. However, our plugin recovers nicely.
Given that recovery works well, and that this is likely an uncommon scenario (explicitly blocking the device at a router), I am inclined to recommend shielding the alarming warning messages behind a test for verbose logging. With this there is only an occasional "Create new socket, reconnect" message to log.
I did add/refine some of our debug logging which I will push if I can just get lint to pass!!!
Of course the problem with suppressing the log messages by default is that we may miss real problems that other users run into. I think we should define a config setting logRecoverableErrors
that defaults to true. Any user that has the problem documented here can then choose to suppress the logging by setting this to false.
Of course the problem with suppressing the log messages by default is that we may miss real problems that other users run into. I think we should define a config setting
logRecoverableErrors
that defaults to true. Any user that has the problem documented here can then choose to suppress the logging by setting this to false.
I think no user will actively watching the logs when it's working as expected. I think it can be hidden, but if you think we must create an other flag for this, we can do that too.
I have another idea but I didn't have the time currently to tinker with it. With Wireshark and a "monitor mode" compatible WiFi adapter it's possible to sniff on the network traffic. It could be checked if the device try to connect to some website. I don't know if it would help us, but it can be interesting. Maybe blocking that URL will solve this problem...
Of course the problem with suppressing the log messages by default is that we may miss real problems that other users run into. I think we should define a config setting
logRecoverableErrors
that defaults to true. Any user that has the problem documented here can then choose to suppress the logging by setting this to false.I think no user will actively watching the logs when it's working as expected. I think it can be hidden, but if you think we must create an other flag for this, we can do that too.
Thinking about it. More flags are not necessarily a good thing. But missing possible errors is also not a good thing.
@Benigans we just published an update to the plugin with fairly significant changes. Can you test if for us please and report back. Note that you will have to use the settings user interface window to find your devices, save and restart. The existing settings in config.json will not be used and can be deleted.
Describe The Bug:
I installed the plugin today to use with my dehumidifier. Working great for now but in homebridge logs i see those 3 errors every refresh : [homebridge-midea-platform] [Déshumidificateur | run] Error reading from socket: Error: read ECONNRESET at TCP.onStreamRead (node:internal/stream_base_commons:217:20)
[homebridge-midea-platform] Socket closed with error
[homebridge-midea-platform] [Déshumidificateur] Does not supports the protocol MessageQuerySubtype, ignored, error: Error: [Déshumidificateur | refresh_status] Error when receiving data from device.
One thing to note, I block internet access to my dehumidifier with my router. I juste opened it once for the initial setup of the plugin (using nethomeplus login), I put the IP adress in the config, launch once and after testing that it's ok, i blocked internet access on my router. Control still working without internet access in homekit, so that's not a big deal.
To Reproduce:
Configure plugin with nethomeplus login and IP address. Block internet access to dehumidifier, errors popping.
Expected behavior:
No errors when controlling only in LAN
Logs:
Plugin Config:
Environment: