search

krahabb / meross_lan

Home Assistant integration for Meross devices
MIT License
454 stars 47 forks source link

Meross Hub MSH300HK #262

Closed KiraPC closed 1 year ago

KiraPC commented 1 year ago

Version of the custom_component

v3.0.2

Describe the bug

I used this component for 2 weeks without problems.

Now, since 2days, I'm facing continuous disconnecting of my meross hub that I use for my Term Valve.

Basically, them become unavailable intermittently.

Screenshot 2023-02-20 alle 09 38 10

Some logs:

2023-02-20 07:35:47.557 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2570494592): HTTP Request ({"header": {"messageId": "7f42df20786d4742ac201d256a08539c", "namespace": "Appliance.Hub.Mts100.ScheduleB", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676878547, "timestampMs": 0, "sign": "983cba2de6ae3fc80a8b880df42684d7"}, "payload": {"schedule": []}})
2023-02-20 07:35:47.588 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2570494592): HTTP Response ({"header":{"messageId":"7f42df20786d4742ac201d256a08539c","namespace":"Appliance.Hub.Mts100.ScheduleB","method":"GETACK","payloadVersion":1,"from":"/appliance/2108312483296526281348e1e974dc05/publish","timestamp":1676878537,"timestampMs":747,"sign":"e5d731f381c1916967552d3af106ba56"},"payload":{"schedule":[{"id":"0300FA00","mon":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"tue":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"wed":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"thu":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"fri":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"sat":[[390,200],[90,250],[300,250],[300,100],[240,250],[120,200]],"sun":[[390,200],[90,250],[300,250],[300,100],[240,250],[120,200]]},{"id":"0300E2E7","mon":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"tue":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"wed":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"thu":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"fri":[[390,200],[90,250],[300,100],[300,100],[240,250],[120,200]],"sat":[[390,200],[90,250],[300,250],[300,100],[240,250],[120,200]],"sun":[[390,200],[90,250],[300,250],[300,100],[240,250],[120,200]]},{"id":"0100442C","mon":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]],"tue":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]],"wed":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]],"thu":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]],"fri":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]],"sat":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]],"sun":[[50,200],[50,200],[50,200],[150,200],[150,200],[990,180]]}]}}
)
2023-02-20 07:35:47.590 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-20 07:37:17.591 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-20 07:37:17.591 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2582192368): HTTP Request ({"header": {"messageId": "3784128582564bdbb0bee7649f24c60d", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676878637, "timestampMs": 0, "sign": "2ae0db1c2c031d387566155a43c9d885"}, "payload": {"all": {}}})
2023-02-20 07:37:32.597 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2582192368): HTTP TimeoutError ()
2023-02-20 07:37:32.598 INFO (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) TimeoutError() in async_http_request 0 GET attempt(Appliance.System.All)
2023-02-20 07:37:32.598 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) going offline!
2023-02-20 07:37:32.628 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-20 07:38:02.628 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start

Could you help me?

krahabb commented 1 year ago

It looks like the error is very 'repeatable' every 5 minutes so this is likely something which could be fixed. I'd need a more comprehensive log by the way to better understand it. I fthe device is still behaving like this (disconnected every 5 minutes) please configure the device for tracing and upload the results so I can have a read. At the moment I can't really figure out the issue: maybe a recent firmware update for the msh300 ? some new addition on the LAN? The HTTP timeout should really be the device itself is 'stalling' while trying to reply bubt the fact it started 2 days ago should really be related to something happening since then

KiraPC commented 1 year ago

Thanks fo reply.

I thinks somethings happend on last friday.

The morning, the Hub was completely disconnected everywhere, included meross app. It had the leg blinking green red and I need to pair it (and all the valves) again.

It is one year I have them, never an issue.

Anyway, after this moment, I figured this issue on HA.

Yesterday I restarted the hub and change ip adress setting fixed by router, and was working without issue 'till this morning.

I have some trace file from yesterday. msh300hk-1676813526.csv msh300hk-1676851996.csv

KiraPC commented 1 year ago

Hi @krahabb I have updates.

Its from 6h the hub is disconnected from the component.

Here some logs:

