Debug spam in home assistant log (v0.1.0), and HASS unresponsive

rasssta commented 2 weeks ago

The problem

First, thanks for the new release supporting cloud! :D

After upgrading to v0.1.0 I noticed that my Home Assistant log was spammed by debug info from this integration. After a couple of hours (also, quite quickly after the robot started its mowing) HASS became unresponsive via HTTP(S) so I had to restart it. Haven't had any issues like that in more than a year so it might be related to this integration which is the only one I've updated today.

Should it log so much debug stuff by default?

A little snippet (replaced client id, not sure if it's a secret of any kind):

2024-08-27 20:50:40.632 INFO (Thread-93 (__thread_main)) [linkkit] __on_internal_disconnect enter
2024-08-27 20:50:40.632 ERROR (Thread-93 (__thread_main)) [linkkit] __on_internal_disconnect enter from wrong state:<LinkKitState.CONNECTING: 2>
2024-08-27 20:50:40.633 INFO (Thread-93 (__thread_main)) [linkkit] loop return:7
2024-08-27 20:50:40.635 DEBUG (Thread-3810 (__thread_main)) [Paho] Received CONNACK (0, 0)
2024-08-27 20:50:40.635 INFO (Thread-3810 (__thread_main)) [linkkit] __on_internal_connect
2024-08-27 20:50:40.635 DEBUG (Thread-3810 (__thread_main)) [linkkit] post_message :'on_connect' 
2024-08-27 20:50:40.636 DEBUG (Thread-3810 (__thread_main)) [linkkit] post_message success
2024-08-27 20:50:41.723 DEBUG (Thread-93 (__thread_main)) [Paho] Sending CONNECT (u1, p1, wr0, wq0, wf0, c1, k60) client_id=b'xyz|securemode=2,signmethod=hmacsha1,ext=1,_ss=1,lan=Python,_v=1.2.13,timestamp=1724765223|'

What Mammotion mower are you using?

Yuka

What version of the Mammotion intergration are you using?

v0.1.0

What version of Home Assistant Core are you running?

2024.7.4

rasssta commented 2 weeks ago

Seems like it (semi-)died just when it started mowing.

rasssta commented 2 weeks ago

Additional error, not sure if related:

2024-08-27 21:11:23.998 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved (None)
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1052, in _on_mqtt_message
    await self._handle_mqtt_message(topic, payload)
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1159, in _handle_mqtt_message
    await self._parse_mqtt_response(topic=topic, payload=payload)
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1133, in _parse_mqtt_response
    event = ThingEventMessage.from_dicts(payload)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/data/mqtt/event.py", line 118, in from_dicts
    raise ValueError(f"Unknown identifier: {identifier}")
ValueError: Unknown identifier: device_notification_event

rasssta commented 2 weeks ago

Also, I get thrown out of the mobile app every time I start it. I guess I need to create a unique login for HASS so I don't have the same in HASS and the mobile app?

mikey0000 commented 2 weeks ago

Also, I get thrown out of the mobile app every time I start it. I guess I need to create a unique login for HASS so I don't have the same in HASS and the mobile app?

Correct, you can't use the same account, create a new one and share your mower to it

mikey0000 commented 2 weeks ago

0.1.1 released, now with less log spam and a few other tweaks, give that a go.

driesvandamme commented 2 weeks ago

No luck with 0.1.1

Logger: homeassistant.config_entries Bron: config_entries.py:604 Eerst voorgekomen: 23:14:57 (2 gebeurtenissen) Laatst gelogd: 23:15:59

Error setting up entry Luba-VTZ52E4A for mammotion Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/config_entries.py", line 604, in async_setup result = await component.async_setup_entry(hass, self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/config/custom_components/mammotion/init.py", line 59, in async_setup_entry await mammotion_coordinator.async_setup() File "/config/custom_components/mammotion/coordinator.py", line 109, in async_setup device.cloud().on_ready_callback = lambda: device.cloud().start_sync(0) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ AttributeError: 'NoneType' object has no attribute 'on_ready_callback'

mikey0000 commented 2 weeks ago

Thats odd, that means the setup failed when creating the cloud client, any logs further up from that?

mikey0000 commented 2 weeks ago

Additional error, not sure if related:

2024-08-27 21:11:23.998 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved (None)
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1052, in _on_mqtt_message
    await self._handle_mqtt_message(topic, payload)
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1159, in _handle_mqtt_message
    await self._parse_mqtt_response(topic=topic, payload=payload)
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1133, in _parse_mqtt_response
    event = ThingEventMessage.from_dicts(payload)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/data/mqtt/event.py", line 118, in from_dicts
    raise ValueError(f"Unknown identifier: {identifier}")
ValueError: Unknown identifier: device_notification_event

Got a fix for this one coming shortly

rasssta commented 2 weeks ago

Now running v0.1.3.

Debugging seems to be fixed!
HASS hasn't crashed after the first mow so that one is hopefully fixed as well.
"ValueError: Unknown identifier: device_notification_event" is still present. Not sure if it was supposed to be fixed yet or not, but anyway :)

