search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.21k stars 30.57k forks source link

Sense - UnicodeDecodeError Log Entries #109159

Closed ttravisswan closed 5 months ago

ttravisswan commented 9 months ago

The problem

I'm getting thousands of log entries each hour that appear to be originating from the Sense Energy integration with HA. Log entry is below. Any idea what might be causing this issue?

Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:145
First occurred: January 29, 2024 at 10:52:38 PM (4063 occurrences)
Last logged: 12:25:23 PM

Error doing job: Exception in callback _SelectorDatagramTransport._read_ready()
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1163, in _read_ready
    self._protocol.datagram_received(data, addr)
  File "/usr/local/lib/python3.11/site-packages/sense_energy/sense_link.py", line 40, in datagram_received
    decrypted_data = tp_link_decrypt(data)
                     ^^^^^^^^^^^^^^^^^^^^^
  File "src/kasa_crypt/_crypt_impl.pyx", line 37, in kasa_crypt._crypt_impl.decrypt
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xa7 in position 0: invalid start `byte`

What version of Home Assistant Core has the issue?

core-2024.1.5

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Sense

Link to integration documentation on our website

https://www.home-assistant.io/integrations/sense/

Diagnostics information

home-assistant_sense_2024-01-30T19-35-52.117Z.log

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 9 months ago

