search

doudz / homeassistant-zigate

zigate component for Home Assistant
MIT License
48 stars 13 forks source link

Unable to add devices on v0.40.7 #140

Closed ruimarinho closed 4 years ago

ruimarinho commented 4 years ago

Hi @doudz,

I am trying to add two new devices and this is what I'm getting:

2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61445, lqi:0
2020-09-15 23:18:21 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x02\x10M\x02\x10\x02\x1dH\xd8\x8c\x02\x10\x15\x8d\x02\x10\x02\x14{\xbd\x86\x80\x02\x10\x02\x10\x03'
2020-09-15 23:18:21 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16@\x02\x13\x02\x10\x02\x10\xf1\x02\x11\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf0\x02\x15\x02\x10\x03\x01'
2020-09-15 23:18:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'd88c00158d00047bbd868000'
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:d88c, ieee:00158d00047bbd86, mac_capability:10000000, rejoin_status:False, lqi:0
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:d88c, ieee:00158d00047bbd86, mac_capability:10000000, rejoin_status:False, lqi:0
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_ADDED
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [custom_components.zigate] Add device Device  (d88c) 00158d00047bbd86
2020-09-15 23:18:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x02\x10M\x02\x10\x02\x1d\xde\x02\x12D\x02\x14\xcf\x8c\xdf<|\xb37\x84\x02\x10\x02\x10\x03'
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f101'
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61697, lqi:0
2020-09-15 23:18:21 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-15 23:18:21 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new zigate.zigate entity: zigate.00158d00047bbd86
2020-09-15 23:18:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-15 23:18:21 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f005'
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61445, lqi:0
2020-09-15 23:18:21 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] discover_device d88c
2020-09-15 23:18:21 DEBUG (ZiGate-Decode data) [zigate] no endpoints2020-09-15 23:30:37 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16C\x02\x13\x02\x10\x02\x10\xf1\x02\x12\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf1\x02\x14\x02\x10\x03\x01\x805\x02\x10\x02\x16@\x02\x13\x02\x10\x02\x10\xf1\x02\x11\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03'
2020-09-15 23:30:37 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03\x01\x805\x02\x10\x02\x16C\x02\x13\x02\x10\x02\x10\xf1\x02\x12\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf1\x02\x14\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03'
2020-09-15 23:30:37 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED

and on the other device:

2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'024404cf8cdf3c7cb3378400'
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:0244, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:0244, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_ADDED
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [custom_components.zigate] Add device Device  (0244) 04cf8cdf3c7cb337
2020-09-15 23:17:51 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new zigate.zigate entity: zigate.04cf8cdf3c7cb337
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] discover_device 0244
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] no endpoints
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] REQUEST : 0x0045 0244
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] Msg to send b'00450002010244'
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] Encoded Msg to send b'0102104502100212021102124403'
2020-09-15 23:17:51 DEBUG (ZiGate-Decode data) [zigate] Waiting for status message for command 0x0045
...
2020-09-15 23:18:48 ERROR (MainThread) [homeassistant.helpers.entity] Update for zigate.04cf8cdf3c7cb337 fails
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 263, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 456, in async_device_update
    await self.hass.async_add_executor_job(
  File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/zigate/__init__.py", line 816, in update
    self._device.refresh_device()
  File "/usr/local/lib/python3.8/site-packages/zigate/core.py", line 2845, in refresh_device
    if self.last_seen > last_1h:

Any idea what's happening? The device simply says "unknown" state on HASS.

This is a Xiaomi Mijia GZCGQ01LM (https://zigbee.blakadder.com/Xiaomi_GZCGQ01LM.html) and Aqara Water Leak Sensor SJCGQ11LM (https://zigbee.blakadder.com/Xiaomi_SJCGQ11LM.html).

doudz commented 4 years ago

Fixed, thanks

ruimarinho commented 4 years ago

@doudz thanks for the quick fix. However, still no endpoints are discovered:

2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:9fdc, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:9fdc, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-17 11:39:41 WARNING (ZiGate-Decode data) [zigate] Device already exists with another addr 2762, rename it.
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device Device  (9fdc) 04cf8cdf3c7cb337
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device Device  (9fdc) 04cf8cdf3c7cb337
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_ADDRESS_CHANGED
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update device Device  (9fdc) 04cf8cdf3c7cb337
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] discover_device 9fdc
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] no endpoints
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] REQUEST : 0x0045 9fdc
2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] Msg to send b'00450002049fdc'

Could this be a bad zigate unit?

doudz commented 4 years ago

2020-09-17 11:39:41 DEBUG (ZiGate-Decode data) [zigate] REQUEST : 0x0045 9fdc

what happens next ? request 0x0045 search for actives endpoints You should receive a response 0x8045

ruimarinho commented 4 years ago

Let me see if widening the log search helps:

