Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
11.51k stars 1.63k forks source link

CC2531 - ZB 3.0, panid/epanid issues #4086

Closed Stoatwblr closed 3 years ago

Stoatwblr commented 3 years ago

Bug Report

What happened

After updating a CC2531 to ZB 3.0 (CC2531_20190425.zip, hex file), it worked for a few days, then after several restarts panid, epanid and channel settings reset to 0xfffe(65534)/0x00124B001CD48A18/channel 11 and can no longer be adjusted

What did you expect to happen

These parameters should be adjustable (ie, the values set in configuration.yaml should be applied)

How to reproduce it (minimal and precise)

Unsure, the current device seems wedged on these values

Debug Info

Zigbee2mqtt version: 1.14.2

(This was found when using openhab2 zigbee binding - zigbee2mqtt doesn't readback/display this information from the stick after startup - which is arguably a bug)

Adapter hardware: CC2531 Adapter firmware version:

Coordinator firmware version: '{"type":"zStack30x","meta":{"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425}}'

Stoatwblr commented 3 years ago

After about 10 minutes of operation, this gets logged and at this point everything stops working entirely

I'm assuming the stick is "bad", but what I don't know is whether that's firmware or hardware

zigbee2mqtt:warn  2020-08-12 21:18:34: Soft reset timeout triggered
zigbee2mqtt:warn  2020-08-12 21:18:35: Soft resetted ZNP due to timeout
zigbee2mqtt:debug 2020-08-12 21:19:41: Saving state to file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:debug 2020-08-12 21:19:46: Non-pingable device 'sensor_bathroom_quarterlight' was last seen '565.057' seconds ago.
(node:2936072) UnhandledPromiseRejectionWarning: Error: SREQ '--> ZDO - mgmtPermitJoinReq - {"addrmode":15,"dstaddr":65532,"duration":254,"tcsignificance":0}' failed with status '(0xc2: NWK_INVALID_REQUEST)' (expected '(0x00: SUCCESS)')
    at Znp.<anonymous> (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:290:27)
    at Generator.next (<anonymous>)
    at fulfilled (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:24:58)
(node:2936072) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
(node:2936072) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Stoatwblr commented 3 years ago

other notes: 0x00124B001CD48A18 is the MAC address of the device (why would the epanID be forced to this?)

Changing back to 1.2HA seems to work but the panid is still broken

Koenkk commented 3 years ago

Can you provide the zigbee2mqtt debug startup logging and your configuration.yaml?

To enable debug logging set in configuration.yaml:

advanced:
  log_level: debug
Stoatwblr commented 3 years ago

I've flashed the device back to 1.2HA. Will have to reflash and then hope it breaks again.... :) This may take a while

Stoatwblr commented 3 years ago
mqtt:
  base_topic: zigbee2mqtt
  server: 'mqtt://localhost'
  user: zigbee2mqtt
  password: xxxxxxxx
  include_device_information: true
  keepalive: 60
  version: 5
serial:
  port: /dev/ttyUSB.CC2531-01
  disable_led: false
advanced:
  baudrate: 115200
  rtscts: false
  soft_reset_timeout: 300
  last_seen: 'epoch'
  channel: 15
  cache_state: true
  cache_state_persistent: true
  log_level: debug
#  log_output: syslog
  pan_id: 0x1a62
#### 6754
  ext_pan_id: [0xC3, 0x8D, 0xF4, 0x34, 0xD1, 0xC8, 0xC3, 0x8B]
###C3 8D F4 34 D1 C8 C3 8B
  network_key:
    - 156
    - 161
    - 36
    - 139
    - 219
    - 66
    - 182
    - 200
    - 210
    - 248
    - 84
    - 56
    - 205
    - 81
    - 17
    - 133
###9c a1 24 8b db 42 b6 c8 d2 f8 54 38 cd 51 11 85
  availability_timeout: 300
  report: true
Stoatwblr commented 3 years ago

zigbee2mqtt:info  2020-08-13 20:15:27: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-08-13.20-15-27' filename: log.txt
zigbee2mqtt:debug 2020-08-13 20:15:27: Removing old log directory '/opt/zigbee2mqtt/data/log/2020-08-12.02-29-24'
zigbee2mqtt:debug 2020-08-13 20:15:27: Can't load state from file /opt/zigbee2mqtt/data/state.json (doesn't exist)
zigbee2mqtt:info  2020-08-13 20:15:27: Starting zigbee2mqtt version 1.14.2 (commit #b91b456)
zigbee2mqtt:info  2020-08-13 20:15:27: Starting zigbee-herdsman...
zigbee2mqtt:debug 2020-08-13 20:15:27: Using zigbee-herdsman with settings: '{"network":{"panID":6754,"extendedPanID":[195,141,244,52,209,200,195,139],"channelList":[15],"networkKey":"HIDDEN"},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json","serialPort":{"baudRate":115200,"rtscts":false,"path":"/dev/ttyUSB.CC2531-01"},"adapter":{"concurrent":null}}'
zigbee2mqtt:info  2020-08-13 20:15:33: zigbee-herdsman started
zigbee2mqtt:info  2020-08-13 20:15:33: Coordinator firmware version: '{"type":"zStack12","meta":{"transportrev":2,"product":0,"majorrel":2,"minorrel":6,"maintrel":3,"revision":20190619}}'
zigbee2mqtt:debug 2020-08-13 20:15:33: Zigbee network parameters: {"panID":6754,"extendedPanID":"0x8bc3c8d134f48dc3","channel":15}
zigbee2mqtt:info  2020-08-13 20:15:33: Currently 0 devices are joined:
zigbee2mqtt:warn  2020-08-13 20:15:33: `permit_join` set to  `true` in configuration.yaml.
zigbee2mqtt:warn  2020-08-13 20:15:33: Allowing new devices to join.
zigbee2mqtt:warn  2020-08-13 20:15:33: Set `permit_join` to `false` once you joined all devices.
zigbee2mqtt:info  2020-08-13 20:15:33: Zigbee: allowing new devices to join.
zigbee2mqtt:debug 2020-08-13 20:15:33: Soft reset timeout set to 300 seconds
zigbee2mqtt:info  2020-08-13 20:15:33: Connecting to MQTT server at mqtt://localhost
zigbee2mqtt:debug 2020-08-13 20:15:33: Using MQTT keepalive: 60
zigbee2mqtt:info  2020-08-13 20:15:33: Connected to MQTT server
zigbee2mqtt:info  2020-08-13 20:15:33: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
zigbee2mqtt:info  2020-08-13 20:15:33: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.14.2","commit":"b91b456","coordinator":{"type":"zStack12","meta":{"transportrev":2,"product":0,"majorrel":2,"minorrel":6,"maintrel":3,"revision":20190619}},"log_level":"debug","permit_join":true}'
Stoatwblr commented 3 years ago

This is an ikea tradfri light joining from reset


zigbee2mqtt:info  2020-08-13 20:20:13: Device '0x680ae2fffe9adecc' joined
zigbee2mqtt:info  2020-08-13 20:20:13: Starting interview of '0x680ae2fffe9adecc'
zigbee2mqtt:info  2020-08-13 20:20:13: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x680ae2fffe9adecc"}}'
zigbee2mqtt:info  2020-08-13 20:20:13: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x680ae2fffe9adecc"}}'
zigbee2mqtt:info  2020-08-13 20:20:13: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffe9adecc/availability', payload 'online'
zigbee2mqtt:debug 2020-08-13 20:20:27: Saving state to file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:error 2020-08-13 20:22:31: Failed to interview '0x680ae2fffe9adecc', device has not successfully been paired
zigbee2mqtt:info  2020-08-13 20:22:31: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_failed","meta":{"friendly_name":"0x680ae2fffe9adecc"}}'
zigbee2mqtt:debug 2020-08-13 20:25:27: Saving state to file /opt/zigbee2mqtt/data/state.json

zigbee2mqtt:warn  2020-08-13 20:27:31: Soft reset timeout triggered
zigbee2mqtt:warn  2020-08-13 20:27:32: Soft resetted ZNP due to timeout

restarted the light again (oops, 7 restarts, not 6)

(node:1055917) UnhandledPromiseRejectionWarning: Error: SREQ '--> AF - dataRequestExt - {"dstaddrmode":2,"dstaddr":"0x000000000000fffd","destendpoint":242,"dstpanid":0,"srcendpoint":242,"clusterid":33,"transid":5,"options":0,"radius":30,"len":6,"data":{"type":"Buffer","data":[25,6,2,11,254,0]}}' failed with status '(0x02: INVALID_PARAM)' (expected '(0x00: SUCCESS)')
    at Znp.<anonymous> (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:290:27)
    at Generator.next (<anonymous>)
    at fulfilled (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:24:58)
(node:1055917) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
(node:1055917) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

nothing else happens with 6 cycles (cold start)

Stoatwblr commented 3 years ago

I'm assuming to some extent that the dongle itself is the problem, but without another one to compare with, it's impossible to tell. There's one on order but it'll take a while to show up

At this point trying to add anything else is failing with the same errors

Stoatwblr commented 3 years ago

Doh, I've just realised that was 1.2. Reflashing to 3.0 again

Stoatwblr commented 3 years ago
zigbee2mqtt:info  2020-08-13 23:36:38: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-08-13.23-36-38' filename: log.txt
zigbee2mqtt:debug 2020-08-13 23:36:38: Loaded state from file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:info  2020-08-13 23:36:38: Starting zigbee2mqtt version 1.14.2 (commit #b91b456)
zigbee2mqtt:info  2020-08-13 23:36:38: Starting zigbee-herdsman...
zigbee2mqtt:debug 2020-08-13 23:36:38: Using zigbee-herdsman with settings: '{"network":{"panID":6754,"extendedPanID":[195,141,244,52,209,200,195,139],"channelList":[15],"networkKey":"HIDDEN"},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json","serialPort":{"baudRate":115200,"rtscts":false,"path":"/dev/ttyUSB.CC2531-01"},"adapter":{"concurrent":null}}'
zigbee2mqtt:info  2020-08-13 23:36:53: zigbee-herdsman started
zigbee2mqtt:info  2020-08-13 23:36:53: Coordinator firmware version: '{"type":"zStack30x","meta":{"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425}}'
zigbee2mqtt:debug 2020-08-13 23:36:53: Zigbee network parameters: {"panID":6754,"extendedPanID":"0x00124b001cd48a18","channel":15}
zigbee2mqtt:info  2020-08-13 23:36:53: Currently 0 devices are joined:
zigbee2mqtt:warn  2020-08-13 23:36:53: `permit_join` set to  `true` in configuration.yaml.
zigbee2mqtt:warn  2020-08-13 23:36:53: Allowing new devices to join.
zigbee2mqtt:warn  2020-08-13 23:36:53: Set `permit_join` to `false` once you joined all devices.
zigbee2mqtt:info  2020-08-13 23:36:53: Zigbee: allowing new devices to join.
zigbee2mqtt:debug 2020-08-13 23:36:53: Soft reset timeout set to 300 seconds
zigbee2mqtt:info  2020-08-13 23:36:53: Connecting to MQTT server at mqtt://localhost
zigbee2mqtt:debug 2020-08-13 23:36:53: Using MQTT keepalive: 60
zigbee2mqtt:info  2020-08-13 23:36:54: Connected to MQTT server
zigbee2mqtt:info  2020-08-13 23:36:54: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
zigbee2mqtt:info  2020-08-13 23:36:54: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.14.2","commit":"b91b456","coordinator":{"type":"zStack30x","meta":{"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425}},"log_level":"debug","permit_join":true}'