2023-02-21 07:44:40.169 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 07:44:40.171 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2593975664): HTTP Request ({"header": {"messageId": "7b43a6119d9a4e36a5bb30003d868fd6", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676965480, "timestampMs": 0, "sign": "9f45cddb7c4b493fede0a5a828048d14"}, "payload": {"all": {}}})
2023-02-21 07:44:40.185 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2593975664): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 07:44:40.186 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 07:49:40.186 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 07:49:40.187 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2569872200): HTTP Request ({"header": {"messageId": "0eeba9990ef843e78026bb215ef267c6", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676965780, "timestampMs": 0, "sign": "e391d469ee698bbc34510ca43d7de6f4"}, "payload": {"all": {}}})
2023-02-21 07:49:40.218 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2569872200): HTTP ClientOSError ([Errno 104] Connection reset by peer)
2023-02-21 07:49:40.219 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 07:54:40.221 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 07:54:40.223 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2587337424): HTTP Request ({"header": {"messageId": "d9df2af5a01540b6a999c16c29e45a5b", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676966080, "timestampMs": 0, "sign": "be4feca0e4d8d9a1a0d0bc6eb67c1921"}, "payload": {"all": {}}})
2023-02-21 07:54:40.238 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2587337424): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 07:54:40.238 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 07:59:40.239 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 07:59:40.240 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2572252336): HTTP Request ({"header": {"messageId": "04ca1af78e8e455cb3222eb0762b62fb", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676966380, "timestampMs": 0, "sign": "f01ac74bf33aca781604e690282137da"}, "payload": {"all": {}}})
2023-02-21 07:59:40.252 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2572252336): HTTP ClientOSError ([Errno 104] Connection reset by peer)
2023-02-21 07:59:40.253 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:04:40.254 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:04:40.255 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2611151648): HTTP Request ({"header": {"messageId": "f4c24e82b1454b9e9d9a045be6db79cf", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676966680, "timestampMs": 0, "sign": "837aeea1bb35340364c991aad2e742c9"}, "payload": {"all": {}}})
2023-02-21 08:04:40.270 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2611151648): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:04:40.270 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:09:40.271 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:09:40.272 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2607966240): HTTP Request ({"header": {"messageId": "bbefa461ccf14980ac16631138a7e5d0", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676966980, "timestampMs": 0, "sign": "4169f8d651b53efed2c5df3045f88628"}, "payload": {"all": {}}})
2023-02-21 08:09:40.292 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2607966240): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:09:40.292 WARNING (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) ServerDisconnectedError(Server disconnected) in async_http_request GET Appliance.System.All
2023-02-21 08:09:40.296 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:14:40.296 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:14:40.297 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2557145032): HTTP Request ({"header": {"messageId": "90863de508134fd9a496adb7bf9e1df9", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676967280, "timestampMs": 0, "sign": "4c8106c0261a5c807ad609cae4bf566f"}, "payload": {"all": {}}})
2023-02-21 08:14:40.313 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2557145032): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:14:40.314 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:19:40.314 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:19:40.315 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2742539680): HTTP Request ({"header": {"messageId": "0e372e181ca24c8786b5617557e48145", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676967580, "timestampMs": 0, "sign": "09277381b0b8b5ca1f3f70a5bad204cf"}, "payload": {"all": {}}})
2023-02-21 08:19:40.331 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2742539680): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:19:40.331 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:24:40.333 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:24:40.334 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2533001328): HTTP Request ({"header": {"messageId": "85d1d9203af14bb8af7086d20b48651d", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676967880, "timestampMs": 0, "sign": "8eb5ac944d9da584d62154de3eb55928"}, "payload": {"all": {}}})
2023-02-21 08:24:40.360 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2533001328): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:24:40.360 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:29:40.361 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:29:40.363 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2587266056): HTTP Request ({"header": {"messageId": "031940693dac4fc780946da9681e66b7", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676968180, "timestampMs": 0, "sign": "37e9028f4241425b40864f62dd089974"}, "payload": {"all": {}}})
2023-02-21 08:29:40.377 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2587266056): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:29:40.377 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:34:40.377 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:34:40.378 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2557928544): HTTP Request ({"header": {"messageId": "0ee86bdfca454078867fedec3affb1dc", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676968480, "timestampMs": 0, "sign": "9a561695cbc508eb9e8bf62855cb35f7"}, "payload": {"all": {}}})
2023-02-21 08:34:40.394 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2557928544): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 08:34:40.395 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end
2023-02-21 08:39:40.396 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 08:39:40.398 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2768633080): HTTP Request ({"header": {"messageId": "cd620512fc4d4abaa85a2fddc9be9567", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676968780, "timestampMs": 0, "sign": "b05ac570a2acc9f612270106b99d2856"}, "payload": {"all": {}}})
2023-02-21 08:39:40.412 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2768633080): HTTP ClientOSError ([Errno 104] Connection reset by peer)
2023-02-21 08:39:40.412 WARNING (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) ClientOSError([Errno 104] Connection reset by peer) in async_http_request GET Appliance.System.All
2023-02-21 08:39:40.415 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end