2020-09-17 11:40:42 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:42 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:42 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x02\x10M\x02\x10\x02\x1dj\xef\x1d\x02\x14\xcf\x8c\xdf<|\xb37\x84\x02\x10\x02\x10\x03'
2020-09-17 11:40:43 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'ef1d04cf8cdf3c7cb3378400'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:ef1d, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:ef1d, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-17 11:40:43 WARNING (ZiGate-Decode data) [zigate] Device already exists with another addr 9fdc, rename it.
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device Device  (ef1d) 04cf8cdf3c7cb337
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device Device  (ef1d) 04cf8cdf3c7cb337
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_ADDRESS_CHANGED
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update device Device  (ef1d) 04cf8cdf3c7cb337
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] discover_device ef1d
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] no endpoints
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] REQUEST : 0x0045 ef1d
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Msg to send b'00450002b5ef1d'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Encoded Msg to send b'0102104502100212b5ef1d03'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Waiting for status message for command 0x0045
2020-09-17 11:40:43 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15@\x80\x02\x10\x02\x10E\x02\x10\x03'
2020-09-17 11:40:43 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'80000045'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:69, error:b'', lqi:0
2020-09-17 11:40:43 ERROR (ZiGate-Decode data) [zigate] Command 0x0045 failed Failed (ZigBee event codes) 0x80 : b''
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] STATUS code to command 0x0045:RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:69, error:b'', lqi:0
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16@\x02\x13\x02\x10\x02\x10\xf1\x02\x11\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf0\x02\x15\x02\x10\x03'
2020-09-17 11:40:46 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f101'
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61697, lqi:0
2020-09-17 11:40:46 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-17 11:40:46 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f005'
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61445, lqi:0
2020-09-17 11:40:46 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x02\x10M\x02\x10\x02\x1dj\xef\x1d\x02\x14\xcf\x8c\xdf<|\xb37\x84\x02\x10\x02\x10\x03'
2020-09-17 11:40:46 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'ef1d04cf8cdf3c7cb3378400'
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:ef1d, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:ef1d, ieee:04cf8cdf3c7cb337, mac_capability:10000100, rejoin_status:False, lqi:0
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device Device  (ef1d) 04cf8cdf3c7cb337
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device Device  (ef1d) 04cf8cdf3c7cb337
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_UPDATED
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update device Device  (ef1d) 04cf8cdf3c7cb337
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:50 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf1\x02\x14\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03'
2020-09-17 11:40:50 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:50 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f104'
2020-09-17 11:40:50 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61700, lqi:0
2020-09-17 11:40:50 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:50 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:50 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:50 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-17 11:40:50 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-17 11:40:50 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:50 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16C\x02\x13\x02\x10\x02\x10\xf1\x02\x12\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf1\x02\x14\x02\x10\x03'
2020-09-17 11:40:51 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f102'
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61698, lqi:0
2020-09-17 11:40:51 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f104'
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61700, lqi:0
2020-09-17 11:40:51 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16@\x02\x13\x02\x10\x02\x10\xf1\x02\x11\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03'
2020-09-17 11:40:51 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f101'
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61697, lqi:0
2020-09-17 11:40:51 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-17 11:40:51 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 11:40:51 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] discover_device ef1d
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] no mac_capability
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] REQUEST : 0x0042 ef1d
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] Msg to send b'00420002b2ef1d'
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] Encoded Msg to send b'0102104202100212b2ef1d03'
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] Waiting for status message for command 0x0042
2020-09-17 11:40:59 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15G\x80\x02\x10\x02\x10B\x02\x10\x03'
2020-09-17 11:40:59 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:59 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'80000042'
2020-09-17 11:40:59 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:66, error:b'', lqi:0
2020-09-17 11:40:59 ERROR (ZiGate-Decode data) [zigate] Command 0x0042 failed Failed (ZigBee event codes) 0x80 : b''
2020-09-17 11:40:59 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] STATUS code to command 0x0042:RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:66, error:b'', lqi:0
2020-09-17 11:41:09 DEBUG (SyncWorker_48) [zigate] discover_device ef1d
2020-09-17 11:41:09 DEBUG (SyncWorker_48) [zigate] no mac_capability
2020-09-17 11:41:09 DEBUG (SyncWorker_48) [zigate] Msg to send b'00420002b2ef1d'
2020-09-17 11:41:09 DEBUG (SyncWorker_48) [zigate] Encoded Msg to send b'0102104202100212b2ef1d03'
2020-09-17 11:41:09 DEBUG (SyncWorker_48) [zigate] Waiting for status message for command 0x0042
2020-09-17 11:41:09 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15G\x80\x02\x10\x02\x10B\x02\x10\x03'
2020-09-17 11:41:09 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:41:09 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'80000042'
2020-09-17 11:41:09 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:66, error:b'', lqi:0
2020-09-17 11:41:09 ERROR (ZiGate-Decode data) [zigate] Command 0x0042 failed Failed (ZigBee event codes) 0x80 : b''
2020-09-17 11:41:09 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:41:09 DEBUG (SyncWorker_48) [zigate] STATUS code to command 0x0042:RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:66, error:b'', lqi:0
2020-09-17 11:41:14 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10\x02\x1e\x9a\xfdH\xe1\x02\x18\x02\x10\x02\x16\x02\x10\x02\x10\x02\x10 \x02\x10\x02\x11\x02\x10l\x03'
2020-09-17 11:41:14 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'fd48e108000600000020000100'
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:253, addr:48e1, endpoint:8, cluster:6, attribute:0, status:0, data_type:32, size:1, data:0, lqi:108
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED
2020-09-17 11:41:14 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update attribute for device LUMI lumi.router (48e1) 00124b001f3205d7 {'endpoint': 8, 'cluster': 6, 'addr': '48e1', 'attribute': 0, 'data': 0, 'name': 'multiclick', 'type': <class 'int'>, 'value': 0}
doudz commented 4 years ago 
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] REQUEST : 0x0045 ef1d
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Msg to send b'00450002b5ef1d'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Encoded Msg to send b'0102104502100212b5ef1d03'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Waiting for status message for command 0x0045
2020-09-17 11:40:43 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15@\x80\x02\x10\x02\x10E\x02\x10\x03'
2020-09-17 11:40:43 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'80000045'
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:69, error:b'', lqi:0
2020-09-17 11:40:43 ERROR (ZiGate-Decode data) [zigate] Command 0x0045 failed Failed (ZigBee event codes) 0x80 : b''
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] STATUS code to command 0x0045:RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:69, error:b'', lqi:0