As you can see above, the epanid isn't what it should be and matches the mac of the dongle

pairing a device:

zigbee2mqtt:info  2020-08-13 23:38:04: Device '0x00158d00049fd8e1' joined
zigbee2mqtt:info  2020-08-13 23:38:04: Starting interview of '0x00158d00049fd8e1'
zigbee2mqtt:info  2020-08-13 23:38:04: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x00158d00049fd8e1"}}'
zigbee2mqtt:info  2020-08-13 23:38:04: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x00158d00049fd8e1"}}'
zigbee2mqtt:info  2020-08-13 23:38:04: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1/availability', payload 'online'
zigbee2mqtt:debug 2020-08-13 23:38:05: Device '0x00158d00049fd8e1' announced itself
zigbee2mqtt:info  2020-08-13 23:38:05: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_announced","message":"announce","meta":{"friendly_name":"0x00158d00049fd8e1"}}'
zigbee2mqtt:debug 2020-08-13 23:38:05: Received Zigbee message from '0x00158d00049fd8e1', type 'attributeReport', cluster 'genBasic', data '{"modelId":"lumi.sensor_magnet.aq2","appVersion":3}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:05: Received Zigbee message from '0x00158d00049fd8e1', type 'attributeReport', cluster 'genBasic', data '{"65281":{"1":2995,"3":35,"4":424,"5":97,"6":[0,1],"10":0,"100":1}}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:38:05: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1', payload '{"battery":97,"voltage":2995,"contact":false,"linkquality":28,"device":{"friendlyName":"0x00158d00049fd8e1","model":"MCCGQ11LM","ieeeAddr":"0x00158d00049fd8e1","networkAddress":15081,"applicationVersion":3},"last_seen":1597358285953}'
zigbee2mqtt:debug 2020-08-13 23:38:22: Received Zigbee message from '0x00158d00049fd8e1', type 'attributeReport', cluster 'genBasic', data '{"65281":{"1":2995,"3":35,"4":424,"5":98,"6":[0,0],"10":0,"100":1},"modelId":"lumi.sensor_magnet.aq2"}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:38:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1', payload '{"battery":97,"voltage":2995,"contact":false,"linkquality":21,"device":{"friendlyName":"0x00158d00049fd8e1","model":"MCCGQ11LM","ieeeAddr":"0x00158d00049fd8e1","networkAddress":15081,"type":"EndDevice","manufacturerID":4151,"applicationVersion":3},"last_seen":1597358302861}'
zigbee2mqtt:debug 2020-08-13 23:38:25: Received Zigbee message from '0x00158d00049fd8e1', type 'attributeReport', cluster 'genBasic', data '{"65281":{"1":2995,"3":35,"4":424,"5":98,"6":[0,0],"10":0,"100":1},"modelId":"lumi.sensor_magnet.aq2"}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:38:25: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1', payload '{"battery":97,"voltage":2995,"contact":false,"linkquality":44,"device":{"friendlyName":"0x00158d00049fd8e1","model":"MCCGQ11LM","ieeeAddr":"0x00158d00049fd8e1","networkAddress":15081,"type":"EndDevice","manufacturerID":4151,"applicationVersion":3},"last_seen":1597358305394}'
zigbee2mqtt:debug 2020-08-13 23:38:25: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"manufacturerName":"LUMI"}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:28: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"powerSource":3}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:30: Received Zigbee message from '0x00158d00049fd8e1', type 'attributeReport', cluster 'genBasic', data '{"65281":{"1":2995,"3":35,"4":424,"5":98,"6":[0,131072],"10":0,"100":1},"modelId":"lumi.sensor_magnet.aq2"}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:38:30: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1', payload '{"battery":97,"voltage":2995,"contact":false,"linkquality":44,"device":{"friendlyName":"0x00158d00049fd8e1","model":"MCCGQ11LM","ieeeAddr":"0x00158d00049fd8e1","networkAddress":15081,"type":"EndDevice","manufacturerID":4151,"manufacturerName":"LUMI","powerSource":"Battery","applicationVersion":3},"last_seen":1597358310376}'
zigbee2mqtt:debug 2020-08-13 23:38:30: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"zclVersion":1}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:33: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"stackVersion":2}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:35: Received Zigbee message from '0x00158d00049fd8e1', type 'attributeReport', cluster 'genBasic', data '{"65281":{"1":2995,"3":35,"4":424,"5":98,"6":[0,262144],"10":0,"100":1},"modelId":"lumi.sensor_magnet.aq2"}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:38:35: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1', payload '{"battery":97,"voltage":2995,"contact":false,"linkquality":42,"device":{"friendlyName":"0x00158d00049fd8e1","model":"MCCGQ11LM","ieeeAddr":"0x00158d00049fd8e1","networkAddress":15081,"type":"EndDevice","manufacturerID":4151,"manufacturerName":"LUMI","powerSource":"Battery","applicationVersion":3,"stackVersion":2,"zclVersion":1},"last_seen":1597358315592}'
zigbee2mqtt:debug 2020-08-13 23:38:35: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"hwVersion":2}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:39: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"dateCode":"20161128"}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:38:42: Received Zigbee message from '0x00158d00049fd8e1', type 'readResponse', cluster 'genBasic', data '{"swBuildId":"3000-0001"}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:38:42: Successfully interviewed '0x00158d00049fd8e1', device has successfully been paired
zigbee2mqtt:info  2020-08-13 23:38:42: Device '0x00158d00049fd8e1' is supported, identified as: Xiaomi Aqara door & window contact sensor (MCCGQ11LM)
zigbee2mqtt:info  2020-08-13 23:38:42: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x00158d00049fd8e1","model":"MCCGQ11LM","vendor":"Xiaomi","description":"Aqara door & window contact sensor","supported":true}}'

