core: Tradfri light, various frequent errors: KeyError: '3311', NoneType' object does not support item assignment

The problem

as logged in the beta a couple of times, below error(s) is (are) in the logs.

Update: <strike>Not sure if it is actually causing functionality issues, but is is so frequent, something really is not ok.</strike>

time has shown this is causing frequent (multiple times daily) connection issues, and Tradfri not responding/communicating to the Gateway any longer. The Gateway btw being fully functional standalone communicating correctly with the Ikea app.

What version of Home Assistant Core has the issue?

2023.1

What was the last working version of Home Assistant Core?

2022.12

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Tradfri

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant
Source: components/tradfri/light.py:93 
First occurred: 18:11:09 (5256 occurrences) 
Last logged: 22:02:15

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 168, in _handle_refresh_interval
    await self._async_refresh(log_failures=True, scheduled=True)
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 316, in _async_refresh
    self.async_update_listeners()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 121, in async_update_listeners
    update_callback()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/base_class.py", line 71, in _handle_coordinator_update
    self._refresh()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/light.py", line 93, in _refresh
    self._device_data = self.coordinator.data.light_control.lights[0]
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/__init__.py", line 84, in light_control
    return LightControl(self)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/light_control.py", line 40, in __init__
    if ATTR_LIGHT_DIMMER in self.raw[0]:
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/light_control.py", line 71, in raw
    return self._device.raw[ATTR_LIGHT_CONTROL]
KeyError: '3311'

and 

Logger: homeassistant.util.logging
Source: util/logging.py:156 
First occurred: 18:11:53 (451 occurrences) 
Last logged: 22:01:55

Exception in set_hub_available when dispatching 'tradfri.gw_status': (True,)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/tradfri/coordinator.py", line 47, in set_hub_available
    await self.async_request_refresh()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 175, in async_request_refresh
    await self._debounced_refresh.async_call()
  File "/usr/src/homeassistant/homeassistant/helpers/debounce.py", line 82, in async_call
    await task
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 201, in async_refresh
    await self._async_refresh(log_failures=True)
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 316, in _async_refresh
    self.async_update_listeners()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 121, in async_update_listeners
    update_callback()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/base_class.py", line 71, in _handle_coordinator_update
    self._refresh()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/light.py", line 93, in _refresh
    self._device_data = self.coordinator.data.light_control.lights[0]
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/__init__.py", line 84, in light_control
    return LightControl(self)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/light_control.py", line 40, in __init__
    if ATTR_LIGHT_DIMMER in self.raw[0]:
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/light_control.py", line 71, in raw
    return self._device.raw[ATTR_LIGHT_CONTROL]
KeyError: '3311'

Logger: homeassistant.components.tradfri
Source: helpers/update_coordinator.py:201 
Integration: IKEA TRÅDFRI (documentation, issues) 
First occurred: 18:11:02 (2 occurrences) 
Last logged: 18:11:04

Error fetching Update coordinator for <65583 - Parking light (TRADFRI bulb E27 W opal 1000lm)> data: Error communicating with API: Gateway payload: {"r":"02"}. Error code: 4.00 Bad Request..
Error fetching Update coordinator for <65714 - Mademoiselle Filou (TRADFRI bulb E14 W op/ch 400lm)> data: Error communicating with API: Gateway payload: {"r":"02"}. Error code: 4.00 Bad Request..


Logger: homeassistant.components.tradfri
Source: components/tradfri/light.py:93 
Integration: IKEA TRÅDFRI (documentation, issues) 
First occurred: 18:11:09 (2 occurrences) 
Last logged: 18:12:48

Unexpected error fetching Update coordinator for <65714 - Mademoiselle Filou (TRADFRI bulb E14 W op/ch 400lm)> data: '3311'
Unexpected error fetching Update coordinator for <65583 - Parking light (TRADFRI bulb E27 W opal 1000lm)> data: '3311'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 225, in _async_refresh
    self.data = await self._async_update_data()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/coordinator.py", line 88, in _async_update_data
    await self.api(cmd)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/api/aiocoap_api.py", line 199, in request
    result = await self._execute(api_commands, timeout)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/api/aiocoap_api.py", line 137, in _execute
    await self._observe(api_command, timeout)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/api/aiocoap_api.py", line 220, in _observe
    api_command.result = _process_output(pr_rsp)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/command.py", line 91, in result
    self._result = self._process_result(value)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/resource.py", line 62, in observe_callback
    callback(self)
  File "/usr/src/homeassistant/homeassistant/components/tradfri/coordinator.py", line 52, in _observe_update
    self.async_set_updated_data(data=device)
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 346, in async_set_updated_data
    self.async_update_listeners()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 121, in async_update_listeners
    update_callback()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/base_class.py", line 71, in _handle_coordinator_update
    self._refresh()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/light.py", line 93, in _refresh
    self._device_data = self.coordinator.data.light_control.lights[0]
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/__init__.py", line 84, in light_control
    return LightControl(self)
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/light_control.py", line 40, in __init__
    if ATTR_LIGHT_DIMMER in self.raw[0]:
  File "/usr/local/lib/python3.10/site-packages/pytradfri/device/light_control.py", line 71, in raw
    return self._device.raw[ATTR_LIGHT_CONTROL]