The problem is here, the request 0x0045 fails,

Same for request 0x0042

2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] REQUEST : 0x0042 ef1d
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] Msg to send b'00420002b2ef1d'
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] Encoded Msg to send b'0102104202100212b2ef1d03'
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] Waiting for status message for command 0x0042
2020-09-17 11:40:59 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15G\x80\x02\x10\x02\x10B\x02\x10\x03'
2020-09-17 11:40:59 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 11:40:59 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'80000042'
2020-09-17 11:40:59 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:66, error:b'', lqi:0
2020-09-17 11:40:59 ERROR (ZiGate-Decode data) [zigate] Command 0x0042 failed Failed (ZigBee event codes) 0x80 : b''
2020-09-17 11:40:59 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 11:40:59 DEBUG (SyncWorker_51) [zigate] STATUS code to command 0x0042:RESPONSE 0x8000 - Status response : status:128, sequence:0, packet_type:66, error:b'', lqi:0

I think you have a problem with your zigate, you should try to restart it (soft reset) maybe related to the PDM event E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE ? if problem persists, you should ask @fairecasoimeme

pipiche38 commented 4 years ago

What is your firmware version ? IS with Zigpy a possibility to know if Association has been though and the Key has been exchanged ? Usually this where there is any issue with firmware 31d .

So if that is the case there are one point:

Do not start provisionning with 0x0045 until you got the final and true Device Annoucement

ruimarinho commented 4 years ago

I think you have a problem with your zigate, you should try to restart it (soft reset)

Already did.

if problem persists, you should ask @fairecasoimeme

Started an email thread about potentially bad PDM. I don't think it's normal to receive E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE every 6 seconds, 24x7.

@pipiche38 v3.1c.

pipiche38 commented 4 years ago

This looks a known bug from 31c most-likely a corrupted PDM. Usally the only way is Erase PDM and re-pair all devices

On the other side, I think that there is an issue in zigpy as they seems starting the provisioning while the device is not full paired to Zigate.

doudz commented 4 years ago

@pipiche38 This is not zigpy

doudz commented 4 years ago

Do not start provisionning with 0x0045 until you got the final and true Device Annoucement

Are you talking about response 0x004D ? or should we wait for other thing ?

ruimarinho commented 4 years ago

@doudz considering https://github.com/doudz/zigate/commit/c576480b935bb62b9a00907e6689553f093ca783, what are my options for erasing PDM (or EEPROM as well) on macOS?

pipiche38 commented 4 years ago

In fact they are at least 2 0x004D which are sent during a pairing process.

  1. the first one is sent as the first step of association. In that step the 0x004D is sent with a Join Flag information and the LQI is set to a real value.
  2. The second 0x004d is then sent when the full pairing is done (meaning that the association key has been exchanged). In that case you don't have the Join Flag and LQI is set to 0.

Here are the information related to the JoinFlag: When receiving a Device Annoucement the Rejoin Flag can give us some information 0x00 The device was not on the network. Most-likely it has been reset, and all Unbind, Bind , Report, must be redone 0x01 The device was on the Network, but change its route the device was not reset 0x02, 0x03 The device was on the network and coming back. Here we can assumed the device was not reset.

pipiche38 commented 4 years ago

Just to add, you need to receive the 2 0x004D in order to known exactly what to do as if the ReJoin Flag might have to be taken in consideration when receiving the true 0x004D

pipiche38 commented 4 years ago

@pipiche38 This is not zigpy

Sorry for the confusion on my end

doudz commented 4 years ago