tradfri lamp:

zigbee2mqtt:info  2020-08-13 23:56:07: Device '0x680ae2fffe9adecc' joined
zigbee2mqtt:info  2020-08-13 23:56:07: Starting interview of '0x680ae2fffe9adecc'
zigbee2mqtt:info  2020-08-13 23:56:07: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x680ae2fffe9adecc"}}'
zigbee2mqtt:info  2020-08-13 23:56:07: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x680ae2fffe9adecc"}}'
zigbee2mqtt:info  2020-08-13 23:56:07: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffe9adecc/availability', payload 'online'
zigbee2mqtt:debug 2020-08-13 23:56:10: Device '0x680ae2fffe9adecc' announced itself
zigbee2mqtt:info  2020-08-13 23:56:10: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_announced","message":"announce","meta":{"friendly_name":"0x680ae2fffe9adecc"}}'
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"modelId":"TRADFRI bulb E14 WS 470lm"}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"manufacturerName":"IKEA of Sweden"}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"powerSource":1}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"zclVersion":3}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"appVersion":33}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"stackVersion":98}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:21: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"hwVersion":1}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:22: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"dateCode":"20190312"}' from endpoint 1 with groupID 0
zigbee2mqtt:debug 2020-08-13 23:56:22: Received Zigbee message from '0x680ae2fffe9adecc', type 'readResponse', cluster 'genBasic', data '{"swBuildId":"2.1.022"}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-13 23:56:22: Successfully interviewed '0x680ae2fffe9adecc', device has successfully been paired
zigbee2mqtt:info  2020-08-13 23:56:22: Device '0x680ae2fffe9adecc' is supported, identified as: IKEA TRADFRI bulb E14 WS 470 lumen, dimmable, white spectrum, opal white (LED1903C5/LED1835C6)
zigbee2mqtt:info  2020-08-13 23:56:22: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x680ae2fffe9adecc","model":"LED1903C5/LED1835C6","vendor":"IKEA","description":"TRADFRI bulb E14 WS 47
0 lumen, dimmable, white spectrum, opal white","supported":true}}'
zigbee2mqtt:debug 2020-08-13 23:56:22: Setup reporting for '0x680ae2fffe9adecc' - 1 - genOnOff
zigbee2mqtt:info  2020-08-13 23:56:22: Successfully setup reporting for '0x680ae2fffe9adecc' - 1 - genOnOff
zigbee2mqtt:debug 2020-08-13 23:56:22: Setup reporting for '0x680ae2fffe9adecc' - 1 - genLevelCtrl
zigbee2mqtt:info  2020-08-13 23:56:22: Successfully setup reporting for '0x680ae2fffe9adecc' - 1 - genLevelCtrl
zigbee2mqtt:debug 2020-08-13 23:56:22: Setup reporting for '0x680ae2fffe9adecc' - 1 - lightingColorCtrl
zigbee2mqtt:info  2020-08-13 23:56:22: Successfully setup reporting for '0x680ae2fffe9adecc' - 1 - lightingColorCtrl
Koenkk commented 3 years ago

Can you provide the herdsman debug logging when starting zigbee2mqtt?

To enable herdsman debug logging, see https://www.zigbee2mqtt.io/information/debug.html#zigbee-herdsman-debug-logging

Stoatwblr commented 3 years ago
openhab@Riffraff:/opt/zigbee2mqtt$ DEBUG=zigbee-herdsman* npm start

> zigbee2mqtt@1.14.2 start /opt/zigbee2mqtt
> node index.js

