search

anotherjulien / MyHOME

MyHOME integration for Home-Assistant
GNU Affero General Public License v3.0
137 stars 57 forks source link

Command session connection keeps resetting, integration gets stuck #125

Open gPinato opened 6 months ago

gPinato commented 6 months ago

Hello,

my integration gets periodically stuck, around once per day but that's not a fixed interval. I have to reboot HA to get it to work again.

Digging into the logs, it seems to me the session is being renewed/reset and the integration gets into a loop while doing so.

I have described the issue here too

Can I do anything to help?

2024-04-14 19:47:24.507 INFO (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sensor 1 is reporting an active power draw of 486 W.
2024-04-14 19:47:41.665 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*1000#1*13##`
2024-04-14 19:47:41.665 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Ignoring translation message `*1*1000#1*13##`
2024-04-14 19:47:41.717 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*10*13##`
2024-04-14 19:48:07.801 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully queued.
2024-04-14 19:48:07.810 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Command session connection reset, retrying...
2024-04-14 19:48:07.810 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Opening command session.
2024-04-14 19:48:07.815 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Negotiating command session.
2024-04-14 19:48:07.818 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Received SHA challenge: `*98*2##`
2024-04-14 19:48:07.818 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Accepting sha256 challenge, initiating handshake.
2024-04-14 19:48:07.821 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sending command session password.
2024-04-14 19:48:07.989 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*567463##`.
2024-04-14 19:48:08.031 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully sent.
2024-04-14 19:49:07.801 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully queued.
2024-04-14 19:49:07.810 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Command session connection reset, retrying...
2024-04-14 19:49:07.811 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Opening command session.
2024-04-14 19:49:07.815 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Negotiating command session.
2024-04-14 19:49:07.818 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Received SHA challenge: `*98*2##`
2024-04-14 19:49:07.819 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Accepting sha256 challenge, initiating handshake.
2024-04-14 19:49:07.821 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sending command session password.
2024-04-14 19:49:07.989 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*567463##`.
2024-04-14 19:49:08.030 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully sent.
2024-04-14 19:50:07.802 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully queued.
gPinato commented 6 months ago

I noticed something else in the logs. Normally, after the response arrives from the gateway, it is "interpreted" in a human readable fashion. See the following

2024-04-16 20:08:13.327 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Command session connection reset, retrying...
2024-04-16 20:08:13.328 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Opening command session.
2024-04-16 20:08:13.333 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Negotiating command session.
2024-04-16 20:08:13.336 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Received SHA challenge: `*98*2##`
2024-04-16 20:08:13.336 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Accepting sha256 challenge, initiating handshake.
2024-04-16 20:08:13.339 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sending command session password.
2024-04-16 20:08:13.507 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*#18*51*51*584395##`
2024-04-16 20:08:13.507 INFO (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sensor 1 is reporting a total power consumption of 584395 Wh.
2024-04-16 20:08:13.510 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*584395##`.
2024-04-16 20:08:13.551 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully sent.
2024-04-16 20:08:15.203 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*#18*51*113*1550##`
2024-04-16 20:08:15.204 INFO (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sensor 1 is reporting an active power draw of 1550 W.
2024-04-16 20:08:35.351 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*1000#0*13##`
2024-04-16 20:08:35.351 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Ignoring translation message `*1*1000#0*13##`
2024-04-16 20:08:35.400 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*0*13##`
2024-04-16 20:08:42.266 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*1000#0*13##`
2024-04-16 20:08:42.266 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Ignoring translation message `*1*1000#0*13##`
2024-04-16 20:08:42.319 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*0*13##`
2024-04-16 20:08:44.735 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*1000#0*13##`
2024-04-16 20:08:44.736 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Ignoring translation message `*1*1000#0*13##`
2024-04-16 20:08:44.786 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*0*13##`
2024-04-16 20:08:45.138 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*#18*51*113*1540##`
2024-04-16 20:08:45.139 INFO (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sensor 1 is reporting an active power draw of 1540 W.

What I mean is

2024-04-16 20:08:13.507 INFO (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sensor 1 is reporting a total power consumption of 584395 Wh.
2024-04-16 20:08:13.510 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*584395##`.

When the integration get stuck, this does not happen anymore, as the loop is

2024-04-16 20:08:47.509 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*1000#1*13##`
2024-04-16 20:08:47.510 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Ignoring translation message `*1*1000#1*13##`
2024-04-16 20:08:47.561 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*10*13##`
2024-04-16 20:09:13.320 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully queued.
2024-04-16 20:09:13.329 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Command session connection reset, retrying...
2024-04-16 20:09:13.330 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Opening command session.
2024-04-16 20:09:13.334 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Negotiating command session.
2024-04-16 20:09:13.339 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Received SHA challenge: `*98*2##`
2024-04-16 20:09:13.339 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Accepting sha256 challenge, initiating handshake.
2024-04-16 20:09:13.342 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Sending command session password.
2024-04-16 20:09:13.511 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*584395##`.
2024-04-16 20:09:13.555 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully sent.
2024-04-16 20:10:13.321 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` was successfully queued.
2024-04-16 20:10:13.330 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Command session connection reset, retrying...
2

without any parsing of the value.

I notice though that the message response for total energy consumption does change overtime, so the sensor and the gateway are responding with up to date values.

2024-04-16 20:10:13.512 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*584395##`.
 and after a while
2024-04-16 20:32:13.532 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message `*#18*51*51##` received response `*#18*51*51*584948##`.

Tho the UI does not report any change, I guess because it is not parsed and updated by the integration.

Lastly, I noticed that when the integration gets stuck I do not get any more acknowledgement from the gateway of messages being received, such as 

2024-04-16 00:07:12.465 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*0*08##`
nachogarcia commented 6 months ago

I'm experiencing the same behaviour (altough I only have a couple of motion sensors and a light). If I try to turn on the light after the integration freezes, this is what happens:

2024-04-17T00:32:11.656373133-07:00 --- Logging error ---
2024-04-17T00:32:11.657335999-07:00 2024-04-17 09:32:11.655 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message `*1*1*16##` was successfully queued.
2024-04-17T00:32:11.658480489-07:00 Traceback (most recent call last):
2024-04-17T00:32:11.659901424-07:00   File "/usr/local/lib/python3.12/logging/handlers.py", line 1497, in emit
2024-04-17T00:32:11.660009240-07:00     self.enqueue(self.prepare(record))
2024-04-17T00:32:11.660084019-07:00                  ^^^^^^^^^^^^^^^^^^^^
2024-04-17T00:32:11.660148786-07:00   File "/usr/src/homeassistant/homeassistant/util/logging.py", line 31, in prepare
2024-04-17T00:32:11.660213811-07:00     record = super().prepare(record)
2024-04-17T00:32:11.660277470-07:00              ^^^^^^^^^^^^^^^^^^^^^^^
2024-04-17T00:32:11.660342616-07:00   File "/usr/local/lib/python3.12/logging/handlers.py", line 1479, in prepare
2024-04-17T00:32:11.660406480-07:00     msg = self.format(record)
2024-04-17T00:32:11.660471458-07:00           ^^^^^^^^^^^^^^^^^^^
2024-04-17T00:32:11.660524362-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 999, in format
2024-04-17T00:32:11.660585716-07:00     return fmt.format(record)
2024-04-17T00:32:11.660635411-07:00            ^^^^^^^^^^^^^^^^^^
2024-04-17T00:32:11.660725464-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 703, in format
2024-04-17T00:32:11.660793849-07:00     record.message = record.getMessage()
2024-04-17T00:32:11.660889483-07:00                      ^^^^^^^^^^^^^^^^^^^
2024-04-17T00:32:11.660947941-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 392, in getMessage
2024-04-17T00:32:11.661011360-07:00     msg = msg % self.args
2024-04-17T00:32:11.661061537-07:00           ~~~~^~~~~~~~~~~
2024-04-17T00:32:11.661150962-07:00 TypeError: not all arguments converted during string formatting
2024-04-17T00:32:11.661220682-07:00 Call stack:
2024-04-17T00:32:11.661365061-07:00   File "<frozen runpy>", line 198, in _run_module_as_main
2024-04-17T00:32:11.661525141-07:00   File "<frozen runpy>", line 88, in _run_code
2024-04-17T00:32:11.661594962-07:00   File "/usr/src/homeassistant/homeassistant/__main__.py", line 222, in <module>
2024-04-17T00:32:11.661663677-07:00     sys.exit(main())
2024-04-17T00:32:11.661727801-07:00   File "/usr/src/homeassistant/homeassistant/__main__.py", line 210, in main
2024-04-17T00:32:11.661792302-07:00     exit_code = runner.run(runtime_conf)
2024-04-17T00:32:11.661804353-07:00   File "/usr/src/homeassistant/homeassistant/runner.py", line 189, in run
2024-04-17T00:32:11.661816526-07:00     return loop.run_until_complete(setup_and_run_hass(runtime_config))
2024-04-17T00:32:11.661836484-07:00   File "/usr/local/lib/python3.12/asyncio/base_events.py", line 672, in run_until_complete
2024-04-17T00:32:11.661850440-07:00     self.run_forever()
2024-04-17T00:32:11.661863640-07:00   File "/usr/local/lib/python3.12/asyncio/base_events.py", line 639, in run_forever
2024-04-17T00:32:11.661876038-07:00     self._run_once()
2024-04-17T00:32:11.661888456-07:00   File "/usr/local/lib/python3.12/asyncio/base_events.py", line 1988, in _run_once
2024-04-17T00:32:11.661900747-07:00     handle._run()
2024-04-17T00:32:11.661913631-07:00   File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
2024-04-17T00:32:11.661925964-07:00     self._context.run(self._callback, *self._args)
2024-04-17T00:32:11.661938934-07:00   File "/config/custom_components/myhome/gateway.py", line 380, in sending_loop
2024-04-17T00:32:11.661951490-07:00     LOGGER.debug(
2024-04-17T00:32:11.661974213-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 1527, in debug
2024-04-17T00:32:11.661989185-07:00     self._log(DEBUG, msg, args, **kwargs)
2024-04-17T00:32:11.662001574-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 1684, in _log
2024-04-17T00:32:11.662011708-07:00     self.handle(record)
2024-04-17T00:32:11.662020261-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 1700, in handle
2024-04-17T00:32:11.662031283-07:00     self.callHandlers(record)
2024-04-17T00:32:11.662053159-07:00   File "/usr/local/lib/python3.12/logging/__init__.py", line 1762, in callHandlers
2024-04-17T00:32:11.662065550-07:00     hdlr.handle(record)
2024-04-17T00:32:11.662075823-07:00   File "/usr/src/homeassistant/homeassistant/util/logging.py", line 49, in handle
2024-04-17T00:32:11.662085957-07:00     self.emit(record)
2024-04-17T00:32:11.662101112-07:00 Message: '%s Message `%s` was successfully unqueued by worker %s.'
2024-04-17T00:32:11.662112733-07:00 Arguments: ('HL4684 Gateway', '192.168.0.131', *1*1*16##, 0)
2024-04-17T00:32:11.662126723-07:00 2024-04-17 09:32:11.661 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Command session connection reset, retrying...
2024-04-17T00:32:11.662351521-07:00 2024-04-17 09:32:11.661 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Opening command session.
2024-04-17T00:32:11.662811882-07:00 2024-04-17 09:32:11.662 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Negotiating command session.
2024-04-17T00:32:12.771471439-07:00 2024-04-17 09:32:12.770 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Received nonce: `*#199310394##`
2024-04-17T00:32:12.772000795-07:00 2024-04-17 09:32:12.770 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Sending command session password.
2024-04-17T00:32:12.773331656-07:00 2024-04-17 09:32:12.772 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Command session established.
2024-04-17T00:32:12.828141919-07:00 2024-04-17 09:32:12.827 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message `*1*1*16##` was successfully sent.
gPinato commented 6 months ago

I've added a few logs here and there, and I think I was able to see this before the integration got stuck

2024-04-18 18:09:32.779 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*6*13##`
2024-04-18 18:09:32.779 ERROR (MainThread) [custom_components.myhome] Custom breakpoint 1
2024-04-18 18:09:32.788 ERROR (MainThread) [custom_components.myhome] Traceback (most recent call last):
File "/config/custom_components/myhome/gateway.py", line 264, in listening_loop
self.hass.data[DOMAIN][self.mac][CONF_PLATFORMS][LIGHT][message.entity][CONF_ENTITIES][LIGHT],
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^
KeyError: '1-13'

I wrapped this call into a try except, and the 2024-04-18 18:09:32.779 ERROR (MainThread) [custom_components.myhome] Custom breakpoint 1 is what is logged in that except block, meaning there is/was an unhandled exception.

gPinato commented 6 months ago

I might be on to something.

When I turn on a regular light, I get three events, in order:

event_type: myhome_message_event
data:
  gateway: 10.0.5.2
  message: "*1*1000#0*09##"
  family: Command translation
  type: Status
  who: 1
  where: "09"
  what: 1000
  what parameters:
    - "0"
origin: LOCAL
time_fired: "2024-04-18T17:36:45.059288+00:00"
context:
  id: 01HVS4GG03Z60NT9PTT6R971TW
  parent_id: null
  user_id: null
event_type: myhome_message_event
data:
  gateway: 10.0.5.2
  message: "*1*0*09##"
  family: Event
  type: Status
  who: 1
  where: "09"
origin: LOCAL
time_fired: "2024-04-18T17:36:45.132662+00:00"
context:
  id: 01HVS4GG2CBSCJ9T7TSA5M55Q2
  parent_id: null
  user_id: null
event_type: state_changed
data:
  entity_id: light.terrazza_piccola
  old_state:
    entity_id: light.terrazza_piccola
    state: "on"
    attributes:
      supported_color_modes:
        - onoff
      color_mode: onoff
      A: "0"
      PL: "9"
      friendly_name: Small Terrace
      supported_features: 8
    last_changed: "2024-04-18T17:36:43.909439+00:00"
    last_reported: "2024-04-18T17:36:43.909439+00:00"
    last_updated: "2024-04-18T17:36:43.909439+00:00"
    context:
      id: 01HVS4GEW5FAY2PA7RATTA80R8
      parent_id: null
      user_id: null
  new_state:
    entity_id: light.terrazza_piccola
    state: "off"
    attributes:
      supported_color_modes:
        - onoff
      color_mode: null
      A: "0"
      PL: "9"
      friendly_name: Small Terrace
      supported_features: 8
    last_changed: "2024-04-18T17:36:45.133549+00:00"
    last_reported: "2024-04-18T17:36:45.133549+00:00"
    last_updated: "2024-04-18T17:36:45.133549+00:00"
    context:
      id: 01HVS4GG2DF1RGCS1S369ESH9S
      parent_id: null
      user_id: null
origin: LOCAL
time_fired: "2024-04-18T17:36:45.133549+00:00"
context:
  id: 01HVS4GG2DF1RGCS1S369ESH9S
  parent_id: null
  user_id: null

Which I assume is the event for the light switch and its translation by the integration.

If I do so with a dimmable light

event_type: myhome_message_event
data:
  gateway: 10.0.5.2
  message: "*1*1000#1*13##"
  family: Command translation
  type: Status
  who: 1
  where: "13"
  what: 1000
  what parameters:
    - "1"
origin: LOCAL
time_fired: "2024-04-18T17:43:57.886245+00:00"
context:
  id: 01HVS4XPNYXGDDY547AHBRF42R
  parent_id: null
  user_id: null
event_type: myhome_message_event
data:
  gateway: 10.0.5.2
  message: "*1*10*13##"
  family: Event
  type: Status
  who: 1
  where: "13"
  what: 10
origin: LOCAL
time_fired: "2024-04-18T17:43:57.925931+00:00"
context:
  id: 01HVS4XPQ50MGF8THJPXBWKRJ6
  parent_id: null
  user_id: null
2024-04-18 19:43:57.886 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*1000#1*13##`
2024-04-18 19:43:57.886 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Ignoring translation message `*1*1000#1*13##`
2024-04-18 19:43:57.925 DEBUG (MainThread) [custom_components.myhome] CHIPOTLE
2024-04-18 19:43:57.925 DEBUG (MainThread) [custom_components.myhome] [F454 gateway - 10.0.5.2] Message received: `*1*10*13##`
2024-04-18 19:43:57.937 ERROR (MainThread) [custom_components.myhome] Traceback (most recent call last):
File "/config/custom_components/myhome/gateway.py", line 264, in listening_loop
self.hass.data[DOMAIN][self.mac][CONF_PLATFORMS][LIGHT][message.entity][CONF_ENTITIES][LIGHT],
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^
KeyError: '1-13'

Could it be due to the dimmable light message format?

I use a DALI dimmer, could that be the cause?

gPinato commented 6 months ago

Turns out, a light in my home was not mapped in the configuration of this integration, and interacting with it would cause a message to look up an entity in a dictionary, not finding it and breaking.

At least that's how I've understood it so far.

nachogarcia commented 5 months ago

To me it keeps 'freezing'. I enabled debug and the last messages of the integration are

2024-05-12 21:21:29.551 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#4*98*0*0248##`
2024-05-12 21:21:29.866 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#4*98*14*0200*3##`
2024-05-12 21:21:30.187 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#4*98*14*0200*3##`
2024-05-12 21:21:30.696 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#4*98*13*00##`
2024-05-12 21:21:31.206 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#4*98*12*0350*3##`
2024-05-12 21:21:31.207 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*4*202*98##`
2024-05-12 21:21:31.225 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#13**15*23##`
2024-05-12 21:21:31.225 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Gateway device type is: Unknown (23).
2024-05-12 21:21:31.716 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#4*98*14*0200*3##`
2024-05-12 21:21:34.029 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*1*0*11##`
2024-05-12 21:21:35.977 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#13**15*23##`
2024-05-12 21:21:35.977 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Gateway device type is: Unknown (23).
2024-05-12 21:21:39.021 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*1*1*21##`
2024-05-12 21:21:40.968 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#13**15*23##`
2024-05-12 21:21:40.969 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Gateway device type is: Unknown (23).
2024-05-12 21:21:44.016 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*1*1*22##`
2024-05-12 21:21:45.986 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#13**15*23##`
2024-05-12 21:21:45.986 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Gateway device type is: Unknown (23).
2024-05-12 21:21:49.029 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*1*0*31##`
2024-05-12 21:21:50.391 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*9*1*4##`
2024-05-12 21:21:50.391 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Auxilliary channel 4 is set to 'ON'.
2024-05-12 21:21:50.541 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*9*0*4##`
2024-05-12 21:21:50.542 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Auxilliary channel 4 is set to 'OFF'.
2024-05-12 21:21:50.975 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*#13**15*23##`
2024-05-12 21:21:50.975 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Gateway device type is: Unknown (23).
2024-05-12 21:21:51.611 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*9*1*4##`
2024-05-12 21:21:51.611 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Auxilliary channel 4 is set to 'ON'.
2024-05-12 21:21:52.070 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*9*0*4##`
2024-05-12 21:21:52.071 INFO (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Auxilliary channel 4 is set to 'OFF'.
2024-05-12 21:21:53.884 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*1*1000#1*31##`
2024-05-12 21:21:53.884 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Ignoring translation message `*1*1000#1*31##`
2024-05-12 21:21:53.904 DEBUG (MainThread) [custom_components.myhome] [HL4684 gateway - 192.168.0.131] Message received: `*1*7*31##`

Still haven't pinpointed the issue :/