Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[ZHA] Zigbee fails to set up after 2023.11.0 upgrade #103208

Closed
trickv opened this issue Nov 1, 2023 · 16 comments · Fixed by zigpy/zigpy-xbee#166, zigpy/zigpy-xbee#168 or #104335
Closed

[ZHA] Zigbee fails to set up after 2023.11.0 upgrade #103208

trickv opened this issue Nov 1, 2023 · 16 comments · Fixed by zigpy/zigpy-xbee#166, zigpy/zigpy-xbee#168 or #104335
Assignees

Comments

@trickv
Copy link

trickv commented Nov 1, 2023

The problem

I upgraded to 2023.11.0 today and my ZHA integration has failed to load. When I go back to 2023.10.5 it seems to work. Maybe some quirk with my Xbee coordinator?

What version of Home Assistant Core has the issue?

core-2023.11.0

What was the last working version of Home Assistant Core?

core-2023.10.5

What type of installation are you running?

Home Assistant Container

Integration causing the issue

ZHA

Link to integration documentation on our website

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

Diagnostics information

The integration is failing to start so I don't have an option to download diagnostics data, but the logs look useful.

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2023-11-01 16:51:52.984 DEBUG (MainThread) [zigpy.serial] Opening a serial connection to '/dev/ttyUSB0' (57600 baudrate)
2023-11-01 16:51:53.002 DEBUG (MainThread) [zigpy_xbee.uart] Connection made
2023-11-01 16:51:53.003 DEBUG (MainThread) [zigpy_xbee.api] at command: AP (2,)
2023-11-01 16:51:53.003 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'AP', b'\x02')
2023-11-01 16:51:53.003 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x01AP\x02'
2023-11-01 16:51:53.011 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x01AP\x00'
2023-11-01 16:51:53.011 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.012 DEBUG (MainThread) [zigpy_xbee.api] at command: MY ()
2023-11-01 16:51:53.012 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'MY', b'')
2023-11-01 16:51:53.012 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x02MY'
2023-11-01 16:51:53.042 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x02MY\x00\x00\x00'
2023-11-01 16:51:53.043 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.043 DEBUG (MainThread) [zigpy_xbee.api] at command: SH ()
2023-11-01 16:51:53.043 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'SH', b'')
2023-11-01 16:51:53.043 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x03SH'
2023-11-01 16:51:53.059 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x03SH\x00\x00\x13\xa2\x00'
2023-11-01 16:51:53.059 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.059 DEBUG (MainThread) [zigpy_xbee.api] at command: SL ()
2023-11-01 16:51:53.059 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'SL', b'')
2023-11-01 16:51:53.060 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x04SL'
2023-11-01 16:51:53.074 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x04SL\x00A(\x08f'
2023-11-01 16:51:53.074 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.075 DEBUG (MainThread) [zigpy_xbee.api] at command: CE ()
2023-11-01 16:51:53.075 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'CE', b'')
2023-11-01 16:51:53.075 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x05CE'
2023-11-01 16:51:53.090 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x05CE\x00\x01'
2023-11-01 16:51:53.090 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.091 DEBUG (MainThread) [zigpy_xbee.api] at command: OI ()
2023-11-01 16:51:53.091 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'OI', b'')
2023-11-01 16:51:53.091 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x06OI'
2023-11-01 16:51:53.106 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x06OI\x00\t['
2023-11-01 16:51:53.106 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.106 DEBUG (MainThread) [zigpy_xbee.api] at command: ID ()
2023-11-01 16:51:53.106 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'ID', b'')
2023-11-01 16:51:53.107 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x07ID'
2023-11-01 16:51:53.121 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x07ID\x00\x00\x00\x00\x00\x00\x00 \x15'
2023-11-01 16:51:53.122 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.122 DEBUG (MainThread) [zigpy_xbee.api] at command: CH ()
2023-11-01 16:51:53.122 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'CH', b'')
2023-11-01 16:51:53.122 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x08CH'
2023-11-01 16:51:53.137 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x08CH\x00\x0f'
2023-11-01 16:51:53.138 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.138 DEBUG (MainThread) [zigpy.application] Network info: NetworkInfo(extended_pan_id=00:00:00:00:00:00:20:15, pan_id=0x095B, nwk_update_id=0, nwk_manager_id=0x0000, channel=15, channel_mask=<Channels.NO_CHANNELS: 0>, security_level=0, network_key=Key(key=ff:ff:ff:ff:ff:ff:ff:ff:ff:ff:ff:ff:ff:ff:ff:ff, tx_counter=0, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), tc_link_key=Key(key=5a:69:67:42:65:65:41:6c:6c:69:61:6e:63:65:30:39, tx_counter=0, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), key_table=[], children=[], nwk_addresses={}, stack_specific={}, metadata={}, source='zigpy-xbee@0.18.3')
2023-11-01 16:51:53.138 DEBUG (MainThread) [zigpy.application] Node info: NodeInfo(nwk=0x0000, ieee=00:13:a2:00:41:28:08:66, logical_type=<LogicalType.Coordinator: 0>)
2023-11-01 16:51:53.139 DEBUG (MainThread) [zigpy_xbee.api] at command: AI ()
2023-11-01 16:51:53.139 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'AI', b'')
2023-11-01 16:51:53.139 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\tAI'
2023-11-01 16:51:53.154 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\tAI\x00\x00'
2023-11-01 16:51:53.154 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.154 DEBUG (MainThread) [zigpy_xbee.api] at command: AO (3,)
2023-11-01 16:51:53.154 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'AO', b'\x03')
2023-11-01 16:51:53.155 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\nAO\x03'
2023-11-01 16:51:53.170 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\nAO\x00'
2023-11-01 16:51:53.170 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.170 DEBUG (MainThread) [zigpy_xbee.api] at command: EE ()
2023-11-01 16:51:53.170 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'EE', b'')
2023-11-01 16:51:53.170 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x0bEE'
2023-11-01 16:51:53.186 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0bEE\x00\x01'
2023-11-01 16:51:53.187 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.189 DEBUG (MainThread) [zigpy_xbee.api] at command: EO ()
2023-11-01 16:51:53.189 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'EO', b'')
2023-11-01 16:51:53.190 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x0cEO'
2023-11-01 16:51:53.201 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0cEO\x00\x02'
2023-11-01 16:51:53.201 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.202 DEBUG (MainThread) [zigpy_xbee.api] at command: ZS ()
2023-11-01 16:51:53.202 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'ZS', b'')
2023-11-01 16:51:53.202 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\rZS'
2023-11-01 16:51:53.217 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\rZS\x00\x02'
2023-11-01 16:51:53.218 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.218 DEBUG (MainThread) [zigpy_xbee.api] at command: NJ (0,)
2023-11-01 16:51:53.218 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'NJ', b'\x00')
2023-11-01 16:51:53.218 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x0eNJ\x00'
2023-11-01 16:51:53.234 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0eNJ\x00'
2023-11-01 16:51:53.234 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.235 DEBUG (MainThread) [zigpy_xbee.api] at command: SP (768,)
2023-11-01 16:51:53.235 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'SP', b'\x03\x00')
2023-11-01 16:51:53.235 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x0fSP\x03\x00'
2023-11-01 16:51:53.250 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x0fSP\x00'
2023-11-01 16:51:53.250 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.250 DEBUG (MainThread) [zigpy_xbee.api] at command: SN (667,)
2023-11-01 16:51:53.250 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'SN', b'\x02\x9b')
2023-11-01 16:51:53.251 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x10SN\x02\x9b'
2023-11-01 16:51:53.266 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x10SN\x00'
2023-11-01 16:51:53.267 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:53.270 DEBUG (MainThread) [zigpy.application] Device is initialized <XBeeCoordinator model='XBee' manuf='Digi' nwk=0x0000 ieee=00:13:a2:00:41:28:08:66 is_initialized=True>
2023-11-01 16:51:53.271 DEBUG (MainThread) [zigpy_xbee.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2023, 11, 1, 21, 51, 53, 271324, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=3, profile_id=0, cluster_id=<ZDOCmd.Mgmt_Permit_Joining_req: 0x0036>, data=Serialized[b'\x03\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-11-01 16:51:53.271 DEBUG (MainThread) [zigpy_xbee.api] Command tx_explicit (00:00:00:00:00:00:ff:fc, <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>, 0, 0, <ZDOCmd.Mgmt_Permit_Joining_req: 0x0036>, 0, 0, <TXOptions.NONE: 0>, b'\x03\x00\x00')
2023-11-01 16:51:53.272 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x11\x11\x00\x00\x00\x00\x00\x00\xff\xfc\xff\xfc\x00\x00\x006\x00\x00\x00\x00\x03\x00\x00'
2023-11-01 16:51:53.273 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO devices_v12 (ieee, nwk, status, last_seen)\n                    VALUES (?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                        nwk=excluded.nwk,\n                        status=excluded.status,\n                        last_seen=excluded.last_seen', (00:13:a2:00:41:28:08:66, 0x0000, <Status.ENDPOINTS_INIT: 2>, 0.0))
2023-11-01 16:51:53.273 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO devices_v12 (ieee, nwk, status, last_seen)\n                    VALUES (?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                        nwk=excluded.nwk,\n                        status=excluded.status,\n                        last_seen=excluded.last_seen', (00:13:a2:00:41:28:08:66, 0x0000, <Status.ENDPOINTS_INIT: 2>, 0.0)) completed
2023-11-01 16:51:53.276 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO node_descriptors_v12\n                VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                logical_type=excluded.logical_type,\n                complex_descriptor_available=excluded.complex_descriptor_available,\n                user_descriptor_available=excluded.user_descriptor_available,\n                reserved=excluded.reserved,\n                aps_flags=excluded.aps_flags,\n                frequency_band=excluded.frequency_band,\n                mac_capability_flags=excluded.mac_capability_flags,\n                manufacturer_code=excluded.manufacturer_code,\n                maximum_buffer_size=excluded.maximum_buffer_size,\n                maximum_incoming_transfer_size=excluded.maximum_incoming_transfer_size,\n                server_mask=excluded.server_mask,\n                maximum_outgoing_transfer_size=excluded.maximum_outgoing_transfer_size,\n                descriptor_capability_field=excluded.descriptor_capability_field', (00:13:a2:00:41:28:08:66, <LogicalType.Coordinator: 0>, 0, 0, 0, 0, <FrequencyBand.Freq2400MHz: 8>, <MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, 4126, 82, 255, 11264, 255, <DescriptorCapability.NONE: 0>))
2023-11-01 16:51:53.276 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO node_descriptors_v12\n                VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                logical_type=excluded.logical_type,\n                complex_descriptor_available=excluded.complex_descriptor_available,\n                user_descriptor_available=excluded.user_descriptor_available,\n                reserved=excluded.reserved,\n                aps_flags=excluded.aps_flags,\n                frequency_band=excluded.frequency_band,\n                mac_capability_flags=excluded.mac_capability_flags,\n                manufacturer_code=excluded.manufacturer_code,\n                maximum_buffer_size=excluded.maximum_buffer_size,\n                maximum_incoming_transfer_size=excluded.maximum_incoming_transfer_size,\n                server_mask=excluded.server_mask,\n                maximum_outgoing_transfer_size=excluded.maximum_outgoing_transfer_size,\n                descriptor_capability_field=excluded.descriptor_capability_field', (00:13:a2:00:41:28:08:66, <LogicalType.Coordinator: 0>, 0, 0, 0, 0, <FrequencyBand.Freq2400MHz: 8>, <MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, 4126, 82, 255, 11264, 255, <DescriptorCapability.NONE: 0>)) completed
2023-11-01 16:51:53.281 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>)
2023-11-01 16:51:53.281 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>) completed
2023-11-01 16:51:53.283 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, '\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': 00:13:a2:00:41:28:08:66, 'endpoint_id': 1, 'cluster_id': 0, 'attrid': 5, 'value': 'XBee', 'timestamp': 1698875513.270742, 'min_update_delta': 30.0})
2023-11-01 16:51:53.283 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, '\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': 00:13:a2:00:41:28:08:66, 'endpoint_id': 1, 'cluster_id': 0, 'attrid': 5, 'value': 'XBee', 'timestamp': 1698875513.270742, 'min_update_delta': 30.0}) completed
2023-11-01 16:51:53.285 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>)
2023-11-01 16:51:53.285 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>) completed
2023-11-01 16:51:53.286 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, '\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': 00:13:a2:00:41:28:08:66, 'endpoint_id': 1, 'cluster_id': 0, 'attrid': 4, 'value': 'Digi', 'timestamp': 1698875513.270801, 'min_update_delta': 30.0})
2023-11-01 16:51:53.286 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, '\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': 00:13:a2:00:41:28:08:66, 'endpoint_id': 1, 'cluster_id': 0, 'attrid': 4, 'value': 'Digi', 'timestamp': 1698875513.270801, 'min_update_delta': 30.0}) completed
2023-11-01 16:51:53.287 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>)
2023-11-01 16:51:53.287 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>) completed
2023-11-01 16:51:53.288 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO devices_v12 (ieee, nwk, status, last_seen)\n                    VALUES (?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                        nwk=excluded.nwk,\n                        status=excluded.status,\n                        last_seen=excluded.last_seen', (00:13:a2:00:41:28:08:66, 0x0000, <Status.ENDPOINTS_INIT: 2>, 0.0))
2023-11-01 16:51:53.288 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO devices_v12 (ieee, nwk, status, last_seen)\n                    VALUES (?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                        nwk=excluded.nwk,\n                        status=excluded.status,\n                        last_seen=excluded.last_seen', (00:13:a2:00:41:28:08:66, 0x0000, <Status.ENDPOINTS_INIT: 2>, 0.0)) completed
2023-11-01 16:51:53.289 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO node_descriptors_v12\n                VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                logical_type=excluded.logical_type,\n                complex_descriptor_available=excluded.complex_descriptor_available,\n                user_descriptor_available=excluded.user_descriptor_available,\n                reserved=excluded.reserved,\n                aps_flags=excluded.aps_flags,\n                frequency_band=excluded.frequency_band,\n                mac_capability_flags=excluded.mac_capability_flags,\n                manufacturer_code=excluded.manufacturer_code,\n                maximum_buffer_size=excluded.maximum_buffer_size,\n                maximum_incoming_transfer_size=excluded.maximum_incoming_transfer_size,\n                server_mask=excluded.server_mask,\n                maximum_outgoing_transfer_size=excluded.maximum_outgoing_transfer_size,\n                descriptor_capability_field=excluded.descriptor_capability_field', (00:13:a2:00:41:28:08:66, <LogicalType.Coordinator: 0>, 0, 0, 0, 0, <FrequencyBand.Freq2400MHz: 8>, <MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, 4126, 82, 255, 11264, 255, <DescriptorCapability.NONE: 0>))
2023-11-01 16:51:53.289 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'INSERT INTO node_descriptors_v12\n                VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)\n                    ON CONFLICT (ieee)\n                    DO UPDATE SET\n                logical_type=excluded.logical_type,\n                complex_descriptor_available=excluded.complex_descriptor_available,\n                user_descriptor_available=excluded.user_descriptor_available,\n                reserved=excluded.reserved,\n                aps_flags=excluded.aps_flags,\n                frequency_band=excluded.frequency_band,\n                mac_capability_flags=excluded.mac_capability_flags,\n                manufacturer_code=excluded.manufacturer_code,\n                maximum_buffer_size=excluded.maximum_buffer_size,\n                maximum_incoming_transfer_size=excluded.maximum_incoming_transfer_size,\n                server_mask=excluded.server_mask,\n                maximum_outgoing_transfer_size=excluded.maximum_outgoing_transfer_size,\n                descriptor_capability_field=excluded.descriptor_capability_field', (00:13:a2:00:41:28:08:66, <LogicalType.Coordinator: 0>, 0, 0, 0, 0, <FrequencyBand.Freq2400MHz: 8>, <MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, 4126, 82, 255, 11264, 255, <DescriptorCapability.NONE: 0>)) completed
2023-11-01 16:51:53.290 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>)
2023-11-01 16:51:53.290 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fa3887489a0>) completed
2023-11-01 16:51:54.237 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x8b\x11\xff\xfe\x00\x00\x00'
2023-11-01 16:51:54.238 DEBUG (MainThread) [zigpy_xbee.api] Frame received: tx_status
2023-11-01 16:51:54.238 DEBUG (MainThread) [zigpy_xbee.api] tx_explicit to 0xfffe: TXStatus.SUCCESS after 0 tries. Discovery Status: DiscoveryStatus.SUCCESS, Frame #17
2023-11-01 16:51:54.239 DEBUG (MainThread) [zigpy_xbee.api] at command: NJ (0,)
2023-11-01 16:51:54.239 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'NJ', b'\x00')
2023-11-01 16:51:54.239 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x12NJ\x00'
2023-11-01 16:51:54.253 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x12NJ\x00'
2023-11-01 16:51:54.253 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:54.254 DEBUG (MainThread) [zigpy_xbee.api] at command: AC ()
2023-11-01 16:51:54.254 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'AC', b'')
2023-11-01 16:51:54.254 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x13AC'
2023-11-01 16:51:54.270 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x13AC\x00'
2023-11-01 16:51:54.270 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:54.270 DEBUG (MainThread) [zigpy_xbee.api] at command: ED (4,)
2023-11-01 16:51:54.271 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'ED', b'\x00\x00\x00\x00')
2023-11-01 16:51:54.271 DEBUG (MainThread) [zigpy_xbee.uart] Sending: b'\x08\x14ED\x00\x00\x00\x00'
2023-11-01 16:51:54.285 DEBUG (MainThread) [zigpy_xbee.uart] Frame received: b'\x88\x14ED\x03'
2023-11-01 16:51:54.285 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-01 16:51:54.285 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start XBee = Digi XBee Zigbee radios: Digi XBee Series 2, 2C, 3 coordinator (attempt 3 of 3)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 209, in async_initialize
    await self.application_controller.startup(auto_form=True)
  File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 214, in startup
    await self.initialize(auto_form=auto_form)
  File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 184, in initialize
    results = await self.energy_scan(
              ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy_xbee/zigbee/application.py", line 199, in energy_scan
    results = await self._api._at_command("ED", duration_exp)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy_xbee/api.py", line 418, in _at_partial
    return await asyncio.wait_for(
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/asyncio/tasks.py", line 489, in wait_for
    return fut.result()
           ^^^^^^^^^^^^
RuntimeError: AT Command response: INVALID_PARAMETER
2023-11-01 16:51:54.291 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7fa3881b9e40>)
2023-11-01 16:51:54.291 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7fa3881b9e40>) completed
2023-11-01 16:51:54.293 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'PRAGMA wal_checkpoint;', [])
2023-11-01 16:51:54.295 DEBUG (MainThread) [zigpy_xbee.uart] Closed serial connection
2023-11-01 16:51:54.302 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fa3887489a0>, 'PRAGMA wal_checkpoint;', []) completed
2023-11-01 16:51:54.304 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7fa3881b9940>)
2023-11-01 16:51:54.304 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7fa3881b9940>) completed
2023-11-01 16:51:54.305 DEBUG (Thread-7) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Connection object at 0x7fa3887489a0>)
2023-11-01 16:51:54.306 DEBUG (Thread-7) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Connection object at 0x7fa3887489a0>) completed
2023-11-01 16:51:54.411 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry FT232R USB UART - FT232R USB UART, s/n: A50285BI - FTDI for zha
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 402, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 164, in async_setup_entry
    await zha_gateway.async_initialize()
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 224, in async_initialize
    raise exc
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 209, in async_initialize
    await self.application_controller.startup(auto_form=True)
  File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 214, in startup
    await self.initialize(auto_form=auto_form)
  File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 184, in initialize
    results = await self.energy_scan(
              ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy_xbee/zigbee/application.py", line 199, in energy_scan
    results = await self._api._at_command("ED", duration_exp)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy_xbee/api.py", line 418, in _at_partial
    return await asyncio.wait_for(
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/asyncio/tasks.py", line 489, in wait_for
    return fut.result()
           ^^^^^^^^^^^^
RuntimeError: AT Command response: INVALID_PARAMETER

Additional information

No response

@home-assistant
Copy link

home-assistant bot commented Nov 1, 2023

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.

(message by CodeOwnersMention)


zha documentation
zha source
(message by IssueLinks)

@puddly
Copy link
Contributor

puddly commented Nov 1, 2023

@Shulyaka it seems like zigpy/zigpy-xbee#149 is not compatible with all XBee firmwares

@Shulyaka
Copy link
Contributor

Shulyaka commented Nov 1, 2023

@trickv which module and firmware do you have (if you know)?

@Shulyaka
Copy link
Contributor

Shulyaka commented Nov 1, 2023

@trickv We are preparing a fix. As a workaround, if you have access to the file system, in your /usr/local/lib/python3.11/site-packages/zigpy_xbee/zigbee/application.py, line 195 (at the start of the energy_scan function), please insert the following line:

        return {c: 0 for c in channels}

Example:

    async def energy_scan(
        self, channels: zigpy.types.Channels, duration_exp: int, count: int
    ) -> dict[int, float]:
        """Runs an energy detection scan and returns the per-channel scan results."""
        return {c: 0 for c in channels}
        all_results = {}

        for _ in range(count):
            results = await self._api._at_command("ED", duration_exp)
...

@trickv
Copy link
Author

trickv commented Nov 2, 2023

@trickv which module and firmware do you have (if you know)?

Took me a while, I had to go get XCTU out to figure out the firmware version :)
My module is an Xbee S2C with firmware version 4061 which looks to be the latest (https://hub.digi.com/support/products/digi-xbee/digi-xbee-s2c/?path=/support/asset/xbee-zb-s2c-firmware-4061/)

I'll go try that workaround now. Thanks!

@trickv
Copy link
Author

trickv commented Nov 2, 2023

@trickv We are preparing a fix. As a workaround, if you have access to the file system, in your /usr/local/lib/python3.11/site-packages/zigpy_xbee/zigbee/application.py, line 195 (at the start of the energy_scan function), please insert the following line:

        return {c: 0 for c in channels}

Example:

    async def energy_scan(
        self, channels: zigpy.types.Channels, duration_exp: int, count: int
    ) -> dict[int, float]:
        """Runs an energy detection scan and returns the per-channel scan results."""
        return {c: 0 for c in channels}
        all_results = {}

        for _ in range(count):
            results = await self._api._at_command("ED", duration_exp)
...

Hacked in-place on my 2023.11.0 container and this workaround does the trick. Thanks!

I'll keep an eye out for your upstream patch to make it into a release and give it a go when it does.

@zacolly
Copy link

zacolly commented Nov 2, 2023

I have the same issue with a conbee II USB dongle
I tried downgrading core to 2023.10.5 but zigbee still not working
I am running OS so I am not sure I can get to file structure, don't know enough about that.
No sure if this log file is helpful
home-assistant.log
Anything I can try?

@trickv
Copy link
Author

trickv commented Nov 2, 2023

I have the same issue with a conbee II USB dongle I tried downgrading core to 2023.10.5 but zigbee still not working I am running OS so I am not sure I can get to file structure, don't know enough about that. No sure if this log file is helpful home-assistant.log Anything I can try?

Hi @zacolly - I'm not a Zigbee expert, but reading your comment and looking at the log file, this isn't the same bug that I hit. Mine was specific to the underlying library that uses an Xbee as my Zigbee coordinator; the Conbee uses a different backend. The patch mentioned here won't fix your issue.

I'd recommend opening a new bug report and specifically mention Conbee in the title to see if anyone else with a Conbee is having trouble.

@TheJulianJES
Copy link
Member

@zacolly Yeah, that's another issue. TXStatus.MAC_CHANNEL_ACCESS_FAILURE indicates you have too much interference. Not related to the update.
Make sure to use a USB extension cable for the Conbee, move it away from APs/metal, USB 3 SSDs, ...

@zacolly
Copy link

zacolly commented Nov 3, 2023

Thanks @TheJulianJES
Amateur mistake, was reconfiguring my data cabinet devices at the same time as the update and had my HA NUC temporarily shoved out of the way. Now I know why the downgrade didn't work :)

@DominiqueGEORGES-SBDG
Copy link

Hi.

I lost all the mnemonics used by my Zigbee devices, I have to find back all the uid (that only HA can understand, but not a human) and reconfigure my scripts.
A real nightmare :'(

Maybe did you already had such an issue (it is a real issue, because nothing was working), and a way to convert unreadble uid into human readable is :-) .

Thanks.
Dom

@F4bsi
Copy link

F4bsi commented Nov 5, 2023

I have a similar issue with a digi x stick. But it says "Invalid_Command" instead of "Invalid_Parameter".

I also tried the fix in zigpy/zigpy-xbee#168, but this did not work.
But using return {c: 0 for c in channels} did the trick and allowed me to start, but it seems like I cannot use any of my zigbee devices and get lots of timeouts.
I just have to find out wether this is because I tried to do a firmware update with xctu or if this is another issue.

Not sure if evrything important is inside the log:

Error Log

2023-11-05 23:09:20.371 DEBUG (MainThread) [zigpy_xbee.api] at command: NJ (0,)
2023-11-05 23:09:20.372 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'NJ', b'\x00')
2023-11-05 23:09:20.385 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-05 23:09:20.386 DEBUG (MainThread) [zigpy_xbee.api] at command: AC ()
2023-11-05 23:09:20.386 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'AC', b'')
2023-11-05 23:09:20.401 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-05 23:09:20.403 DEBUG (MainThread) [zigpy_xbee.api] at command: ED (b'\x04',)
2023-11-05 23:09:20.403 DEBUG (MainThread) [zigpy_xbee.api] Command at (b'ED', b'\x04')
2023-11-05 23:09:20.417 DEBUG (MainThread) [zigpy_xbee.api] Frame received: at_response
2023-11-05 23:09:20.548 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry XStick, s/n: n/a - Digi for zha
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 402, in async_setup
result = await component.async_setup_entry(hass, self)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/zha/init.py", line 164, in async_setup_entry
await zha_gateway.async_initialize()
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 224, in async_initialize
raise exc
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 209, in async_initialize
await self.application_controller.startup(auto_form=True)
File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 214, in startup
await self.initialize(auto_form=auto_form)
File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 184, in initialize
results = await self.energy_scan(
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/zigpy_xbee/zigbee/application.py", line 199, in energy_scan
results = await self._api._at_command("ED", bytes([duration_exp]))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/zigpy_xbee/api.py", line 418, in _at_partial
return await asyncio.wait_for(
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/asyncio/tasks.py", line 489, in wait_for
return fut.result()
^^^^^^^^^^^^
RuntimeError: AT Command response: INVALID_COMMAND

@Shulyaka
Copy link
Contributor

Shulyaka commented Nov 5, 2023

Hi @F4bsi , which firmware do you have?

@F4bsi
Copy link

F4bsi commented Nov 5, 2023

Hey @Shulyaka, thanks for the help :)
This is what XCTU says:
grafik
Its an really old Digi XStick2 ZB (at least thats what it says on the sticker on the stick)

@drug123
Copy link

drug123 commented Nov 12, 2023

Hey @Shulyaka, thanks for the help :) This is what XCTU says: grafik Its an really old Digi XStick2 ZB (at least thats what it says on the sticker on the stick)

Hi, I can confirm my XBee2 with the latest Coordinator API firmware (21A7) also has this issue. I have used the recommended manual patch and it is fully working now.

@trickv
Copy link
Author

trickv commented Dec 2, 2023

Running home-assistant 2023.12.0b1 which includes zigpy-zbee==0.20.0 and it's working out of the box for me 👍

@github-actions github-actions bot locked and limited conversation to collaborators Jan 1, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.