zigbee2mqtt:info  2020-08-14 13:18:19: Logging to console and directory: '/opt/zigbee2mqtt/data/log/2020-08-14.13-18-19' filename: log.txt
zigbee2mqtt:debug 2020-08-14 13:18:19: Loaded state from file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:info  2020-08-14 13:18:20: Starting zigbee2mqtt version 1.14.2 (commit #b91b456)
zigbee2mqtt:info  2020-08-14 13:18:20: Starting zigbee-herdsman...
zigbee2mqtt:debug 2020-08-14 13:18:20: Using zigbee-herdsman with settings: '{"network":{"panID":6754,"extendedPanID":[195,141,244,52,209,200,195,139],"channelList":[15],"networkKey":"HIDDEN"},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json","serialPort":{"baudRate":115200,"rtscts":false,"path":"/dev/ttyUSB.CC2531-01"},"adapter":{"concurrent":null}}'
  zigbee-herdsman:adapter Path '/dev/ttyUSB.CC2531-01' is valid for 'ZStackAdapter' +0ms
  zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133],"panID":6754,"extendedPanID":[195,141,244,52,209,200,195,139],"channelList":[15]},"serialPort":{"baudRate":115200,"rtscts":false,"path":"/dev/ttyUSB.CC2531-01"},"databasePath":"/opt/zigbee2mqtt/data/database.db","databaseBackupPath":"/opt/zigbee2mqtt/data/database.db.backup","backupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json","adapter":{"concurrent":null}}' +0ms
  zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with /dev/ttyUSB.CC2531-01 and {"baudRate":115200,"rtscts":false,"autoOpen":false} +0ms
  zigbee-herdsman:adapter:zStack:znp:log Serialport opened +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,27,68,129,0,0,6,0,80,159,1,1,0,0,0,109,192,55,0,0,7,8,22,10,0,0,16,1,80,159,29,93] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,27,68,129,0,0,6,0,80,159,1,1,0,0,0,109,192,55,0,0,7,8,22,10,0,0,16,1,80,159,29,93] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 27 - 2 - 4 - 129 - [0,0,6,0,80,159,1,1,0,0,0,109,192,55,0,0,7,8,22,10,0,0,16,1,80,159,29] - 93 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":40784,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":0,"securityuse":0,"timestamp":3653741,"transseqnumber":0,"len":7,"data":{"type":"Buffer","data":[8,22,10,0,0,16,1]}} +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +6ms
  zigbee-herdsman:adapter:zStack:znp:log Writing skip bootloader payload +463ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> buffer [239] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - ping - {"capabilities":1} +0ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,1,32] +1s
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,2,97,1,121,7,28] +1s
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,2,97,1,121,7,28] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 2 - 3 - 1 - 1 - [121,7] - 28 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - ping - {"capabilities":1913} +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - version - {} +6ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,2,35] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,2,2,2,2,7,2,217,20,52,1,2,0,0,0,0,144] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,2,2,2,2,7,2,217,20,52,1,2,0,0,0,0,144] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 2 - [2,2,2,7,2,217,20,52,1,2,0,0,0,0] - 144 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - version - {"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425} +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:adapter Adapter concurrent: 2 +0ms
  zigbee-herdsman:adapter:zStack:adapter Detected znp version 'zStack30x' ({"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425}) +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":96,"offset":0,"len":1,"value":{"type":"Buffer","data":[85]}} +7ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,96,0,0,74] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,97,8,0,1,85,62] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,97,8,0,1,85,62] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 3 - 1 - 8 - [0,1,85] - 62 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":1,"value":{"type":"Buffer","data":[85]}} +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":96,"offset":0,"len":1,"value":{"type":"Buffer","data":[85]}} +7ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,96,0,0,74] +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,97,8,0,1,85,62] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,97,8,0,1,85,62] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 3 - 1 - 8 - [0,1,85] - 62 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":1,"value":{"type":"Buffer","data":[85]}} +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid +7ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":132,"len":4,"offset":0,"value":{"type":"Buffer","data":[0,128,0,0]}} +7ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,132,0,0,174] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,6,97,8,0,4,0,128,0,0,235] +21ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,6,97,8,0,4,0,128,0,0,235] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 6 - 3 - 1 - 8 - [0,4,0,128,0,0] - 235 +1ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":4,"value":{"type":"Buffer","data":[0,128,0,0]}} +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'channelList' is valid +22ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":99,"len":1,"offset":0,"value":{"type":"Buffer","data":[0]}} +22ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,99,0,0,73] +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,97,8,0,1,0,107] +10ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,97,8,0,1,0,107] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 3 - 1 - 8 - [0,1,0] - 107 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":1,"value":{"type":"Buffer","data":[0]}} +11ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'networkKeyDistribute' is valid +11ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SAPI - readConfiguration - {"id":98,"configid":98,"len":16,"offset":0,"value":{"type":"Buffer","data":[156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133]}} +11ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,1,38,4,98,65] +10ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,19,102,4,0,98,16,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,56] +31ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,19,102,4,0,98,16,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,56] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 19 - 3 - 6 - 4 - [0,98,16,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133] - 56 +1ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SAPI - readConfiguration - {"status":0,"configid":98,"len":16,"value":{"type":"Buffer","data":[156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133]}} +32ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'networkKey' is valid +32ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":131,"len":2,"offset":0,"value":{"type":"Buffer","data":[98,26]}} +33ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,131,0,0,169] +33ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,8,0,2,98,26,23] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,8,0,2,98,26,23] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 8 - [0,2,98,26] - 23 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":2,"value":{"type":"Buffer","data":[98,26]}} +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'panID' is valid +23ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":45,"len":8,"offset":0,"value":{"type":"Buffer","data":[195,141,244,52,209,200,195,139]}} +22ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,45,0,0,7] +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,10,97,8,0,8,195,141,244,52,209,200,195,139,180] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,10,97,8,0,8,195,141,244,52,209,200,195,139,180] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 10 - 3 - 1 - 8 - [0,8,195,141,244,52,209,200,195,139] - 180 +1ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":8,"value":{"type":"Buffer","data":[195,141,244,52,209,200,195,139]}} +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'extendedPanID' is valid +24ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> UTIL - getDeviceInfo - {} +25ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,39,0,39] +24ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,20,103,0,0,24,138,212,28,0,75,18,0,0,0,7,9,3,233,58,120,216,101,224,139] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,20,103,0,0,24,138,212,28,0,75,18,0,0,0,7,9,3,233,58,120,216,101,224,139] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 20 - 3 - 7 - 0 - [0,24,138,212,28,0,75,18,0,0,0,7,9,3,233,58,120,216,101,224] - 139 +1ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- UTIL - getDeviceInfo - {"status":0,"ieeeaddr":"0x00124b001cd48a18","shortaddr":0,"devicetype":7,"devicestate":9,"numassocdevices":3,"assocdeviceslist":[15081,55416,57445]} +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:startZnp ZNP is already started as coordinator +7ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - activeEpReq - {"dstaddr":0,"nwkaddrofinterest":0} +7ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,4,37,5,0,0,0,0,36] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,5,0,97] +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,5,0,97] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 5 - [0] - 97 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - activeEpReq - {"status":0} +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,19,69,133,0,0,0,0,0,13,242,47,13,12,110,11,8,6,5,4,3,2,1,104] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,19,69,133,0,0,0,0,0,13,242,47,13,12,110,11,8,6,5,4,3,2,1,104] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 19 - 2 - 5 - 133 - [0,0,0,0,0,13,242,47,13,12,110,11,8,6,5,4,3,2,1] - 104 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - activeEpRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"activeepcount":13,"activeeplist":[242,47,13,12,110,11,8,6,5,4,3,2,1]} +2s
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '1' already registered +14ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '2' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '3' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '4' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '5' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '6' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '8' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '11' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '110' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '12' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '13' already registered +0ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '47' already registered +1ms
  zigbee-herdsman:adapter:zStack:startZnp Endpoint '242' already registered +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - extFindGroup - {"endpoint":242,"groupid":2948} +14ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,37,74,242,132,11,17] +14ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,19,101,74,0,132,11,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,179] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,19,101,74,0,132,11,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,179] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 19 - 3 - 5 - 74 - [0,132,11,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0] - 179 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - extFindGroup - {"status":0,"groupid":2948,"namelen":0,"groupname":{"type":"Buffer","data":[]}} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:controller:log Started with result 'resumed' +2s
  zigbee-herdsman:controller:log Injected database: true, adapter: true +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - activeEpReq - {"dstaddr":0,"nwkaddrofinterest":0} +6ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,4,37,5,0,0,0,0,36] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,5,0,97] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,5,0,97] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 5 - [0] - 97 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - activeEpReq - {"status":0} +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,19,69,133,0,0,0,0,0,13,242,47,13,12,110,11,8,6,5,4,3,2,1,104] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,19,69,133,0,0,0,0,0,13,242,47,13,12,110,11,8,6,5,4,3,2,1,104] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 19 - 2 - 5 - 133 - [0,0,0,0,0,13,242,47,13,12,110,11,8,6,5,4,3,2,1] - 104 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - activeEpRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"activeepcount":13,"activeeplist":[242,47,13,12,110,11,8,6,5,4,3,2,1]} +20ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> UTIL - getDeviceInfo - {} +13ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,39,0,39] +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,20,103,0,0,24,138,212,28,0,75,18,0,0,0,7,9,3,233,58,120,216,101,224,139] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,20,103,0,0,24,138,212,28,0,75,18,0,0,0,7,9,3,233,58,120,216,101,224,139] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 20 - 3 - 7 - 0 - [0,24,138,212,28,0,75,18,0,0,0,7,9,3,233,58,120,216,101,224] - 139 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- UTIL - getDeviceInfo - {"status":0,"ieeeaddr":"0x00124b001cd48a18","shortaddr":0,"devicetype":7,"devicestate":9,"numassocdevices":3,"assocdeviceslist":[15081,55416,57445]} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":242} +6ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,242,214] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,242,224,161,5,0,0,0,0,113] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,242,224,161,5,0,0,0,0,113] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,242,224,161,5,0,0,0,0] - 113 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":242,"profileid":41440,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +18ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":47} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,47,11] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,47,4,1,5,0,0,0,0,232] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,47,4,1,5,0,0,0,0,232] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,47,4,1,5,0,0,0,0] - 232 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":47,"profileid":260,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":13} +13ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,13,41] +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,16,69,132,0,0,0,0,0,10,13,4,1,5,0,0,1,25,0,0,206] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,16,69,132,0,0,0,0,0,10,13,4,1,5,0,0,1,25,0,0,206] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 16 - 2 - 5 - 132 - [0,0,0,0,0,10,13,4,1,5,0,0,1,25,0,0] - 206 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":10,"endpoint":13,"profileid":260,"deviceid":5,"deviceversion":0,"numinclusters":1,"inclusterlist":[25],"numoutclusters":0,"outclusterlist":[]} +11ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":12} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,12,40] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,12,94,192,5,0,0,0,0,80] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,12,94,192,5,0,0,0,0,80] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,12,94,192,5,0,0,0,0] - 80 +1ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":12,"profileid":49246,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":110} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,110,74] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,110,4,1,5,0,0,0,0,169] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,110,4,1,5,0,0,0,0,169] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,110,4,1,5,0,0,0,0] - 169 +1ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":110,"profileid":260,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":11} +13ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,11,47] +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +14ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,18,69,132,0,0,0,0,0,12,11,4,1,0,4,0,0,2,0,5,2,5,213] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,18,69,132,0,0,0,0,0,12,11,4,1,0,4,0,0,2,0,5,2,5,213] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 18 - 2 - 5 - 132 - [0,0,0,0,0,12,11,4,1,0,4,0,0,2,0,5,2,5] - 213 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":12,"endpoint":11,"profileid":260,"deviceid":1024,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":2,"outclusterlist":[1280,1282]} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":8} +13ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,8,44] +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,8,4,1,5,0,0,0,0,207] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,8,4,1,5,0,0,0,0,207] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,8,4,1,5,0,0,0,0] - 207 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":8,"profileid":260,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":6} +13ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,6,34] +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,6,9,1,5,0,0,0,0,204] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,6,9,1,5,0,0,0,0,204] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,6,9,1,5,0,0,0,0] - 204 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":6,"profileid":265,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":5} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,5,33] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +11ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,5,8,1,5,0,0,0,0,206] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,5,8,1,5,0,0,0,0,206] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,5,8,1,5,0,0,0,0] - 206 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":5,"profileid":264,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":4} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,4,32] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,4,7,1,5,0,0,0,0,192] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,4,7,1,5,0,0,0,0,192] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,4,7,1,5,0,0,0,0] - 192 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":4,"profileid":263,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +13ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":3} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,3,39] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,3,5,1,5,0,0,0,0,197] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,3,5,1,5,0,0,0,0,197] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,3,5,1,5,0,0,0,0] - 197 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":3,"profileid":261,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +11ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":2} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,2,38] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,2,1,1,5,0,0,0,0,192] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,2,1,1,5,0,0,0,0,192] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,2,1,1,5,0,0,0,0] - 192 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":2,"profileid":257,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":0,"nwkaddrofinterest":0,"endpoint":1} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,0,0,0,0,1,37] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,69,132,0,0,0,0,0,8,1,4,1,5,0,0,0,0,198] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,69,132,0,0,0,0,0,8,1,4,1,5,0,0,0,0,198] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 2 - 5 - 132 - [0,0,0,0,0,8,1,4,1,5,0,0,0,0] - 198 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":0,"status":0,"nwkaddr":0,"len":8,"endpoint":1,"profileid":260,"deviceid":5,"deviceversion":0,"numinclusters":0,"inclusterlist":[],"numoutclusters":0,"outclusterlist":[]} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:controller:log Creating coordinator backup +182ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - version - {} +14ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,33,2,35] +14ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,2,2,2,2,7,2,217,20,52,1,2,0,0,0,0,144] +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,2,2,2,2,7,2,217,20,52,1,2,0,0,0,0,144] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 2 - [2,2,2,7,2,217,20,52,1,2,0,0,0,0] - 144 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - version - {"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":1,"offset":0,"osal":true,"product":-1} +5ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,1,0,0,43] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,10,97,8,0,8,24,138,212,28,0,75,18,0,104] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,10,97,8,0,8,24,138,212,28,0,75,18,0,104] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 10 - 3 - 1 - 8 - [0,8,24,138,212,28,0,75,18,0] - 104 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":8,"value":{"type":"Buffer","data":[24,138,212,28,0,75,18,0]}} +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":33,"offset":0,"osal":true,"product":-1} +7ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,33,0,0,11] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,112,97,8,0,110,76,5,2,16,20,16,0,20,0,0,0,1,5,1,143,7,0,2,5,30,0,0,15,0,0,0,0,0,0,0,0,0,0,98,26,8,0,128,0,0,15,15,4,0,1,0,0,0,1,0,0,0,0,24,138,212,28,0,75,18,0,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,60,3,0,1,120,10,1,0,0,85,1,0,72] +7ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,112,97,8,0,110,76,5,2,16,20,16,0,20,0,0,0,1,5,1,143,7,0,2,5,30,0,0,15,0,0,0,0,0,0,0,0,0,0,98,26,8,0,128,0,0,15,15,4,0,1,0,0,0,1,0,0,0,0,24,138,212,28,0,75,18,0,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,60,3,0,1,120,10,1,0,0,85,1,0,72] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 112 - 3 - 1 - 8 - [0,110,76,5,2,16,20,16,0,20,0,0,0,1,5,1,143,7,0,2,5,30,0,0,15,0,0,0,0,0,0,0,0,0,0,98,26,8,0,128,0,0,15,15,4,0,1,0,0,0,1,0,0,0,0,24,138,212,28,0,75,18,0,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,60,3,0,1,120,10,1,0,0,85,1,0] - 72 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":110,"value":{"type":"Buffer","data":[76,5,2,16,20,16,0,20,0,0,0,1,5,1,143,7,0,2,5,30,0,0,15,0,0,0,0,0,0,0,0,0,0,98,26,8,0,128,0,0,15,15,4,0,1,0,0,0,1,0,0,0,0,24,138,212,28,0,75,18,0,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,60,3,0,1,120,10,1,0,0,85,1,0]}} +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":131,"offset":0,"osal":true,"product":-1} +8ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,131,0,0,169] +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,8,0,2,98,26,23] +21ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,8,0,2,98,26,23] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 8 - [0,2,98,26] - 23 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":2,"value":{"type":"Buffer","data":[98,26]}} +21ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":45,"offset":0,"osal":true,"product":-1} +22ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,45,0,0,7] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,10,97,8,0,8,195,141,244,52,209,200,195,139,180] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,10,97,8,0,8,195,141,244,52,209,200,195,139,180] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 10 - 3 - 1 - 8 - [0,8,195,141,244,52,209,200,195,139] - 180 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":8,"value":{"type":"Buffer","data":[195,141,244,52,209,200,195,139]}} +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":58,"offset":0,"osal":true,"product":-1} +22ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,58,0,0,16] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,19,97,8,0,17,0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,80] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,19,97,8,0,17,0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,80] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 19 - 3 - 1 - 8 - [0,17,0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133] - 80 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":17,"value":{"type":"Buffer","data":[0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133]}} +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":59,"offset":0,"osal":true,"product":-1} +5ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,59,0,0,17] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,19,97,8,0,17,0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,80] +4ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,19,97,8,0,17,0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,80] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 19 - 3 - 1 - 8 - [0,17,0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133] - 80 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":17,"value":{"type":"Buffer","data":[0,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133]}} +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":71,"offset":0,"osal":true,"product":-1} +5ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,71,0,0,109] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,10,97,8,0,8,0,0,0,0,0,0,0,0,107] +11ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,10,97,8,0,8,0,0,0,0,0,0,0,0,107] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 10 - 3 - 1 - 8 - [0,8,0,0,0,0,0,0,0,0] - 107 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":8,"value":{"type":"Buffer","data":[0,0,0,0,0,0,0,0]}} +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":98,"offset":0,"osal":true,"product":-1} +12ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,98,0,0,72] +12ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,18,97,8,0,16,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,80] +21ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,18,97,8,0,16,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133,80] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 18 - 3 - 1 - 8 - [0,16,156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133] - 80 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":16,"value":{"type":"Buffer","data":[156,161,36,139,219,66,182,200,210,248,84,56,205,81,17,133]}} +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":99,"offset":0,"osal":true,"product":-1} +22ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,99,0,0,73] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,97,8,0,1,0,107] +9ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,97,8,0,1,0,107] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 3 - 1 - 8 - [0,1,0] - 107 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":1,"value":{"type":"Buffer","data":[0]}} +10ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":132,"offset":0,"osal":true,"product":-1} +10ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,132,0,0,174] +10ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,6,97,8,0,4,0,128,0,0,235] +21ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,6,97,8,0,4,0,128,0,0,235] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 6 - 3 - 1 - 8 - [0,4,0,128,0,0] - 235 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":4,"value":{"type":"Buffer","data":[0,128,0,0]}} +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":257,"product":2,"offset":0,"osal":true} +22ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,1,1,0,42] +22ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,18,97,8,0,16,255,73,194,182,208,150,223,46,90,156,250,137,194,38,208,90,197] +15ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,18,97,8,0,16,255,73,194,182,208,150,223,46,90,156,250,137,194,38,208,90,197] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 18 - 3 - 1 - 8 - [0,16,255,73,194,182,208,150,223,46,90,156,250,137,194,38,208,90] - 197 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":16,"value":{"type":"Buffer","data":[255,73,194,182,208,150,223,46,90,156,250,137,194,38,208,90]}} +16ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - osalNvRead - {"id":117,"product":2,"offset":0,"osal":true} +16ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,3,33,8,117,0,0,95] +16ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,8,0,12,59,164,0,0,24,138,212,28,0,75,18,0,247] +28ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,8,0,12,59,164,0,0,24,138,212,28,0,75,18,0,247] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 8 - [0,12,59,164,0,0,24,138,212,28,0,75,18,0] - 247 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[59,164,0,0,24,138,212,28,0,75,18,0]}} +28ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:controller:log Wrote coordinator backup to '/opt/zigbee2mqtt/data/coordinator_backup.json' +185ms
