search

doudz / zigate

python lib for zigate
MIT License
47 stars 22 forks source link

Multiple issues with lumi.router (CC2530 + CC2591) #178

Open ruimarinho opened 4 years ago

ruimarinho commented 4 years ago

Hi @doudz,

I have built a router based on CC2530 + CC2591 using an alternative firmware from the zigbee2mqtt project.

After having it successfully join the network, several errors occurred:

2020-02-29 16:32:02 ERROR (ZiGate-Decode data) [zigate] Command 0x0030 failed Failed (ZigBee event codes) 0x80 : b''
2020-02-29 16:32:02 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-02-29 16:32:03 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x800\x02\x10\x02\x16\x02\x13x\x02\x10\x02\x12H\xe1f\x03\x01\x800\x02\x10\x02\x16\x02\x1dy\x02\x10\x02\x12H\xe1i\x03'
2020-02-29 16:32:03 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-02-29 16:32:03 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8030: b'78000248e1'
2020-02-29 16:32:03 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-02-29 16:32:03 ERROR (ZiGate-Decode data) [zigate] Error decoding response 0x8030: b'78000248e1'
2020-02-29 16:32:03 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8030: b'79000248e1'
2020-02-29 16:32:03 ERROR (ZiGate-Decode data) [zigate] Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/zigate/core.py", line 597, in decode_data
    response = RESPONSES.get(msg_type, Response)(value, lqi)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 36, in __init__
    self.decode()
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 449, in decode
    Response.decode(self)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 98, in decode
    sdata, msg_data = self._decode(fmt, keys, msg_data)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 109, in _decode
    sdata = OrderedDict(zip(keys, struct.unpack(fmt, data[:size])))
struct.error: unpack requires a buffer of 7 bytes

2020-02-29 16:32:03 ERROR (ZiGate-Decode data) [zigate] Error decoding response 0x8030: b'79000248e1'
2020-02-29 16:32:03 ERROR (ZiGate-Decode data) [zigate] Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/zigate/core.py", line 597, in decode_data
    response = RESPONSES.get(msg_type, Response)(value, lqi)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 36, in __init__
    self.decode()
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 449, in decode
    Response.decode(self)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 98, in decode
    sdata, msg_data = self._decode(fmt, keys, msg_data)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 109, in _decode
    sdata = OrderedDict(zip(keys, struct.unpack(fmt, data[:size])))
struct.error: unpack requires a buffer of 7 bytes

2020-02-29 16:32:03 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x800\x02\x10\x02\x16\x02\x11z\x02\x10\x02\x12H\xe1f\x03'
2020-02-29 16:32:03 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-02-29 16:32:03 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8030: b'7a000248e1'
2020-02-29 16:32:03 ERROR (ZiGate-Decode data) [zigate] Error decoding response 0x8030: b'7a000248e1'
2020-02-29 16:32:03 ERROR (ZiGate-Decode data) [zigate] Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/zigate/core.py", line 597, in decode_data
    response = RESPONSES.get(msg_type, Response)(value, lqi)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 36, in __init__
    self.decode()
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 449, in decode
    Response.decode(self)
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 98, in decode
  File "/usr/local/lib/python3.7/site-packages/zigate/responses.py", line 109, in _decode
    sdata = OrderedDict(zip(keys, struct.unpack(fmt, data[:size])))
struct.error: unpack requires a buffer of 7 bytes

2020-02-29 16:32:07 WARNING (ZiGate-Decode data) [zigate] No response waiting command 0x8030
2020-02-29 16:32:07 DEBUG (ZiGate-Decode data) [zigate] REQUEST : 0x0120 b'\x02H\xe1\x01\x08\x00\x06\x00\x00\x00\x00\x01\x00\x10\x00\x00\x00\x01\x0e\x10\x00\x00\x00'
2020-02-29 16:32:07 WARNING (ZiGate-Decode data) [zigate] No response waiting command 0x8030
2020-02-29 16:32:07 WARNING (ZiGate-Decode data) [zigate] No response waiting command 0x8030
2020-02-29 16:32:07 WARNING (ZiGate-Decode data) [zigate] No response waiting command 0x8030
2020-02-29 16:32:07 DEBUG (ZiGate-Decode data) [zigate] Msg to send b'012000179c0248e10108000600000000010010000000010e10000000'

The device then gets on a loop of APS_DATA_ACK messages presumably because of a multi click switch.

2020-02-29 16:33: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, 'name': 'multiclick', 'value': 1, 'type': <class 'int'>, 'data': 1}
2020-02-29 16:33:14 DEBUG (SyncWorker_19) [custom_components.zigate.switch] Event received: {'endpoint': 8, 'cluster': 6, 'addr': '48e1', 'attribute': 0, 'name': 'multiclick', 'value': 1, 'type': 'int', 'data': 1, 'ieee': '00124b001f3205d7', 'device_type': 'lumi.router', 'entity_id': 'zigate.00124b001f3205d7'}
2020-02-29 16:33:14 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-02-29 16:33:15 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x81\x02\x12\x02\x10\x02\x1ed\x02\x1dH\xe1\x02\x18\x02\x10\x02\x16\x02\x10\x02\x10\x02\x10 \x02\x10\x02\x11\x02\x11c\x03'
2020-02-29 16:33:15 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8102: b'0d48e108000600000020000101'
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8102 - Individual Attribute Report : sequence:13, addr:48e1, endpoint:8, cluster:6, attribute:0, status:0, data_type:32, size:1, data:1, lqi:99
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Acquire Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Release Lock on device LUMI lumi.router (48e1) 00124b001f3205d7
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_ATTRIBUTE_UPDATED
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [custom_components.zigate] Update attribute for device LUMI lumi.router (48e1) 00124b001f3205d7 {'endpoint': 8, 'cluster': 6, 'addr': '48e1', 'attribute': 0, 'name': 'multiclick', 'value': 1, 'type': <class 'int'>, 'data': 1}
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED
2020-02-29 16:33:15 DEBUG (SyncWorker_10) [custom_components.zigate.switch] Event received: {'endpoint': 8, 'cluster': 6, 'addr': '48e1', 'attribute': 0, 'name': 'multiclick', 'value': 1, 'type': 'int', 'data': 1, 'ieee': '00124b001f3205d7', 'device_type': 'lumi.router', 'entity_id': 'zigate.00124b001f3205d7'}
2020-02-29 16:33:15 DEBUG (ZiGate-Listen) [zigate] Raw packet received, b'\x01\x80\x11\x02\x10\x02\x178\x02\x10H\xe1\x02\x11\x02\x10\x02\x16\x02\x10\x03'
2020-02-29 16:33:15 DEBUG (ZiGate-Event Loop) [zigate] Dispatch ZIGATE_PACKET_RECEIVED
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Received response 0x8011: b'0048e1010006'
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] RESPONSE 0x8011 - APS_DATA_ACK : status:0, addr:48e1, endpoint:1, cluster:6, lqi:0
2020-02-29 16:33:15 DEBUG (ZiGate-Decode data) [zigate] Dispatch ZIGATE_RESPONSE_RECEIVED

Here's what the zigate panel shows:

Screenshot 2020-02-29 at 16 35 30

Also attached zigate.json and full log.

log.txt zigate.json.txt