Noted some other errors. Do you want me to list them here or create separate issues for each of them?

I'll start listing them in the meanwhile... :)

Error 1: 2024-08-28 13:17:43.812 ERROR (MainThread) [pymammotion.mammotion.devices.mammotion] Yuka: error in sending command -
Traceback (most recent call last): File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mqtt/mammotion_future.py", line 23, in async_get return await self.fut ^^^^^^^^^^^^^^ asyncio.exceptions.CancelledError

Error 2: 2024-08-28 16:00:02.548 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved (None) Traceback (most recent call last): File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1055, in _on_mqtt_message await self._handle_mqtt_message(topic, payload) File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1182, in _handle_mqtt_message await self._parse_mqtt_response(topic=topic, payload=payload) File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1159, in _parse_mqtt_response self._update_raw_data(cast(bytes, binary_data)) File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 390, in _update_raw_data tmp_msg = LubaMsg().parse(data) ^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 759, in parse value = self._postprocess_single( ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 718, in _postprocess_single value = cls().parse(value) ^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 759, in parse value = self._postprocess_single( ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 718, in _postprocess_single value = cls().parse(value) ^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 759, in parse value = self._postprocess_single( ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 701, in _postprocess_single fmt = _pack_fmt(meta.proto_type) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/srv/homeassistant/lib/python3.12/site-packages/betterproto/init.py", line 281, in _pack_fmt return { ^ KeyError: 'int64'

Error/question 3: What's the device_tracker used for? Mine seems to jump a bit randomly between Home/Away. Mowing started at 16:00 today and around 20:00 yesterday.

mikey0000 commented 2 weeks ago

Device tracker is the lat and long of your mower. It exposes the GPS coordinates, home and away is due to your geofence of your home. Yes keep the bug reports flowing :D, can post your errors in here.

mikey0000 commented 2 weeks ago

for error 2 I'd have to see the raw protobuf bytes to resolve it.

mikey0000 commented 2 weeks ago

Can you let me know if you run into the device_notification_event error, on latest it should show whats inside it so I can model it.

rasssta commented 2 weeks ago

Just upgraded to the latest one. Will keep an eye out for the error.

Regarding error 3: Is it possible to get the Yuka's lat/lng values somehow? I double checked my HASS location and it's properly set with quite a big radius but my Yuka still doesn't set its home/away properly.

mikey0000 commented 2 weeks ago

Hit the RTK sync button, also the lat long is in the device tracker

driesvandamme commented 2 weeks ago

Hit the RTK sync button, also the lat long is in the device tracker

FYI, I don't think the Lat/Long are correct: I'm pretty sure it's not on the bottom of the ocean :)

rasssta commented 2 weeks ago

mikey0000 commented 2 weeks ago

Yeah there seems to be an issue where it's getting overwritten back to zero, not the only one with this issue so will check it out

rasssta commented 2 weeks ago

I had a new HASS crash. Not sure if it's related to this integration this time though, but I'll mention it just in case. Seems to have happened in relation to an issue with the internet connection. IMO, it would be nice with a sort of standard warning message for timeouts instead of a "raw" error.

2024-08-31 00:03:42.827 ERROR (MainThread) [pymammotion.mammotion.devices.mammotion] Yuka: error in sending command -  HTTPSConnectionPool(host='eu-central-1.api-iot.aliyuncs.com', port=443): Read timed out. (read timeout=10.0)
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1135, in _send_command_with_args
    return await self._send_command_locked(key, command_bytes)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1081, in _send_command_locked
    return await self._execute_command_locked(key, command)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1112, in _execute_command_locked
    await self.loop.run_in_executor(None, self._mqtt_client.get_cloud_client().send_cloud_command, self.iot_id, command)
  File "/usr/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/aliyun/cloud_gateway.py", line 593, in send_cloud_command
    response = client.do_request("/thing/service/invoke", "https", "POST", None, body, RuntimeOptions())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/alibabacloud_iot_api_gateway/client.py", line 132, in do_request
    raise UnretryableException(_last_request, _last_exception)
Tea.exceptions.UnretryableException: HTTPSConnectionPool(host='eu-central-1.api-iot.aliyuncs.com', port=443): Read timed out. (read timeout=10.0)
2024-08-31 00:03:42.848 ERROR (MainThread) [custom_components.mammotion] Unexpected error fetching mammotion data
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/update_coordinator.py", line 312, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/homeassistant/.homeassistant/custom_components/mammotion/coordinator.py", line 187, in _async_update_data
    await self.async_send_command("get_report_cfg")
  File "/home/homeassistant/.homeassistant/custom_components/mammotion/coordinator.py", line 151, in async_send_command
    await self.manager.send_command_with_args(
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 300, in send_command_with_args
    return await device.cloud().command(key, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 557, in command
    return await self._send_command_with_args(key, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1135, in _send_command_with_args
    return await self._send_command_locked(key, command_bytes)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1081, in _send_command_locked
    return await self._execute_command_locked(key, command)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/mammotion/devices/mammotion.py", line 1112, in _execute_command_locked
    await self.loop.run_in_executor(None, self._mqtt_client.get_cloud_client().send_cloud_command, self.iot_id, command)
  File "/usr/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/pymammotion/aliyun/cloud_gateway.py", line 593, in send_cloud_command
    response = client.do_request("/thing/service/invoke", "https", "POST", None, body, RuntimeOptions())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/homeassistant/lib/python3.12/site-packages/alibabacloud_iot_api_gateway/client.py", line 132, in do_request
    raise UnretryableException(_last_request, _last_exception)
Tea.exceptions.UnretryableException: HTTPSConnectionPool(host='eu-central-1.api-iot.aliyuncs.com', port=443): Read timed out. (read timeout=10.0)

After the above I had some warning messages from other integrations similar to this:

2024-08-31 00:03:45.917 WARNING (MainThread) [homeassistant.components.sensor] Updating unifigateway sensor took longer than the scheduled update interval 0:00:30

And the last part of my HASS log contains a bunch of:

2024-08-31 02:42:04.133 ERROR (Thread-5 (__thread_main)) [linkkit] [Errno -3] Temporary failure in name resolution
2024-08-31 02:43:36.420 ERROR (Thread-5 (__thread_main)) [linkkit] [Errno -3] Temporary failure in name resolution
2024-08-31 02:45:36.452 ERROR (Thread-5 (__thread_main)) [linkkit] [Errno -3] Temporary failure in name resolution
2024-08-31 02:47:21.445 ERROR (Thread-5 (__thread_main)) [linkkit] [Errno -3] Temporary failure in name resolution
2024-08-31 02:48:56.837 ERROR (Thread-5 (__thread_main)) [linkkit] [Errno -3] Temporary failure in name resolution
2024-08-31 02:51:09.028 ERROR (Thread-5 (__thread_main)) [linkkit] [Errno -3] Temporary failure in name resolution

rasssta commented 2 weeks ago

Can you let me know if you run into the device_notification_event error, on latest it should show whats inside it so I can model it.

Haven't had that error again FYI.

mikey0000 commented 2 weeks ago

Yeah I get the event on my own mower and was able to model it up.

mikey0000 / Mammotion-HA