zigbee2mqtt:info  2020-08-14 13:18:22: zigbee-herdsman started
zigbee2mqtt:info  2020-08-14 13:18:22: Coordinator firmware version: '{"type":"zStack30x","meta":{"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425}}'
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - extNwkInfo - {} +32ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,0,37,80,117] +32ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,24,101,80,0,0,9,98,26,0,0,24,138,212,28,0,75,18,0,0,0,0,0,0,0,0,0,15,80] +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,24,101,80,0,0,9,98,26,0,0,24,138,212,28,0,75,18,0,0,0,0,0,0,0,0,0,15,80] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 24 - 3 - 5 - 80 - [0,0,9,98,26,0,0,24,138,212,28,0,75,18,0,0,0,0,0,0,0,0,0,15] - 80 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - extNwkInfo - {"shortaddr":0,"devstate":9,"panid":6754,"parentaddr":0,"extendedpanid":"0x00124b001cd48a18","parentextaddr":"0x0000000000000000","channel":15} +9ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
zigbee2mqtt:debug 2020-08-14 13:18:22: Zigbee network parameters: {"panID":6754,"extendedPanID":"0x00124b001cd48a18","channel":15}
zigbee2mqtt:info  2020-08-14 13:18:22: Currently 7 devices are joined:
zigbee2mqtt:info  2020-08-14 13:18:22: 0x00158d00049fd8e1 (0x00158d00049fd8e1): MCCGQ11LM - Xiaomi Aqara door & window contact sensor (EndDevice)
zigbee2mqtt:info  2020-08-14 13:18:22: 0x00158d00052dbd98 (0x00158d00052dbd98): WSDCGQ11LM - Xiaomi Aqara temperature, humidity and pressure sensor (EndDevice)
zigbee2mqtt:info  2020-08-14 13:18:22: 0x00158d0004832b6b (0x00158d0004832b6b): DJT11LM - Xiaomi Aqara vibration sensor (EndDevice)
zigbee2mqtt:info  2020-08-14 13:18:22: 0x680ae2fffe9adecc (0x680ae2fffe9adecc): LED1903C5/LED1835C6 - IKEA TRADFRI bulb E14 WS 470 lumen, dimmable, white spectrum, opal white (Router)
zigbee2mqtt:info  2020-08-14 13:18:22: 0x680ae2fffebe4ab6 (0x680ae2fffebe4ab6): LED1903C5/LED1835C6 - IKEA TRADFRI bulb E14 WS 470 lumen, dimmable, white spectrum, opal white (Router)
zigbee2mqtt:info  2020-08-14 13:18:22: 0x680ae2fffe4d8651 (0x680ae2fffe4d8651): LED1903C5/LED1835C6 - IKEA TRADFRI bulb E14 WS 470 lumen, dimmable, white spectrum, opal white (Router)
zigbee2mqtt:info  2020-08-14 13:18:22: 0x680ae2fffef8f56e (0x680ae2fffef8f56e): LED1903C5/LED1835C6 - IKEA TRADFRI bulb E14 WS 470 lumen, dimmable, white spectrum, opal white (Router)
zigbee2mqtt:warn  2020-08-14 13:18:22: `permit_join` set to  `true` in configuration.yaml.
zigbee2mqtt:warn  2020-08-14 13:18:22: Allowing new devices to join.
zigbee2mqtt:warn  2020-08-14 13:18:22: Set `permit_join` to `false` once you joined all devices.
zigbee2mqtt:info  2020-08-14 13:18:22: Zigbee: allowing new devices to join.
  zigbee-herdsman:controller:log Permit joining +15ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - mgmtPermitJoinReq - {"addrmode":15,"dstaddr":65532,"duration":254,"tcsignificance":0} +13ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,54,15,252,255,254,0,228] +13ms
