Hey all,
quick question as Iām trying to update my IKEA 4 button remote (IKEA of Sweden Remote Control N2). The update starts and then fails at different progress levels. Since its a battery device, Iām pressing a button every now and then to make sure, it remains alive and connected.
Heres the debug log. Possibly one can point me in a direction.
2024-03-01 09:18:03.967 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply: ImageBlockResponseCommand(status=<Status.SUCCESS: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, image_data=b'(\x90\x07F\
2024-03-01 09:18:03.967 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] no 'image_block' OTA command handler for 'IKEA of Sweden Remote Control N2': ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_v
2024-03-01 09:18:04.034 INFO (MainThread) [zigpy.device] [0x7eea] OTA upgrade progress: (3780 / 218698): 1.7284%
2024-03-01 09:18:05.705 DEBUG (MainThread) [zigpy.util] Tries remaining: 2
2024-03-01 09:18:05.706 DEBUG (MainThread) [zigpy.zcl] [0x526D:11:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Client_to_S
2024-03-01 09:18:05.706 DEBUG (MainThread) [zigpy.zcl] [0x526D:11:0x0006] Sending request: off()
2024-03-01 09:18:05.926 INFO (MainThread) [zigpy.device] [0x7eea] OTA upgrade progress: (3780 / 218698): 1.7284%
2024-03-01 09:18:06.043 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 1, 8, 18, 6, 43071, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7EEA),
2024-03-01 09:18:06.043 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received ZCL frame: b'\x010\x03\x00|\x11\xcb\x11\x05\x00\x04\x02\xc4\x0e\x00\x00?'
2024-03-01 09:18:06.043 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Serv
2024-03-01 09:18:06.044 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame: Ota:ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, maximum_data_size=6
2024-03-01 09:18:06.044 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received command 0x03 (TSN 48): ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, maximum_da
2024-03-01 09:18:06.044 DEBUG (MainThread) [zigpy.device] [0x7eea] OTA image_block handler for 'IKEA of Sweden Remote Control N2': field_control=0, manufacturer_id=4476, image_type=4555, file_version=33816581, file_offset=3780, max_data_size=63, re
2024-03-01 09:18:06.044 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply header: ZCLHeader(frame_control=FrameControl<0x19>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Clie
2024-03-01 09:18:06.045 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply: ImageBlockResponseCommand(status=<Status.SUCCESS: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, image_data=b'(\x90\x07F\
2024-03-01 09:18:06.045 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] no 'image_block' OTA command handler for 'IKEA of Sweden Remote Control N2': ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_v
2024-03-01 09:18:06.943 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 1, 8, 18, 6, 943646, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7EEA)
2024-03-01 09:18:06.944 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received ZCL frame: b'\x011\x03\x00|\x11\xcb\x11\x05\x00\x04\x02\xc4\x0e\x00\x00?'
2024-03-01 09:18:06.944 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Serv
2024-03-01 09:18:06.944 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame: Ota:ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, maximum_data_size=6
2024-03-01 09:18:06.944 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received command 0x03 (TSN 49): ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, maximum_da
2024-03-01 09:18:06.945 DEBUG (MainThread) [zigpy.device] [0x7eea] OTA image_block handler for 'IKEA of Sweden Remote Control N2': field_control=0, manufacturer_id=4476, image_type=4555, file_version=33816581, file_offset=3780, max_data_size=63, re
2024-03-01 09:18:06.945 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply header: ZCLHeader(frame_control=FrameControl<0x19>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Clie
2024-03-01 09:18:06.945 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply: ImageBlockResponseCommand(status=<Status.SUCCESS: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3780, image_data=b'(\x90\x07F\
2024-03-01 09:18:06.946 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] no 'image_block' OTA command handler for 'IKEA of Sweden Remote Control N2': ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_v
...
2024-03-01 09:17:53.567 DEBUG (MainThread) [zigpy.device] [0x7eea] OTA image_block handler for 'IKEA of Sweden Remote Control N2': field_control=0, manufacturer_id=4476, image_type=4555, file_version=33816581, file_offset=3654, max_data_size=63, re
2024-03-01 09:17:53.567 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply header: ZCLHeader(frame_control=FrameControl<0x19>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Clie
2024-03-01 09:17:53.567 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply: ImageBlockResponseCommand(status=<Status.SUCCESS: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3654, image_data=b'jF\x19F\t\x
2024-03-01 09:17:53.568 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] no 'image_block' OTA command handler for 'IKEA of Sweden Remote Control N2': ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_v
2024-03-01 09:17:53.568 INFO (MainThread) [zigpy.device] [0x7eea] OTA upgrade progress: (3654 / 218698): 1.6708%
2024-03-01 09:17:55.088 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139738348399040] Failed to send request: device did not respond
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 240, in handle_call_service
response = await hass.services.async_call(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2279, in async_call
response_data = await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2316, in _execute_service
return await target(service_call)
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 917, in entity_service_call
raise result from None
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1540, in async_request_call
return await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 962, in _handle_entity_call
result = await task
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 639, in async_handle_light_off_service
await light.async_turn_off(**filter_turn_off_params(light, params))
File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 471, in async_turn_off
result = await self._on_off_cluster_handler.off()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 83, in wrapper
with wrap_zigpy_exceptions():
File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__
self.gen.throw(value)
File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 66, in wrap_zigpy_exceptions
raise HomeAssistantError(
homeassistant.exceptions.HomeAssistantError: Failed to send request: device did not respond
2024-03-01 09:17:55.574 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 1, 8, 17, 55, 574693, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7EEA
2024-03-01 09:17:55.575 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received ZCL frame: b'\x01,\x03\x00|\x11\xcb\x11\x05\x00\x04\x02\x85\x0e\x00\x00?'
2024-03-01 09:17:55.575 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Serv
2024-03-01 09:17:55.575 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame: Ota:ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3717, maximum_data_size=6
2024-03-01 09:17:55.575 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received command 0x03 (TSN 44): ImageBlockCommand(field_control=<FieldControl: 0>, manufacturer_code=4476, image_type=4555, file_version=33816581, file_offset=3717, maximum_da
Yes, it sais ādevice not reachableā and thus Iām pressing a button on the remote about every 30 seconds.
Also tried updating via service call and got another error message:
2024-03-01 09:59:41.191 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply: query_next_image_response(status=<Status.NO_IMAGE_AVAILABLE: 152>, manufacturer_code=None, image_type=None, file_version=None, image_size=None)
2024-03-01 09:59:44.192 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 1, 8, 59, 44, 192026, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7EEA
2024-03-01 09:59:44.192 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received ZCL frame: b'\x01\x01\x01\x01|\x11\xcb\x11$\x00\x01\x00\x01\x00'
2024-03-01 09:59:44.192 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Serv
2024-03-01 09:59:44.193 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Decoded ZCL frame: Ota:QueryNextImageCommand(field_control=<FieldControl.HardwareVersion: 1>, manufacturer_code=4476, image_type=4555, current_file_version=65572, hardware_ver
2024-03-01 09:59:44.193 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Received command 0x01 (TSN 1): QueryNextImageCommand(field_control=<FieldControl.HardwareVersion: 1>, manufacturer_code=4476, image_type=4555, current_file_version=65572, hard
2024-03-01 09:59:44.193 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] OTA query_next_image handler for 'IKEA of Sweden Remote Control N2': field_control=1, manufacturer_id=4476, image_type=4555, current_file_version=65572, hardware_version=1, mo
2024-03-01 09:59:44.193 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] OTA image version: 33816581, size: 218698. Update needed: True
2024-03-01 09:59:44.194 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply header: ZCLHeader(frame_control=FrameControl<0x19>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Clie
2024-03-01 09:59:44.194 DEBUG (MainThread) [zigpy.zcl] [0x7EEA:1:0x0019] Sending reply: query_next_image_response(status=<Status.NO_IMAGE_AVAILABLE: 152>, manufacturer_code=None, image_type=None, file_version=None, image_size=None)
2024-03-01 09:59:45.035 ERROR (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Error executing script. Unexpected error for call_service at pos 1: Request failed after 5 attempts: <Status.APS_NO_ACK: 183>
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 485, in _async_step
await getattr(self, handler)()
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 723, in _async_call_service_step
response_data = await self._async_run_long_action(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 685, in _async_run_long_action
return long_task.result()
^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2279, in async_call
response_data = await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2316, in _execute_service
return await target(service_call)
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 993, in _async_admin_handler
await result
File "/usr/src/homeassistant/homeassistant/components/zha/websocket_api.py", line 1363, in issue_zigbee_cluster_command
await zha_device.issue_cluster_command(
File "/usr/src/homeassistant/homeassistant/components/zha/core/device.py", line 839, in issue_cluster_command
response = await getattr(cluster, commands[command].name)(*args)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 415, in reply
return await self._endpoint.reply(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 278, in reply
return await self.device.reply(
^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 488, in reply
return await self.request(
^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 322, in request
await send_request()
File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 833, in request
await self.send_packet(
File "/usr/local/lib/python3.12/site-packages/zigpy_znp/zigbee/application.py", line 1100, in send_packet
raise DeliveryError(
zigpy.exceptions.DeliveryError: Request failed after 5 attempts: <Status.APS_NO_ACK: 183>
2024-03-01 09:59:45.041 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139738266885696] Error handling message: Unknown error (unknown_error) Sebastian from 192.168.25.101 (Mozilla/5.0 (Windows NT 10.0; Win64; x6
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 26, in _handle_async_response
await func(hass, connection, msg)
File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 795, in handle_execute_script
script_result = await script_obj.async_run(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1600, in async_run
return await asyncio.shield(run.async_run())
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 435, in async_run
await self._async_step(log_exceptions=False)
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 487, in _async_step
self._handle_exception(
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 512, in _handle_exception
raise exception
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 485, in _async_step
Thanks for your help.
best