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
71.11k stars 29.79k forks source link

ZHA - New 'Firmware update' feature not working (on _TZ3000_2putqrmw device) #110260

Closed flame4ever closed 6 months ago

flame4ever commented 7 months ago

The problem

The ZHA notified me about firmware updates for my _TZ3000_2putqrmw devices.

image image

But when I click on install I get the following error.

image

What version of Home Assistant Core has the issue?

core-2024.2.1

What was the last working version of Home Assistant Core?

-

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Zigbee Home Automation

Link to integration documentation on our website

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

Diagnostics information

config_entry-zha-048b43f8dd1fa44a289c0bc4d3d16b9b.json

Example YAML snippet

zha:
  zigpy_config:
    ota:
      ikea_provider: true                        # Auto update Trådfri devices
      ledvance_provider: true                    # Auto update LEDVANCE/OSRAM devices
      salus_provider: true                       # Auto update SALUS/Computime devices
      inovelli_provider: true                    # Auto update INOVELLI devices
      thirdreality_provider: true                # Auto update 3REALITY devices
      sonoff_provider: true
      #otau_directory: /path/to/your/ota/folder  # Utilize .ota files to update everything else

Anything in the logs that might be useful for us?

2024-02-11 13:14:53.185 DEBUG (MainThread) [zigpy_deconz.api] Sending CommandId.aps_data_request{'request_id': 187, 'flags': <DeconzSendDataFlags.NONE: 0>, 'dst': DeconzAddressEndpoint(address_mode=<AddressMode.NWK: 2>, address=0xAF79, endpoint=1), 'profile_id': 260, 'cluster_id': 2820, 'src_ep': 1, 'asdu': b'\x00\x03\x00\x05\x06\x04\x06\x01\x06', 'tx_options': <DeconzTransmitOptions.USE_NWK_KEY_SECURITY: 2>, 'radius': 0, 'relays': None} (seq=135)
2024-02-11 13:14:53.186 DEBUG (MainThread) [zigpy_deconz.uart] Send: 1287001f001800bb000279af010401040b0109000003000506040601060200
2024-02-11 13:14:53.192 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x1287000900020022bb
2024-02-11 13:14:53.193 DEBUG (MainThread) [zigpy_deconz.api] Received command CommandId.aps_data_request{'status': <Status.SUCCESS: 0>, 'frame_length': 9, 'payload_length': 2, 'device_state': DeviceState(network_state=<NetworkState2.CONNECTED: 2>, device_state=<DeviceStateFlags.APSDE_DATA_REQUEST_FREE_SLOTS_AVAILABLE: 8>), 'request_id': 187} (seq 135)
2024-02-11 13:14:53.615 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x0e88000700aa00
2024-02-11 13:14:53.616 DEBUG (MainThread) [zigpy_deconz.api] Received command CommandId.device_state_changed{'status': <Status.SUCCESS: 0>, 'frame_length': 7, 'device_state': DeviceState(network_state=<NetworkState2.CONNECTED: 2>, device_state=<DeviceStateFlags.APSDE_DATA_INDICATION|APSDE_DATA_REQUEST_FREE_SLOTS_AVAILABLE|32: 42>), 'reserved': 0} (seq 136)
2024-02-11 13:14:53.619 DEBUG (MainThread) [zigpy_deconz.api] Sending CommandId.aps_data_indication{'flags': <DataIndicationFlags.Always_Use_NWK_Source_Addr: 1>} (seq=136)
2024-02-11 13:14:53.620 DEBUG (MainThread) [zigpy_deconz.uart] Send: 1788000800010001
2024-02-11 13:14:53.624 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x17880026001f00220200000102561e010401040b080018200a080521ed0100afffa3636e11d8
2024-02-11 13:14:53.626 DEBUG (MainThread) [zigpy_deconz.api] Received command CommandId.aps_data_indication{'status': <Status.SUCCESS: 0>, 'frame_length': 38, 'payload_length': 31, 'device_state': DeviceState(network_state=<NetworkState2.CONNECTED: 2>, device_state=<DeviceStateFlags.APSDE_DATA_REQUEST_FREE_SLOTS_AVAILABLE: 8>), 'dst_addr': DeconzAddress(address_mode=<AddressMode.NWK: 2>, address=0x0000), 'dst_ep': 1, 'src_addr': DeconzAddress(address_mode=<AddressMode.NWK: 2>, address=0x1E56), 'src_ep': 1, 'profile_id': 260, 'cluster_id': 2820, 'asdu': b'\x18 \n\x08\x05!\xed\x01', 'reserved1': 0, 'reserved2': 175, 'lqi': 255, 'reserved3': 163, 'reserved4': 99, 'reserved5': 110, 'reserved6': 17, 'rssi': -40} (seq 136)
2024-02-11 13:14:53.628 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 2, 11, 12, 14, 53, 627942, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1E56), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=None, profile_id=260, cluster_id=2820, data=Serialized[b'\x18 \n\x08\x05!\xed\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=255, rssi=-40)
2024-02-11 13:14:53.629 DEBUG (MainThread) [zigpy.zcl] [0x1E56:1:0x0b04] Received ZCL frame: b'\x18 \n\x08\x05!\xed\x01'
2024-02-11 13:14:53.629 DEBUG (MainThread) [zigpy.zcl] [0x1E56:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=32, command_id=10, *direction=<Direction.Server_to_Client: 1>)
2024-02-11 13:14:53.631 DEBUG (MainThread) [zigpy.zcl] [0x1E56:1:0x0b04] Decoded ZCL frame: TuyaZBElectricalMeasurement:Report_Attributes(attribute_reports=[Attribute(attrid=0x0508, value=TypeValue(type=uint16_t, value=493))])
2024-02-11 13:14:53.632 DEBUG (MainThread) [zigpy.zcl] [0x1E56:1:0x0b04] Received command 0x0A (TSN 32): Report_Attributes(attribute_reports=[Attribute(attrid=0x0508, value=TypeValue(type=uint16_t, value=493))])
2024-02-11 13:14:53.633 DEBUG (MainThread) [zigpy.zcl] [0x1E56:1:0x0b04] Attribute report received: rms_current=493
2024-02-11 13:14:53.633 DEBUG (MainThread) [homeassistant.components.zha.core.cluster_handlers] [0x1E56:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[493]
2024-02-11 13:14:53.637 DEBUG (Thread-6) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f6a506200>, 'UPDATE devices_v12\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1707653693.627942, 'ieee': a4:c1:38:2f:a9:cb:9c:60, 'min_update_delta': 30.0})
2024-02-11 13:14:53.640 DEBUG (Thread-6) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f6a506200>, 'UPDATE devices_v12\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1707653693.627942, 'ieee': a4:c1:38:2f:a9:cb:9c:60, 'min_update_delta': 30.0}) completed
2024-02-11 13:14:53.642 DEBUG (Thread-6) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f6a506200>)
2024-02-11 13:14:53.642 DEBUG (Thread-6) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f6a506200>) completed
2024-02-11 13:14:53.644 DEBUG (Thread-6) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f6a506200>, '\n            INSERT INTO attributes_cache_v12\n            VALUES (:ieee, :endpoint_id, :cluster_id, :attrid, :value, :timestamp)\n                ON CONFLICT (ieee, endpoint_id, cluster, attrid) DO UPDATE\n                SET value=excluded.value, last_updated=excluded.last_updated\n                WHERE\n                    value != excluded.value\n                    OR :timestamp - last_updated > :min_update_delta\n            ', {'ieee': a4:c1:38:2f:a9:cb:9c:60, 'endpoint_id': 1, 'cluster_id': 2820, 'attrid': 1288, 'value': 493, 'timestamp': 1707653693.633234, 'min_update_delta': 30.0})
2024-02-11 13:14:53.646 DEBUG (Thread-6) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f6a506200>, '\n            INSERT INTO attributes_cache_v12\n            VALUES (:ieee, :endpoint_id, :cluster_id, :attrid, :value, :timestamp)\n                ON CONFLICT (ieee, endpoint_id, cluster, attrid) DO UPDATE\n                SET value=excluded.value, last_updated=excluded.last_updated\n                WHERE\n                    value != excluded.value\n                    OR :timestamp - last_updated > :min_update_delta\n            ', {'ieee': a4:c1:38:2f:a9:cb:9c:60, 'endpoint_id': 1, 'cluster_id': 2820, 'attrid': 1288, 'value': 493, 'timestamp': 1707653693.633234, 'min_update_delta': 30.0}) completed
2024-02-11 13:14:53.649 DEBUG (Thread-6) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f6a506200>)
2024-02-11 13:14:53.650 DEBUG (Thread-6) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f6a506200>) completed