zigbee2mqtt:debug 2020-08-14 13:18:22: Soft reset timeout set to 300 seconds
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,54,0,82] +20ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,54,0,82] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 54 - [0] - 82 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - mgmtPermitJoinReq - {"status":0} +20ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> AF - dataRequestExt - {"dstaddrmode":2,"dstaddr":"0x000000000000fffd","destendpoint":242,"dstpanid":0,"srcendpoint":242,"clusterid":33,"transid":1,"options":0,"radius":30,"len":6,"data":{"type":"Buffer","data":[25,2,2,11,254,0]}} +15ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,26,36,2,2,253,255,0,0,0,0,0,0,242,0,0,242,33,0,1,0,30,6,0,25,2,2,11,254,0,232] +16ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,100,2,0,103] +16ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,100,2,0,103] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 4 - 2 - [0] - 103 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- AF - dataRequestExt - {"status":0} +16ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,69,182,0,0,0,240] +2ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,69,182,0,0,0,240] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 5 - 182 - [0,0,0] - 240 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - mgmtPermitJoinRsp - {"srcaddr":0,"status":0} +234ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,68,128,0,242,1,52] +5ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,68,128,0,242,1,52] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 4 - 128 - [0,242,1] - 52 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":242,"transid":1} +6ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
zigbee2mqtt:info  2020-08-14 13:18:22: Connecting to MQTT server at mqtt://localhost
zigbee2mqtt:debug 2020-08-14 13:18:22: Using MQTT keepalive: 60
zigbee2mqtt:info  2020-08-14 13:18:22: Connected to MQTT server
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1', payload '{"battery":86,"voltage":2975,"contact":false,"linkquality":0,"device":{"friendlyName":"0x00158d00049fd8e1","model":"MCCGQ11LM","ieeeAddr":"0x00158d00049fd8e1","networkAddress":15081,"type":"EndDevice","manufacturerID":4151,"manufacturerName":"LUMI","powerSource":"Battery","applicationVersion":3,"stackVersion":2,"zclVersion":1,"hardwareVersion":2,"dateCode":"20161128","softwareBuildID":"3000-0001"},"last_seen":1597406088862}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00052dbd98', payload '{"battery":100,"voltage":3025,"temperature":23.84,"humidity":67.87,"pressure":1008.8,"linkquality":28,"device":{"friendlyName":"0x00158d00052dbd98","model":"WSDCGQ11LM","ieeeAddr":"0x00158d00052dbd98","networkAddress":55416,"type":"EndDevice","manufacturerID":4151,"manufacturerName":"LUMI","powerSource":"Battery","applicationVersion":5,"stackVersion":2,"zclVersion":1,"hardwareVersion":30,"dateCode":"20191205","softwareBuildID":"3000-0001"},"last_seen":1597406723929}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x00158d0004832b6b', payload '{"battery":100,"voltage":3015,"linkquality":5,"angle":7,"angle_x":-2,"angle_y":8,"angle_z":82,"angle_x_absolute":92,"angle_y_absolute":82,"strength":24,"device":{"friendlyName":"0x00158d0004832b6b","model":"DJT11LM","ieeeAddr":"0x00158d0004832b6b","networkAddress":57445,"type":"EndDevice","manufacturerID":4151,"manufacturerName":"LUMI","powerSource":"Battery","applicationVersion":8,"stackVersion":2,"zclVersion":1,"hardwareVersion":3,"dateCode":"20180130\u0000","softwareBuildID":"3000-0001"},"last_seen":1597407221301}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffe9adecc', payload '{"update_available":false,"state":"ON","linkquality":7,"brightness":254,"color_temp":370,"color":{"x":0.4599,"y":0.4106},"device":{"friendlyName":"0x680ae2fffe9adecc","model":"LED1903C5/LED1835C6","ieeeAddr":"0x680ae2fffe9adecc","networkAddress":27444,"type":"Router","manufacturerID":4476,"manufacturerName":"IKEA of Sweden","powerSource":"Mains (single phase)","applicationVersion":33,"stackVersion":98,"zclVersion":3,"hardwareVersion":1,"dateCode":"20190312","softwareBuildID":"2.3.050"},"last_seen":1597407433184}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffebe4ab6', payload '{"update_available":false,"state":"ON","linkquality":10,"brightness":254,"device":{"friendlyName":"0x680ae2fffebe4ab6","model":"LED1903C5/LED1835C6","ieeeAddr":"0x680ae2fffebe4ab6","networkAddress":40784,"type":"Router","manufacturerID":4476,"manufacturerName":"IKEA of Sweden","powerSource":"Mains (single phase)","applicationVersion":33,"stackVersion":98,"zclVersion":3,"hardwareVersion":1,"dateCode":"20190312","softwareBuildID":"2.3.050"},"last_seen":1597407202748}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffe4d8651', payload '{"update_available":false,"state":"ON","linkquality":7,"brightness":254,"device":{"friendlyName":"0x680ae2fffe4d8651","model":"LED1903C5/LED1835C6","ieeeAddr":"0x680ae2fffe4d8651","networkAddress":53963,"type":"Router","manufacturerID":4476,"manufacturerName":"IKEA of Sweden","powerSource":"Mains (single phase)","applicationVersion":33,"stackVersion":98,"zclVersion":3,"hardwareVersion":1,"dateCode":"20190312","softwareBuildID":"2.3.050"},"last_seen":1597407433189}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffef8f56e', payload '{"update_available":false,"state":"ON","linkquality":0,"brightness":254,"color_temp":370,"color":{"x":0.4599,"y":0.4106},"device":{"friendlyName":"0x680ae2fffef8f56e","model":"LED1903C5/LED1835C6","ieeeAddr":"0x680ae2fffef8f56e","networkAddress":58443,"type":"Router","manufacturerID":4476,"manufacturerName":"IKEA of Sweden","powerSource":"Mains (single phase)","applicationVersion":33,"stackVersion":98,"zclVersion":3,"hardwareVersion":1,"dateCode":"20190312","softwareBuildID":"2.3.050"},"last_seen":1597407460851}'
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,69,196,80,159,0,77] +347ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,69,196,80,159,0,77] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 5 - 196 - [80,159,0] - 77 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - srcRtgInd - {"dstaddr":40784,"relaycount":0,"relaylist":[]} +348ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.14.2","commit":"b91b456","coordinator":{"type":"zStack30x","meta":{"transportrev":2,"product":2,"majorrel":2,"minorrel":7,"maintrel":2,"revision":20190425}},"log_level":"debug","permit_join":true}'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00049fd8e1/availability', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00052dbd98/availability', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x00158d0004832b6b/availability', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffe9adecc/availability', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffebe4ab6/availability', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffe4d8651/availability', payload 'online'
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffef8f56e/availability', payload 'online'
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,27,68,129,0,0,8,0,80,159,1,1,0,0,0,139,227,55,0,0,7,8,23,10,0,0,32,254,80,159,29,88] +9ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,27,68,129,0,0,8,0,80,159,1,1,0,0,0,139,227,55,0,0,7,8,23,10,0,0,32,254,80,159,29,88] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 27 - 2 - 4 - 129 - [0,0,8,0,80,159,1,1,0,0,0,139,227,55,0,0,7,8,23,10,0,0,32,254,80,159,29] - 88 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":8,"srcaddr":40784,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":0,"securityuse":0,"timestamp":3662731,"transseqnumber":0,"len":7,"data":{"type":"Buffer","data":[8,23,10,0,0,32,254]}} +9ms
  zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":23,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":0,"dataType":32,"attrData":254}]},"address":40784,"endpoint":1,"linkquality":0,"groupID":0}' +396ms