Hey there @kbickar, mind taking a look at this issue as it has been labeled with an integration (sense) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `sense` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign sense` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

sense documentation sense source (message by IssueLinks)

codyc1515 commented 9 months ago

Are you using Emulated Kasa by chance? I would try disabling that first.

bdraco commented 9 months ago

It looks like the decrypted payload is invalid utf-8

bdraco commented 9 months ago

Any chance you can get a tcpdump of the packets ?

ttravisswan commented 9 months ago

tcpdump from the web UI's SSH terminal? I can swing that. Any capture filters I should (or should not) add to the command?

bdraco commented 9 months ago

Should be limited to UDP traffic coming into port 9999 https://github.com/scottbonline/sense/blob/243a104fd604eb3f796f7fccc3c24467da0c8c89/sense_energy/sense_link.py#L16

ttravisswan commented 9 months ago

tcpdump picked up absolutely nothing on port 9999 from the HA terminal, but from a Windows 11 PC on the same network I picked up a few hundred packets on port 9999 in roughly 30 minutes or so. Most of them were from my Sense monitor's IP address to 255.255.255.255, which are in the attached pcap file. Sense Packets 01312024.zip

bdraco commented 9 months ago

Looks like its 

  0xd0, 0xf2, 0x81, 0xf8, 0x8b, 0xff, 0x9a, 0xf7,
  0xd5, 0xef, 0xcf, 0xb4, 0x96, 0xf1, 0x94, 0xe0,
  0xbf, 0xcc, 0xb5, 0xc6, 0xaf, 0xc1, 0xa7, 0xc8,
  0xea, 0xd0, 0xf0, 0x8b, 0xf6, 0x8b, 0xa7, 0x87,
  0xa5, 0xc0, 0xad, 0xc8, 0xbc, 0xd9, 0xab, 0x89,
  0xb3, 0x93, 0xe8, 0xca, 0xad, 0xc8, 0xbc, 0xe3,
  0x91, 0xf4, 0x95, 0xf9, 0x8d, 0xe4, 0x89, 0xec,
  0xce, 0xf4, 0xd4, 0xaf, 0xd2, 0xaf, 0xd2
bdraco commented 9 months ago

b'\xd0\xf2\x81\xf8\x8b\xff\x9a\xf7\xd5\xef\xcf\xb4\x96\xf1\x94\xe0\xbf\xcc\xb5\xc6\xaf\xc1\xa7\xc8\xea\xd0\xf0\x8b\xf6\x8b\xa7\x87\xa5\xc0\xad\xc8\xbc\xd9\xab\x89\xb3\x93\xe8\xca\xad\xc8\xbc\xe3\x91\xf4\x95\xf9\x8d\xe4\x89\xec\xce\xf4\xd4\xaf\xd2\xaf\xd2'

bdraco commented 9 months ago 
>>> kasa_crypt.decrypt(b'\xd0\xf2\x81\xf8\x8b\xff\x9a\xf7\xd5\xef\xcf\xb4\x96\xf1\x94\xe0\xbf\xcc\xb5\xc6\xaf\xc1\xa7\xc8\xea\xd0\xf0\x8b\xf6\x8b\xa7\x87\xa5\xc0\xad\xc8\xbc\xd9\xab\x89\xb3\x93\xe8\xca\xad\xc8\xbc\xe3\x91\xf4\x95\xf9\x8d\xe4\x89\xec\xce\xf4\xd4\xaf\xd2\xaf\xd2')
'{"system": {"get_sysinfo": {}}, "emeter": {"get_realtime": {}}}'
bdraco commented 9 months ago

It looks like something else might be sending in garbage data.

You'll have to do get the tcpdump on the HA box working to see it since whats being broadcast looks ok

ttravisswan commented 9 months ago

Try these. Of the six source IPs in this pcap file, two are Google/Nest devices (.96 and .125) and four are Asus ZenWiFi devices (.1, .48, .155, and .222).

Sense Packets 01312024_v2.zip

bdraco commented 9 months ago 
  0xd0, 0xf2, 0x81, 0xf8, 0x8b, 0xff, 0x9a, 0xf7,
  0xd5, 0xef, 0x94, 0xb6, 0xd1, 0xb4, 0xc0, 0x9f,
  0xec, 0x95, 0xe6, 0x8f, 0xe1, 0x87, 0xe8, 0xca,
  0xf0, 0x8b, 0xf6, 0x8b, 0xf6
bdraco commented 9 months ago

That all looks ok as well

>>> payload = bytes((  0xd0, 0xf2, 0x81, 0xf8, 0x8b, 0xff, 0x9a, 0xf7,
...   0xd5, 0xef, 0x94, 0xb6, 0xd1, 0xb4, 0xc0, 0x9f,
...   0xec, 0x95, 0xe6, 0x8f, 0xe1, 0x87, 0xe8, 0xca,
...   0xf0, 0x8b, 0xf6, 0x8b, 0xf6))
>>> kasa_crypt.decrypt(payload)
'{"system":{"get_sysinfo":{}}}'
>>>

I'm not sure where the bad payload is coming from

bdraco commented 9 months ago

Which version of kasa-crypt do you have installed in the container?

bdraco commented 9 months ago

oh there is another one in there 

  0x0c, 0x15, 0x1f, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
  0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
bdraco commented 9 months ago

192.168.50.155, 192.168.50.222 and a few more seem to be sending that

bdraco commented 9 months ago

thats it 

>>> payload=bytes((  0x0c, 0x15, 0x1f, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...   0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00))
>>> kasa_crypt.decrypt(payload)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "src/kasa_crypt/_crypt_impl.pyx", line 38, in kasa_crypt._crypt_impl.decrypt
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xa7 in position 0: invalid start byte
>>>
bdraco commented 9 months ago

192.168.50.48 192.168.50.222 192.168.50.155 192.168.50.1 192.168.50.96 192.168.50.125

These are the ips sending that packet

ttravisswan commented 9 months ago

Looks like .96 and .125 are sending different packets than the other four sources. Are you sure it's all six of these IPs or just the other four (.1, .48, .155, .222) causing the issue? Those four IPs are my Asus ZenWiFi XT8 mesh routers/nodes, so it's not like I can just take those devices off the network to troubleshoot...because without them, there is no network...

image

I'm running HA Core 2024.1.6, HA Supervisor 2024.01.1, and HAOS 11.5.rc3. I'm not aware of a way to manage/update python-kasa or kasa-crypt outside of the managed Home Assistant updates.

bdraco commented 9 months ago

.96 and .125 are ok. Its the other ones that are sending the invalid 512 byte payloads.

bdraco commented 9 months ago

Given its coming from the Asus ZenWiFi XT8 mesh routers/nodes it may be some bad luck that the have their own protocol (or something related to them) that happens to operate on port 9999 and as far as the emulated_kasa integration is concerned its receiving garbage and throwing an exception when it can't decode it

home-assistant[bot] commented 9 months ago

Hey there @kbickar, mind taking a look at this issue as it has been labeled with an integration (emulated_kasa) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `emulated_kasa` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign emulated_kasa` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

emulated_kasa documentation emulated_kasa source (message by IssueLinks)

ttravisswan commented 9 months ago

Did a little research, and it looks like Asus ZenWiFi devices use port 9999 for a process called infosvr, which allegedly assists with locating routers on the local subnet. More info here: https://github.com/jduck/asus-cmd

The packets sent by Asus devices related to this process all have a packet of INFO_PDU_LENGTH (512) bytes, which is consistent with the Wireshark screenshot above. This isn't my area of expertise, but couldn't this issue be resolved by modifying the code to simply ignore all UDP traffic on port 9999 with that packet length?

bdraco commented 9 months ago

That's up to the library author if they want to add that workaround for asus devices. I probably wouldn't want to carry around or maintain code to accommodate every random device in the library though, and it might be better to swallow the exception, regardless, it's not a call I can make.

issue-triage-workflows[bot] commented 6 months ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.