KeyError: '3311'

Logger: homeassistant.components.tradfri
Source: components/tradfri/coordinator.py:77 
Integration: IKEA TRÅDFRI (documentation, issues) 
First occurred: 18:14:03 (50 occurrences) 
Last logged: 18:14:03

Unexpected error fetching Update coordinator for <65641 - Master bed outlet (TRADFRI control outlet)> data: Retransmissions exceeded
Unexpected error fetching Update coordinator for <65741 - Ster rechts (TRADFRI bulb E14 WS 470lm)> data: Retransmissions exceeded
Unexpected error fetching Update coordinator for <65719 - Bureau left (TRADFRI bulb E14 WS opal 400lm)> data: Retransmissions exceeded
Unexpected error fetching Update coordinator for <65740 - Ster links (TRADFRI bulb E14 WS 470lm)> data: Retransmissions exceeded
Unexpected error fetching Update coordinator for <65701 - Guest room afstandsbediening (TRADFRI remote control)> data: Retransmissions exceeded
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 225, in _async_refresh
    self.data = await self._async_update_data()
  File "/usr/src/homeassistant/homeassistant/components/tradfri/coordinator.py", line 77, in _async_update_data
    raise exc
  File "/usr/local/lib/python3.10/site-packages/pytradfri/api/aiocoap_api.py", line 107, in _get_response
    pr_resp = await asyncio.wait_for(pr_req.response, timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 408, in wait_for
    return await fut
  File "/usr/local/lib/python3.10/site-packages/aiocoap/protocol.py", line 612, in _run_outer
    await cls._run(app_request, response, weak_observation, protocol, log)
  File "/usr/local/lib/python3.10/site-packages/aiocoap/protocol.py", line 671, in _run
    blockresponse = await blockrequest.response
  File "/usr/local/lib/python3.10/site-packages/aiocoap/protocol.py", line 897, in __del__
    self._future.result()
  File "/usr/local/lib/python3.10/site-packages/aiocoap/protocol.py", line 897, in __del__
    self._future.result()
  File "/usr/local/lib/python3.10/site-packages/aiocoap/protocol.py", line 897, in __del__
    self._future.result()
  [Previous line repeated 1 more time]
aiocoap.error.ConRetransmitsExceeded: Retransmissions exceeded

Additional information

Aware several other new Tradfri issues have been logged, I decided to create this separate, because the logging is different.

https://github.com/home-assistant/core/issues/85105 https://github.com/home-assistant/core/issues/84624

About this issue

  • Original URL
  • State: open
  • Created a year ago
  • Comments: 62 (44 by maintainers)

Most upvoted comments

Please don’t use this issue as a catch all issue for the Tradfri integration. If the stack trace is different, open a new issue for each stack trace.

so we did, is anyone looking at this? The issue has increased a lot, and is up to the point where the integration cant be used reliably anymore, unless we find a reason for this behavior and fix that.

Ive now also filed an issue at aiocoap, specifically directed to do so by the error message, link is above.

The fact there is no-one assigned to the new issue doesn’t really help probably… this one still stands firmly:

Scherm­afbeelding 2023-12-15 om 10 32 14

new development:

since beta 2023.12.0b the issue seems to have worsened.

The auomatic reload of the integration does seem to work initially and entities are shown as if they are available. However, controlling them is impossible and errors out with

Logger: root
Source: /usr/src/homeassistant/homeassistant/bootstrap.py:402
First occurred: 10:21:50 (76 occurrences)
Last logged: 11:30:16

Uncaught exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiocoap/transports/tinydtls.py", line 170, in wrapper
    return getattr(self, __method)(*args)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiocoap/transports/tinydtls.py", line 280, in _read
    self.coaptransport.ctx.dispatch_message(message)
  File "/usr/local/lib/python3.11/site-packages/aiocoap/messagemanager.py", line 109, in dispatch_message
    success = self._process_response(message)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiocoap/messagemanager.py", line 335, in _process_response
    return self.token_manager.process_response(response)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiocoap/tokenmanager.py", line 167, in process_response
    if key not in self.outgoing_requests:
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: argument of type 'NoneType' is not iterable

a subsequent manual reload of the integration now also errors with:

Logger: homeassistant.config_entries
Source: config_entries.py:557
First occurred: 11:30:46 (1 occurrences)
Last logged: 11:30:46

Error unloading entry Ikea Trådfri for tradfri
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 557, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/tradfri/__init__.py", line 149, in async_unload_entry
    await factory.shutdown()
  File "/usr/local/lib/python3.11/site-packages/pytradfri/api/aiocoap_api.py", line 99, in shutdown
    await self._reset_protocol(exc)
  File "/usr/local/lib/python3.11/site-packages/pytradfri/api/aiocoap_api.py", line 87, in _reset_protocol
    await protocol.shutdown()
  File "/usr/local/lib/python3.11/site-packages/aiocoap/protocol.py", line 326, in shutdown
    await item
  File "/usr/local/lib/python3.11/site-packages/aiocoap/tokenmanager.py", line 61, in shutdown
    await self.token_interface.shutdown()
  File "/usr/local/lib/python3.11/site-packages/aiocoap/messagemanager.py", line 65, in shutdown
    for messageerror_monitor, cancellable in self._active_exchanges.values():
                                             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'values'

followed up with:

2023-12-04 20:38:13.545 WARNING (MainThread) [py.warnings] /usr/local/lib/python3.11/site-packages/aiocoap/transports/tinydtls.py:166: UserWarning: DTLS module did not shut down the DTLSSocket perfectly; it still tried to call _write in vain
  warnings.warn("DTLS module did not shut down the DTLSSocket "

and:

Scherm­afbeelding 2023-12-04 om 11 34 50

so the only thing we can do is restart HA…

meanwhile the gateway and dedicated app works as before: just fine

NOTE this is from before the dec 4th Ikea firmware update ruling that out as a new source of trouble.

ok thanks, I see. well, tbh, I don’t have any loose devices, nor did I ever have.

Testing several ‘solutions’ I did endup with an empty group I can not delete just now… This is not the cause of the issue however (since that exists for a long time), but it is awkward…

there is really nothing I can link this to. Only scenario I remotely imagined being related is light commands to the Gateway. I did notice some connection loss on switching scenes, and, when not actually dong that myself, some automated commands to the night lights.

However, I did test that extensively, even rewrote all of my logic eg to not use transition times, but it never helped…

I cant believe we are the only few people using the Tradfri integration being plagued by this.

All the rewrites of the library or updated to the Gateway from Tradfri havent changed this issue either. Really wish the HA codeowners could contact Ikea team own this matter, its the most frequent offender in the system.

Only real contribution I could make currently, is repost the set of errors/warnings we get, since they did change in the last half year or so.

keeping it alive

Scherm­afbeelding 2023-04-13 om 15 33 09

yes, Ive just corrected an reinstated the automation to take care of it, an d trigger on the keep-alive malfunctioning:

  - alias: Reload Tradfri integration
    id: reload_tradfri_integration
    mode: restart
    trigger:
      - platform: event
        event_type: system_log_event
        event_data:
          level: WARNING
        id: observation
      - platform: event
        event_type: system_log_event
        event_data:
          level: ERROR
        id: failed
    condition:
#       or:
#         - >
#           {{trigger.event.data.name == 'tradfri.base_class' and 'Observation failed for'
#             in trigger.event.data.message[0]}}
      - >
        {{trigger.event.data.name == 'homeassistant.components.tradfri' and
          'Keep-alive failed' in trigger.event.data.message[0]}}
#         - >
#           {{trigger.event.data.name == 'coap' and
#               'Error received in UDP connection under DTLS' in trigger.event.data.message[0]}}
    action:
      - service: system_log.write
        data:
          message: >
            Ikea Tradfri '{{trigger.id}}' on {{trigger.event.data.name}} issue logged, reloading integration
          level: warning
          logger: homeassistant.components.tradfri
      - service: script.reload_tradfri_integration
      - service: system_log.write
        data:
          message: >
            Ikea Tradfri integration was reloaded because of {{trigger.id}}
          level: warning
          logger: homeassistant.components.tradfri
      - service: persistent_notification.create
        data:
          title: >
            {{trigger.event.data.level}}: Tradfri reloaded
          message: >
            {{now().timestamp()|timestamp_custom('%X')}}: Ikea Tradfri integration was
              reloaded because of {{trigger.id}}:
              Message: {{trigger.event.data.message[0]}},
              Logger: {{trigger.event.data.name}},
              Source: {{trigger.event.data.source}},
              Level: {{trigger.event.data.level}}

              Full data: {{trigger.event}}

I did comment the other triggers I had before, as they have changed to the ones we have in this issue now.

Keep-alive seems to be the ultimate state into which the system gets after all of the other listed errors, and should be the final moment to have to restart the integration.

this is the result, so you know something happened:

Scherm­afbeelding 2023-03-14 om 07 35 56