zigbee2mqtt:debug 2020-08-14 13:18:22: Received Zigbee message from '0x680ae2fffebe4ab6', type 'attributeReport', cluster 'genLevelCtrl', data '{"currentLevel":254}' from endpoint 1 with groupID 0
zigbee2mqtt:info  2020-08-14 13:18:22: MQTT publish: topic 'zigbee2mqtt/0x680ae2fffebe4ab6', payload '{"update_available":false,"state":"ON","linkquality":0,"brightness":254,"device":{"friendlyName":"0x680ae2fffebe4ab6","model":"LED1903C5/LED1835C6","ieeeAddr":"0x680ae2fffebe4ab6","networkAddress":40784,"type":"Router","manufacturerID":4476,"manufacturerName":"IKEA of Sweden","powerSource":"Mains (single phase)","applicationVersion":33,"stackVersion":98,"zclVersion":3,"hardwareVersion":1,"dateCode":"20190312","softwareBuildID":"2.3.050"},"last_seen":1597407502743}'
  zigbee-herdsman:controller:endpoint DefaultResponse 0x680ae2fffebe4ab6/1 8(10, {"timeout":10000,"disableResponse":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null}) +0ms
  zigbee-herdsman:adapter:zStack:znp:SREQ --> AF - dataRequest - {"dstaddr":40784,"destendpoint":1,"srcendpoint":1,"clusterid":8,"transid":2,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[24,23,11,10,0]}} +385ms
  zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,15,36,1,80,159,1,1,8,0,2,0,30,5,24,23,11,10,0,250] +384ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,100,1,0,100] +10ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 4 - 1 - [0] - 100 +0ms
  zigbee-herdsman:adapter:zStack:znp:SRSP <-- AF - dataRequest - {"status":0} +383ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,68,128,0,1,2,196] +8ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,68,128,0,1,2,196] +0ms
  zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 4 - 128 - [0,1,2] - 196 +0ms
  zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":2} +26ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +0ms