The fw version (the one reported from the component) of the Hub is 4.5.23.

Now, from the meross app I can see that the hub is disconnected from the network. Is it possible that a lot of this http request make it throttling?

krahabb commented 1 year ago

I don't think the number of requests is making the device throttling since by this log, meross_lan is only trying a connection every 5 minutes (the device went offline and so meross_lan only tries every 5 minutes to see if the device comes up again). When the device is connected the number of requests is a lot higher (every 30 seconds a 'full' rescan involving a lot of messages for hub devices). I suppose the device is maybe stalling internally since the error code reported here means the TCP stack is 'active' on the device but it refuses to accept the connection (out of buffers? I don't know just guessing). Sometimes the 'ServerDisconnectedError' as reported by the python client library happens when the device receives a 'malformed' request due to an unknown message or invalid signature and so closes the connection at the TCP level without further signaling. I guess this is like a security feature implemented in the device where it refuses to process anything which could appear as an 'untrusted request' But I'm not sure this is the case since the 'offending' request in this log is nothing special and usually well managed on every device. Also, the same request worked for your same hub so I don't think meros_lan is now crafting any wrong message structure especially for this basic message request. Even if it's sad to say it could be the hub is malfunctioning of its own. It happened to me too some devices failing in strange ways where they were working sometime and not working some other with no apparent reason. The only fix was their substitution :(

I suggest you to disable the device in HA and try it alone with just the app seeing if it's working in its 'ideal' setup or not. This way we can see if the device is good and meross_lan is failing somehow to query the device.

I've also noticed in the previous traces, the device is not able to manage 'overlapping' requests. meross_lan, before recent 3.x.x versions was even worse in overlapping requests while now they're almost all serialized (except one, which gets rejected in your trace - without any apparent issue since it gets retried and nicely responded in few msec), but it has never been an issue (apparently). Even hubs with many paired subdevices never experienced big troubles for this (or at least I don't have any clear report) Now, I'm going to serialize also this 'last' overlapped request in order to have the code work consistently but I hardly think this would solve the issue

KiraPC commented 1 year ago

mmmm, I'm also supping the issue could be the device.

Anyway, restarting the device the disconnection doesn't appear anymore, but I now that this evening will happen again.

I'll try also to disable meross_lan and check for 2 days the behavior.

I'll keep this 3rd update.

krahabb commented 1 year ago

I suspect the device firmware could have a bug which is 'consuming' its internal RAM so it works fine right after rebooting but then, eventually over time, it'll start suffering more and more of this memory leak (usually that is) and finally it is not able to communicate anymore. In this scenario it could also happen the device would work correctly (or for longer times) without meross_lan since we're not 'stressing' the HTTP software interface

KiraPC commented 1 year ago

Yes, it make sense.

But it's strange I'm the only meross_len user facing this issue.

Do you know a way to dump the hub?

KiraPC commented 1 year ago

@krahabb News.

From HA the devices are unavailble but from meross App I can see them and the smarthub online.

Last logs from moross_lan:

2023-02-21 13:37:28.003 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling start
2023-02-21 13:37:28.004 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2562000008): HTTP Request ({"header": {"messageId": "22c84915959b4d328aae35d403614927", "namespace": "Appliance.System.All", "method": "GET", "payloadVersion": 1, "from": "Meross", "timestamp": 1676986648, "timestampMs": 0, "sign": "5d298de42de117851ae4d13b84990ad8"}, "payload": {"all": {}}})
2023-02-21 13:37:28.017 DEBUG (MainThread) [custom_components.meross_lan] MerossHttpClient(192.168.1.131:2562000008): HTTP ServerDisconnectedError (Server disconnected)
2023-02-21 13:37:28.017 DEBUG (MainThread) [custom_components.meross_lan] MerossDevice(Smart Hub (2108312483296526281348e1e974dc05)) polling end

EDIT: it seems that even if the app shows them as online, triggering them is impossible.

image

KiraPC commented 1 year ago

I think I solved the problem.

It might have been the homebridge integration.

Removing it now are 2 days that the hub is not going in unavailable state.

I'm closing the issue for now.