@pipiche38 I'm not sure this is correct because in the current case the rejoin flag is set to 0x00 in both case

2020-09-17 11:40:43 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'ef1d04cf8cdf3c7cb3378400'
2020-09-17 11:40:46 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'ef1d04cf8cdf3c7cb3378400'
doudz commented 4 years ago

@doudz considering doudz/zigate@c576480, what are my options for erasing PDM (or EEPROM as well) on macOS?

from HA you can call the service raw_command to call the request 0x0012 Erase Persistent Data

ruimarinho commented 4 years ago

Thanks! Do you recommend any steps in terms of maintenance before erasing PDM? Like attempting to manually remove devices, deleting zigate.json or any other cleanup task?

doudz commented 4 years ago

If you plan to restore all devices, juste keep all as is. If you want to remove some devices, delete the zigate.json file to start from scratch.

doudz commented 4 years ago

you could also make a backup of your zigate before, just in case of python3 -m zigate.flasher -p /dev/ttyUSB0 -s backup.img

python3 -m zigate.flasher --help
usage: flasher.py [-h] -p {/dev/ttyS0} [-w WRITE] [-s SAVE] [-u] [-d] [--gpio]
                  [--din]

optional arguments:
  -h, --help            show this help message and exit
  -p {/dev/ttyS0}, --serialport {/dev/ttyS0}
                        Serial port, e.g. /dev/ttyUSB0
  -w WRITE, --write WRITE
                        Firmware bin to flash onto the chip
  -s SAVE, --save SAVE  File to save the currently loaded firmware to
  -u, --upgrade         Download and flash the lastest available firmware
  -d, --debug           Set log level to DEBUG
  --gpio                Configure GPIO for PiZiGate flash
  --din                 Configure USB for ZiGate DIN flash
ruimarinho commented 4 years ago

I did this with zigate module directly by calling z.erase_persistent(), but I don't think it worked:

DEBUG:zigate:Try loading persistent file
DEBUG:zigate:Trying to load /root/.zigate.json
DEBUG:zigate:Load neighbours cache: []
DEBUG:zigate:Load success
INFO:zigate:Searching ZiGate port
INFO:zigate:ZiGate found at /dev/ttyUSB0
DEBUG:zigate:REQUEST : 0x0018 b'\x01'
DEBUG:zigate:Msg to send b'001800011801'
DEBUG:zigate:Encoded Msg to send b'010210180210021118021103'
DEBUG:zigate:Waiting for status message for command 0x0018
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x9d\x02\x10\x02\x10\x02\x10\x18\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00000018'
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:24, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0018:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:24, error:b'', lqi:0
DEBUG:zigate:REQUEST : 0x0010
DEBUG:zigate:Msg to send b'0010000010'
DEBUG:zigate:Encoded Msg to send b'01021010021002101003'
DEBUG:zigate:Waiting for status message for command 0x0010
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x95\x02\x10\x02\x10\x02\x10\x10\x02\x10\x03\x01\x80\x10\x02\x10\x02\x15\x89\x02\x10\x02\x13\x02\x13\x1c\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00000010'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', lqi:0
DEBUG:zigate:Received response 0x8010: b'0003031c'
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:RESPONSE 0x8010 - Version list : major:3, installer:31c, lqi:0, version:3.1c
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0010:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', lqi:0
DEBUG:zigate:Waiting for message 0x8010
DEBUG:zigate:Stop waiting, got message 0x8010
DEBUG:zigate:REQUEST : 0x0021 b'\x07\x18\xc8\x00'
DEBUG:zigate:Msg to send b'00210004f20718c800'
DEBUG:zigate:Encoded Msg to send b'0102102102100214f2021718c8021003'
DEBUG:zigate:Waiting for status message for command 0x0021
DEBUG:zigate:Raw packet received, b'\x01\x805\x02\x10\x02\x16A\x02\x13\x02\x10\x02\x10\xf1\x02\x10\x02\x10\x03\x01\x80\x02\x10\x02\x10\x02\x15\xa4\x02\x10\x02\x10\x02\x10!\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8035: b'030000f100'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8035 - PDM Event : status:3, record:61696, lqi:0
DEBUG:zigate:Received response 0x8000: b'00000021'
WARNING:zigate:PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:33, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0021:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:33, error:b'', lqi:0
DEBUG:zigate:REQUEST : 0x0023 b'\x00'
DEBUG:zigate:Msg to send b'002300012200'
DEBUG:zigate:Encoded Msg to send b'010210230210021122021003'
DEBUG:zigate:Waiting for status message for command 0x0023
DEBUG:zigate:Raw packet received, b'\x01\x805\x02\x10\x02\x16\xb1\x02\x13\x02\x10\x02\x10\x02\x10\x02\x11\x02\x10\x03\x01\x80\x02\x10\x02\x10\x02\x15\xa6\x02\x10\x02\x10\x02\x10#\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8035: b'0300000001'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8035 - PDM Event : status:3, record:1, lqi:0
DEBUG:zigate:Received response 0x8000: b'00000023'
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:35, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
WARNING:zigate:PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0023:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:35, error:b'', lqi:0
DEBUG:zigate:Check network state
DEBUG:zigate:REQUEST : 0x0009
DEBUG:zigate:Msg to send b'0009000009'
DEBUG:zigate:Encoded Msg to send b'010210021902100210021903'
DEBUG:zigate:Waiting for status message for command 0x0009
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x8c\x02\x10\x02\x10\x02\x10\x02\x19\x02\x10\x03\x01\x80\x02\x19\x02\x10\x16\x8a\x02\x10\x02\x10\x02\x10\x15\x8d\x02\x10\x02\x11\xedF\xb0\xf6\xf9\x1e\x12%\xac&\x1c\xd8\xf4\x02\x1b\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00000009'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:9, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Received response 0x8009: b'000000158d0001ed46b0f6f91e1225ac261cd8f40b'
DEBUG:zigate:RESPONSE 0x8009 - Network state response : addr:0000, ieee:00158d0001ed46b0, panid:63225, extended_panid:2166835792022657268, channel:11, lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0009:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:9, error:b'', lqi:0
DEBUG:zigate:Waiting for message 0x8009
DEBUG:zigate:Stop waiting, got message 0x8009
DEBUG:zigate:Set Zigate normal mode (firmware >= 3.1a)
DEBUG:zigate:REQUEST : 0x0002 b'\x00'
DEBUG:zigate:Msg to send b'000200010300'
DEBUG:zigate:Encoded Msg to send b'0102100212021002110213021003'
DEBUG:zigate:Waiting for status message for command 0x0002
DEBUG:zigate:Raw packet received, b'\x01\x805\x02\x10\x02\x16\xb1\x02\x13\x02\x10\x02\x10\x02\x10\x02\x11\x02\x10\x03\x01\x80\x02\x10\x02\x10\x02\x15\x87\x02\x10\x02\x10\x02\x10\x02\x12\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8035: b'0300000001'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8035 - PDM Event : status:3, record:1, lqi:0
DEBUG:zigate:Received response 0x8000: b'00000002'
WARNING:zigate:PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:2, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0002:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:2, error:b'', lqi:0
DEBUG:zigate:Set Zigate Time (firmware >= 3.0f)
DEBUG:zigate:REQUEST : 0x0016 b'&\xf6f\x03'
DEBUG:zigate:Msg to send b'00160004a726f66603'
DEBUG:zigate:Encoded Msg to send b'0102101602100214a726f666021303'
DEBUG:zigate:Waiting for status message for command 0x0016
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x93\x02\x10\x02\x10\x02\x10\x16\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00000016'
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:22, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0016:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:22, error:b'', lqi:0
DEBUG:zigate:REQUEST : 0x0015
DEBUG:zigate:Msg to send b'0015000015'
DEBUG:zigate:Encoded Msg to send b'01021015021002101503'
DEBUG:zigate:Waiting for status message for command 0x0015
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x90\x02\x10\x02\x10\x02\x10\x15\x02\x10\x03\x01\x80\x15\x02\x10\\\x8b\x02\x10\xe4\xa9\x02\x10\x15\x8d\x02\x10\x02\x12\x02\x14\xa4\xde\x02\x10\x92\x02\x11\xfd\x87\x02\x10\x15\x8d\x02\x10\x02\x12\x02\x14\xa1\xc4\x02\x10\xb5\x02\x12\xfdq\x02\x10\x15\x8d\x02\x10\x02\x15D\x8c\xaf\x02\x10o\x02\x13\x88o\x02\x10\x15\x8d\x02\x10\x02\x12\xfbJ\x12\x02\x10l\x02\x14~Y\x14\xb4W\xff\xfe\x02\x17p\x14\x02\x10a\x02\x16,I\x02\x10\x15\x8d\x02\x10\x02\x12xf.\x02\x10\x8b(H\xe1\x02\x10\x12K\x02\x10\x1f2\x02\x15\xd7\x02\x11U\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00000015'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:21, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Received response 0x8015: b'00e4a900158d000204a4de009201fd8700158d000204a1c400b502fd7100158d0005448caf006f03886f00158d0002fb4a12006c047e5914b457fffe0770140061062c4900158d000278662e008b2848e100124b001f3205d70155'
DEBUG:zigate:STATUS code to command 0x0015:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:21, error:b'', lqi:0
DEBUG:zigate:Waiting for message 0x8015
DEBUG:zigate:RESPONSE 0x8015 - Device list : devices:[OrderedDict([('id', 0), ('addr', 'e4a9'), ('ieee', '00158d000204a4de'), ('power_type', 0), ('lqi', 146)]), OrderedDict([('id', 1), ('addr', 'fd87'), ('ieee', '00158d000204a1c4'), ('power_type', 0), ('lqi', 181)]), OrderedDict([('id', 2), ('addr', 'fd71'), ('ieee', '00158d0005448caf'), ('power_type', 0), ('lqi', 111)]), OrderedDict([('id', 3), ('addr', '886f'), ('ieee', '00158d0002fb4a12'), ('power_type', 0), ('lqi', 108)]), OrderedDict([('id', 4), ('addr', '7e59'), ('ieee', '14b457fffe077014'), ('power_type', 0), ('lqi', 97)]), OrderedDict([('id', 6), ('addr', '2c49'), ('ieee', '00158d000278662e'), ('power_type', 0), ('lqi', 139)]), OrderedDict([('id', 40), ('addr', '48e1'), ('ieee', '00124b001f3205d7'), ('power_type', 1), ('lqi', 85)])], lqi:0
DEBUG:zigate:Known devices in zigate : {'886f', 'fd71', 'e4a9', '7e59', '48e1', '2c49', 'fd87'}
DEBUG:zigate:Previous devices missing : set()
DEBUG:zigate:Acquire Lock on device Device  (e4a9) 00158d000204a4de
DEBUG:zigate:Release Lock on device Device  (e4a9) 00158d000204a4de
DEBUG:zigate:Dispatch ZIGATE_DEVICE_UPDATED
DEBUG:zigate:Acquire Lock on device Device  (fd87) 00158d000204a1c4
DEBUG:zigate:Release Lock on device Device  (fd87) 00158d000204a1c4
DEBUG:zigate:Dispatch ZIGATE_DEVICE_UPDATED
DEBUG:zigate:Dispatch ZIGATE_DEVICE_ADDED
DEBUG:zigate:discover_device fd71
DEBUG:zigate:no mac_capability
DEBUG:zigate:REQUEST : 0x0042 fd71
DEBUG:zigate:Msg to send b'00420002ccfd71'
DEBUG:zigate:Encoded Msg to send b'0102104202100212ccfd7103'
DEBUG:zigate:Waiting for status message for command 0x0042
DEBUG:zigate:Stop waiting, got message 0x8015
DEBUG:zigate:Check Need discovery Device  (e4a9) 00158d000204a4de
DEBUG:zigate:Auto saving /root/.zigate.json
WARNING:zigate:Neither type (modelIdentifier) nor manufacturer_code for device e4a9
DEBUG:zigate:Saving persistent file
DEBUG:zigate:Need discovery : no type
DEBUG:zigate:Acquire Lock to save persistent file
DEBUG:zigate:Release Lock of persistent file
DEBUG:zigate:Need discovery : no endpoints
DEBUG:zigate:Dispatch ZIGATE_DEVICE_NEED_DISCOVERY
DEBUG:zigate:Check Need discovery Device  (fd87) 00158d000204a1c4
WARNING:zigate:Neither type (modelIdentifier) nor manufacturer_code for device fd87
DEBUG:zigate:Need discovery : no type
DEBUG:zigate:Need discovery : no endpoints
DEBUG:zigate:Dispatch ZIGATE_DEVICE_NEED_DISCOVERY
DEBUG:zigate:Check Need discovery Device  (fd71) 00158d0005448caf
WARNING:zigate:Neither type (modelIdentifier) nor manufacturer_code for device fd71
DEBUG:zigate:Need discovery : no type
DEBUG:zigate:Need discovery : no endpoints
DEBUG:zigate:REQUEST : 0x0010
DEBUG:zigate:Dispatch ZIGATE_DEVICE_NEED_DISCOVERY
DEBUG:zigate:Msg to send b'0010000010'
DEBUG:zigate:Encoded Msg to send b'01021010021002101003'
DEBUG:zigate:Waiting for status message for command 0x0010
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x1e\x02\x10\xd9\x02\x10B\x02\x10\x03\x01\x80\x02\x10\x02\x10\x02\x15\x95\x02\x10\x02\x10\x02\x10\x10\x02\x10\x03\x01\x80\x10\x02\x10\x02\x15\x89\x02\x10\x02\x13\x02\x13\x1c\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00d90042'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:217, packet_type:66, error:b'', lqi:0
DEBUG:zigate:Received response 0x8000: b'00000010'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', lqi:0
DEBUG:zigate:Received response 0x8010: b'0003031c'
DEBUG:zigate:RESPONSE 0x8010 - Version list : major:3, installer:31c, lqi:0, version:3.1c
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0042:RESPONSE 0x8000 - Status response : status:0, sequence:217, packet_type:66, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_DEVICE_ADDED
DEBUG:zigate:discover_device 886f
DEBUG:zigate:no mac_capability
DEBUG:zigate:REQUEST : 0x0042 886f
DEBUG:zigate:Msg to send b'00420002a7886f'
DEBUG:zigate:Encoded Msg to send b'0102104202100212a7886f03'
DEBUG:zigate:Waiting for status message for command 0x0042
DEBUG:zigate:STATUS code to command 0x0010:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', lqi:0
OrderedDict([('major', 3), ('installer', '31c'), ('lqi', 0), ('version', '3.1c')])
DEBUG:zigate:REQUEST : 0x0014
DEBUG:zigate:Msg to send b'0014000014'
DEBUG:zigate:Encoded Msg to send b'01021014021002101403'
DEBUG:zigate:Waiting for status message for command 0x0014
DEBUG:zigate:Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x1d\x02\x10\xda\x02\x10B\x02\x10\x03\x01\x80\x02\x10\x02\x10\x02\x15\x91\x02\x10\x02\x10\x02\x10\x14\x02\x10\x03\x01\x80\x14\x02\x10\x02\x12\x96\x02\x10\x02\x10\x03'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:Received response 0x8000: b'00da0042'
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:218, packet_type:66, error:b'', lqi:0
DEBUG:zigate:Received response 0x8000: b'00000014'
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Dispatch ZIGATE_PACKET_RECEIVED
DEBUG:zigate:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:20, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:Received response 0x8014: b'00'
DEBUG:zigate:RESPONSE 0x8014 - Permit join status : status:False, lqi:0
DEBUG:zigate:Dispatch ZIGATE_RESPONSE_RECEIVED
DEBUG:zigate:STATUS code to command 0x0042:RESPONSE 0x8000 - Status response : status:0, sequence:218, packet_type:66, error:b'', lqi:0
DEBUG:zigate:Dispatch ZIGATE_DEVICE_ADDED
DEBUG:zigate:discover_device 7e59
DEBUG:zigate:no mac_capability
DEBUG:zigate:REQUEST : 0x0042 7e59
DEBUG:zigate:Msg to send b'00420002677e59'
DEBUG:zigate:Encoded Msg to send b'0102104202100212677e5903'
DEBUG:zigate:Waiting for status message for command 0x0042
DEBUG:zigate:STATUS code to command 0x0014:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:20, error:b'', lqi:0
DEBUG:zigate:Waiting for message 0x8014
DEBUG:zigate:Stop waiting, got message 0x8014
False
DEBUG:zigate:REQUEST : 0x0012
DEBUG:zigate:Msg to send b'0012000012'
DEBUG:zigate:Encoded Msg to send b'01021012021002101203'
False
doudz commented 4 years ago

to check, try z.get_devices_list(True) and then check the content of z.devices

ruimarinho commented 4 years ago

Ah! Not sure why I'm seeing this.. on z.devices: [Device (e4a9) 00158d000204a4de, Device (fd87) 00158d000204a1c4]

ruimarinho commented 4 years ago

If I do:

import logging
logging.basicConfig()
logging.root.setLevel(logging.DEBUG)

import zigate
z = zigate.connect(port=None) # Leave None to auto-discover the port

print(z.get_version())
print(z.erase_persistent())
print(z.get_devices_list(True))
print(z.devices)

Then I get an empty array on z.devices. I guess that means the command worked.

ruimarinho commented 4 years ago

Given the PDM issues, would it be beneficial to also erase EEPROM? I'll have to re-pair everything anyway.

doudz commented 4 years ago

to me, erase_persistent erase the eeprom, but I could be wrong

ruimarinho commented 4 years ago

@doudz I think I found the culprit here. After resetting the network, I've noticed the messages are back after pairing the lumi.router device.

Could messages sent by this router crash Zigate? I'm using something like this - https://www.zigbee2mqtt.io/how_tos/how_to_create_a_cc2530_router.html.

2020-09-17 22:26:43 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x02\x10\x02\x10\x02\x15\x95\x02\x10\x02\x10\x02\x10\x10\x02\x10\x03\x01\x80\x10\x02\x10\x02\x15\x89\x02\x10\x02\x13\x02\x13\x1c\x02\x10\x03'
2020-09-17 22:26:43 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:26:43 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8000: b'00000010'
2020-09-17 22:26:43 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', lqi:0
2020-09-17 22:26:43 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:26:43 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:26:43 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8010: b'0003031c'
2020-09-17 22:26:43 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8010 - Version list : major:3, installer:31c, lqi:0, version:3.1c
2020-09-17 22:26:43 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:26:43 DEBUG (Thread-39) [zigate] STATUS code to command 0x0010:RESPONSE 0x8000 - Status response : status:0, sequence:0, packet_type:16, error:b'', lqi:0
2020-09-17 22:26:45 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10/~\x02\x12\xf8H\x02\x11\x02\x10\x02\x10\xff\x02\x11\x02\x10B\x02\x10"\x02\x11!\x02\x13\x02\x1c\x02\x13( \x02\x14!\xa8\x13\x02\x15!\x16\x02\x10\x02\x16$\x02\x11\x02\x10\x02\x10\x02\x10\x02\x10\x02\x18!\x02\x14\x02\x12\x02\x1a!\x02\x10\x02\x10d\x10\x02\x10Bf\x03'
2020-09-17 22:26:45 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'02f848010000ff01004200220121030c0328200421a8130521160006240100000000082104020a21000064100042'
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:2, addr:f848, endpoint:1, cluster:0, attribute:65281, status:0, data_type:66, size:34, data:0121030c0328200421a8130521160006240100000000082104020a21000064100042, lqi:102
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update attribute for device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86 {'endpoint': 1, 'cluster': 0, 'addr': 'f848', 'attribute': 65281, 'data': '0121030c0328200421a8130521160006240100000000082104020a21000064100042', 'name': 'xiaomi', 'value': {1: 3075, 3: 32, 4: 5032, 5: 22, 6: '0100000000', 8: 516, 10: 0, 100: False}, 'type': <class 'dict'>}
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Handle special xiaomi attribute {'endpoint': 1, 'cluster': 0, 'addr': 'f848', 'attribute': 65281, 'data': '0121030c0328200421a8130521160006240100000000082104020a21000064100042', 'name': 'xiaomi', 'value': {1: 3075, 3: 32, 4: 5032, 5: 22, 6: '0100000000', 8: 516, 10: 0, 100: False}, 'type': <class 'dict'>}
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED
2020-09-17 22:26:45 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update attribute for device LUMI lumi.sensor_wleak.aq1 (f848) 00158d00047bbd86 {'endpoint': 1, 'cluster': 1, 'addr': 'f848', 'attribute': 32, 'data': 30.75, 'name': 'battery_voltage', 'value': 3.075, 'type': <class 'float'>}
2020-09-17 22:26:47 INFO (MainThread) [homeassistant.components.automation.zigate_permit_join] zigate_permit_join: Executing step call service
2020-09-17 22:27:08 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf1\x02'
2020-09-17 22:27:08 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x14\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03\x01\x805\x02\x10\x02\x16C\x02\x13\x02\x10\x02\x10\xf1\x02\x12\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13'
2020-09-17 22:27:08 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x02\x10\x02\x10\xf1\x02\x14\x02\x10\x03'
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f104'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61700, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f102'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61698, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f104'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61700, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16@\x02\x13\x02\x10\x02\x10\xf1\x02\x11\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03\x01\x805\x02\x10\x02\x16E\x02\x13\x02\x10\x02\x10\xf0\x02\x15\x02\x10\x03\x01\x02\x10M\x02\x10\x02\x1d\x02\x1a\x02\x1ah\x02\x10\x12K\x02\x10\x1f2\x02\x15\xd7\x8e\x02\x10\x02\x10\x03'
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f101'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61697, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f005'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61445, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'0a6800124b001f3205d78e00'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:0a68, ieee:00124b001f3205d7, mac_capability:10001110, rejoin_status:False, lqi:0
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:0a68, ieee:00124b001f3205d7, mac_capability:10001110, rejoin_status:False, lqi:0
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (0a68) 00124b001f3205d7
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (0a68) 00124b001f3205d7
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_UPDATED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update device LUMI lumi.router (0a68) 00124b001f3205d7
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x805\x02\x10\x02\x16@\x02\x13\x02\x10\x02\x10\xf1\x02\x11\x02\x10\x03\x01\x805\x02\x10\x02\x16B\x02\x13\x02\x10\x02\x10\xf1\x02\x13\x02\x10\x03\x01\x02\x10M\x02\x10\x02\x1cs\x02\x1ah\x02\x10\x12K\x02\x10\x1f2\x02\x15\xd7\x8ex\x03\x01\x87\x02\x11\x02\x10\x02\x15\x87\x02\x10\x02\x10\x02\x14\x02\x10\x02\x10\x03'
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f101'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61697, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8035: b'030000f103'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8035 - PDM Event : status:3, record:61699, lqi:0
2020-09-17 22:27:08 WARNING (ZiGate-Decode data) [zigate] PDM Event : 3 E_PDM_SYSTEM_EVENT_LARGEST_RECORD_FULL_SAVE_NO_LONGER_POSSIBLE
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x004d: b'0a6800124b001f3205d78e'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x004D - Device announce : addr:0a68, ieee:00124b001f3205d7, mac_capability:10001110, lqi:120
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Device Announce RESPONSE 0x004D - Device announce : addr:0a68, ieee:00124b001f3205d7, mac_capability:10001110, lqi:120
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (0a68) 00124b001f3205d7
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (0a68) 00124b001f3205d7
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_DEVICE_UPDATED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update device LUMI lumi.router (0a68) 00124b001f3205d7
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8701: b'00000400'
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8701 - Route Discovery Confirmation : status:0, network_status:0, additional:b'\x04\x00', lqi:0
2020-09-17 22:27:08 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
doudz commented 4 years ago

I don't know why but it's possible that using this kind of custom router can conflict with zigate. I suggest you to contact fairecasoimeme to confirm the problem and find a solution

ruimarinho commented 4 years ago

Thank you for all your help @doudz @pipiche38. I have reached out to fairecasoimeme to confirm the problem. Will post an update here if we reach any conclusions.

csacre commented 4 years ago

I remember having issues between my router & zigate. I had to restrict my router to only use one band per device. It could be something similar here.