^\Quit (core dumped)
Koenkk commented 3 years ago

Looks like a bug in the z-stack firmware, as can be seen the returned extended pan id is correct:

  zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - osalNvRead - {"status":0,"len":8,"value":{"type":"Buffer","data":[195,141,244,52,209,200,195,139]}} +23ms
  zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
  zigbee-herdsman:adapter:zStack:startZnp Item 'extendedPanID' is valid +24ms

But the returned value is:

  zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - extNwkInfo - {"shortaddr":0,"devstate":9,"panid":6754,"parentaddr":0,"extendedpanid":"0x00124b001cd48a18","parentextaddr":"0x0000000000000000","channel":15} +9ms

I'm wondering what extendedpanid is actually used, can you try to sniff this?

Stoatwblr commented 3 years ago

I can try if you give instructions. Right now I have no extra zigbee equipment onhand though (extra USB stuff is in transit)

Stoatwblr commented 3 years ago

as a FWIW, I believe the epanid on air is the returned one, as I had to repair all the equipment to make things work

Stoatwblr commented 3 years ago

New device has shown up (CC2531 and CC2540 both with external antennas)..... (edit: arrgh. Clumsy me snapped the board off the plug! New one ordered...)

And now sniffing using https://www.zigbee2mqtt.io/how_tos/how_to_sniff_zigbee_traffic.html

Where will I see the epanid in wireshark? (there's nothing I can see explicitly labelled as such)

falmanna commented 3 years ago

Hi @Koenkk , I am experiencing the same issue with CC2538_CC2592_MODKAMRU_V3_20200211 My coordinator expanid and channel are getting rest to 00124B0018F1FC4A and Channel 11 every time I try to change them. The first time I set up the coordinator they got changed to the values I want, but after a few weeks I rebooted the system and they are stuck with these values.

Update: the expanid is reverting to a value equal to the mac address of the dongle, which is strange.

github-actions[bot] commented 3 years ago

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

falmanna commented 3 years ago

unstale

github-actions[bot] commented 3 years ago

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

falmanna commented 3 years ago

Unstale, issue still present

Koenkk commented 3 years ago

@falmanna I understand the problem but I don't think it's very likely that this problem will be fixed because zstack 3.0.x is not developed by TI anymore

falmanna commented 3 years ago

@Koenkk I am not sure if it's present in the default 3.0.x zstack as well or only on this version. If it's in the default then I agree it doesn't make sense to track it unless someone has the skills and willing to fix it.

Koenkk commented 3 years ago

@falmanna given that it happens on both CC2531 and CC2538 I think it is. Looking at the patches of these firmwares I don't see anything what could possibly cause this issue: https://github.com/Koenkk/Z-Stack-firmware/blob/master/coordinator/Z-Stack_3.0.x/firmware_CC2538_CC2592_MODKAMRU_V3.patch https://github.com/Koenkk/Z-Stack-firmware/blob/master/coordinator/Z-Stack_3.0.x/firmware_CC2531_CC2530.patch

falmanna commented 3 years ago

@Koenkk I agree since all changes are only for the configs part, but we can't be sure until we test the original. I think we can try to consult TI forums for a help and patch it here if it's possible.

github-actions[bot] commented 3 years ago

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days