Additional information

No response

home-assistant[bot] commented 7 months ago

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

Code owner commands Code owners of `zha` 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 zha` 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)


zha documentation zha source (message by IssueLinks)

puddly commented 7 months ago

Can you enable ZHA debug logging, reload the integration, and try the update again? Your log snippet unfortunately doesn't contain anything about OTA.

puddly commented 7 months ago

Also, upload diagnostics JSON for that specific device. It's available from the drop-down menu on the device page.

flame4ever commented 7 months ago

Also, upload diagnostics JSON for that specific device. It's available from the drop-down menu on the device page.

The json is available above.

Diagnostics information config_entry-zha-048b43f8dd1fa44a289c0bc4d3d16b9b.json

puddly commented 7 months ago

That is diagnostics for the integration. Every device has diagnostics as well. See the below image:

image
puddly commented 7 months ago

It would be much simpler if you uploaded the device diagnostics for one of your _TZ3000_2putqrmw devices, as in the screenshot above.

flame4ever commented 7 months ago

It would be much simpler if you uploaded the device diagnostics for one of your _TZ3000_2putqrmw devices, as in the screenshot above.

zha-048b43f8dd1fa44a289c0bc4d3d16b9b-_TZ3000_2putqrmw TS011F-1fe12d2fc660202494aa9cbcb3cf2f68.json

flame4ever commented 6 months ago

I have a "ConBee II, s/n: DEXXXXXXX - dresden elektronik ingenieurtechnik GmbH" dongle.

puddly commented 6 months ago

If you are still having this issue, could you:

  1. Enable ZHA debug logging.
  2. Navigate to http://your.homeassistant.url:8123/config/updates
  3. Click the "check for updates" button.
  4. Wait 30s and then disable ZHA debug logging.

I would like to double check the firmware update your device is trying to ask for.

Mookunicorn commented 6 months ago

If you are still having this issue, could you:

  1. Enable ZHA debug logging.
  2. Navigate to http://your.homeassistant.url:8123/config/updates
  3. Click the "check for updates" button.
  4. Wait 30s and then disable ZHA debug logging.

I would like to double check the firmware update your device is trying to ask for.

error_log-3.txt

For lumi.switch.l2aeu1 zha-46603a1ef5f2d5960ec9e235cf41fa22-LUMI lumi.switch.l2aeu1-0cac3e2f427ead2ae43a11acf28a8cca.json