Zigbee2mqtt: Innr SP-120 not reporting Power

[FutureCow]

Running latest 1.7.1-dev

I've connected 2 new Innr SP-120 power sockets. The sockets are working correctly for turning ON/OFF. But they should also report power measurement, but i don't see any report in the MQTT topic.

Database.db:

{"id":9,"type":"Router","ieeeAddr":"0x00158d000342af39","nwkAddr":35504,"manufId":4454,"manufName":"innr","powerSource":"Mains (single phase)","modelId":"SP 120","epList":[1,2],"endpoints":{"1":{"profId":49246,"epId":1,"devId":16,"inClusterList":[0,4,3,6,8,5,2820,1794,10],"outClusterList":[3,25,10],"clusters":{"genBasic":{"attributes":{"modelId":"SP 120","manufacturerName":"innr","powerSource":1,"zclVersion":2,"appVersion":1,"stackVersion":2,"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}}},"binds":[]},"2":{"profId":49246,"epId":2,"devId":4096,"inClusterList":[4096],"outClusterList":[],"clusters":{},"binds":[]}},"appVersion":1,"stackVersion":2,"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0","zclVersion":2,"interviewCompleted":true,"meta":{}}

MQTT topic:
```debug 2019-11-18T21:31:01: Received MQTT message on 'zigbee2mqtt/Schakel_Lamp_Bank/set' with data 'ON'
debug 2019-11-18T21:31:01: Publishing 'set' 'state' to 'Schakel_Lamp_Bank'
info 2019-11-18T21:31:01: MQTT publish: topic 'zigbee2mqtt/Schakel_Lamp_Bank', payload '{"state":"ON","last_seen":1574112661660}'

Debug pairing the plug:
```info  2019-11-18T21:27:08: Device 'Schakel_Lamp_Bank' joined
info  2019-11-18T21:27:08: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"Schakel_Lamp_Bank"}}'
info  2019-11-18T21:27:08: Starting interview of 'Schakel_Lamp_Bank'
info  2019-11-18T21:27:08: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"Schakel_Lamp_Bank"}}'
debug 2019-11-18T21:27:08: Device 'Schakel_Lamp_Bank' announced itself
debug 2019-11-18T21:27:08: Received Zigbee message from 'Schakel_Lamp_Bank', type 'readResponse', cluster 'genBasic', data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}' from endpoint 1 with groupID 0
debug 2019-11-18T21:27:08: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}'
debug 2019-11-18T21:27:08: Received Zigbee message from 'Schakel_Lamp_Bank', type 'readResponse', cluster 'genBasic', data '{"zclVersion":2,"appVersion":1,"stackVersion":2}' from endpoint 1 with groupID 0
debug 2019-11-18T21:27:08: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"zclVersion":2,"appVersion":1,"stackVersion":2}'
debug 2019-11-18T21:27:08: Received Zigbee message from 'Schakel_Lamp_Bank', type 'readResponse', cluster 'genBasic', data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' from endpoint 1 with groupID 0
debug 2019-11-18T21:27:08: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}'
info  2019-11-18T21:27:08: Successfully interviewed 'Schakel_Lamp_Bank', device has successfully been paired
info  2019-11-18T21:27:08: Device 'Schakel_Lamp_Bank' is supported, identified as: Innr Smart plug (SP 120)
info  2019-11-18T21:27:08: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"Schakel_Lamp_Bank","model":"SP 120","vendor":"Innr","description":"Smart plug","supported":true}}'

I Already tried removing / repairing the device without any luck.

[Koenkk]

What commit are you on? As this commit may fix it: https://github.com/Koenkk/zigbee2mqtt/commit/eea660374f3bfb69ae69512131db6a9ff20ee7e1

[FutureCow]

Did a update to the latest: zigbee2mqtt version 1.7.1+dev (commit #461544e)

Still no power report:

info  2019-11-19 18:44:33: Device '0x00158d0003892907' joined
info  2019-11-19 18:44:33: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x00158d0003892907"}}'
info  2019-11-19 18:44:33: Starting interview of '0x00158d0003892907'
info  2019-11-19 18:44:33: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x00158d0003892907"}}'
debug 2019-11-19 18:44:33: Device '0x00158d0003892907' announced itself
info  2019-11-19 18:44:41: MQTT publish: topic 'zigbee2mqtt/Sensor_PIR_Achterdeur', payload '{"battery":100,"voltage":3005,"linkquality":33,"occupancy":false,"last_seen":1574185391515,"elapsed":90001}'
info  2019-11-19 18:44:43: MQTT publish: topic 'zigbee2mqtt/Sensor_PIR_Vrij', payload '{"occupancy":false,"linkquality":36,"battery":100,"voltage":3005,"last_seen":1574185393029,"elapsed":90001}'
debug 2019-11-19 18:44:47: Received Zigbee message from '0x00158d0003892907', type 'readResponse', cluster 'genBasic', data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}' from endpoint 1 with groupID 0
debug 2019-11-19 18:44:47: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}'
debug 2019-11-19 18:44:47: Received Zigbee message from '0x00158d0003892907', type 'readResponse', cluster 'genBasic', data '{"zclVersion":2,"appVersion":1,"stackVersion":2}' from endpoint 1 with groupID 0
debug 2019-11-19 18:44:47: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"zclVersion":2,"appVersion":1,"stackVersion":2}'
debug 2019-11-19 18:44:48: Received Zigbee message from '0x00158d0003892907', type 'readResponse', cluster 'genBasic', data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' from endpoint 1 with groupID 0
debug 2019-11-19 18:44:48: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}'
info  2019-11-19 18:44:48: Successfully interviewed '0x00158d0003892907', device has successfully been paired
info  2019-11-19 18:44:48: Device '0x00158d0003892907' is supported, identified as: Innr Smart plug (SP 120)
info  2019-11-19 18:44:48: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x00158d0003892907","model":"SP 120","vendor":"Innr","description":"Smart plug","supported":true}}'
debug 2019-11-19 18:44:48: Received Zigbee message from '0x00158d0003892907', type 'readResponse', cluster 'genBasic', data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' from endpoint 1 with groupID 0
debug 2019-11-19 18:44:48: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}'

debug 2019-11-19 19:26:50: Received MQTT message on 'zigbee2mqtt/0x00158d0003892907/set' with data 'ON'
debug 2019-11-19 19:26:50: Publishing 'set' 'state' to '0x00158d0003892907'
info  2019-11-19 19:26:50: MQTT publish: topic 'zigbee2mqtt/0x00158d0003892907', payload '{"state":"ON","last_seen":1574188010506}'

[Koenkk]

Can you post the log when starting zigbee2mqtt until 30 seconds?

[FutureCow]

https://pastebin.com/raw/0xbc8j34

[Koenkk]

The problem is

error 2019-11-19 18:38:00: Failed to configure 'Schakel_Lamp_Kerstboom', attempt 1 (Error: AREQ - ZDO - bindRsp after 10000ms
    at Timeout.object.timer.setTimeout [as _onTimeout] (/home/frans/domotica/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24)
    at ontimeout (timers.js:436:11)
    at tryOnTimeout (timers.js:300:5)
    at listOnTimeout (timers.js:263:5)
    at Timer.processTimers (timers.js:223:10))

For some reasons the plug fail to configure. As I also have a SP 120 I've checked again but for me it works properly. I guess you also won't get state changes when turning the switch of via the button on it.

I'm not sure why the configure fails, but could you try to temporarily move the plug very close to the coordinator and check if it configures there?

[FutureCow]

• Removed the device
• Placed it next to the coordinator (50 cm)
• Repaired
• Restarted z2m:

info  2019-11-20 00:02:27: Configuring '0x00158d0003892907'
error 2019-11-20 00:02:37: Failed to configure '0x00158d0003892907', attempt 1 (Error: AREQ - ZDO - bindRsp after 10000ms
    at Timeout.object.timer.setTimeout [as _onTimeout] (/home/frans/domotica/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24)
    at ontimeout (timers.js:436:11)
    at tryOnTimeout (timers.js:300:5)
    at listOnTimeout (timers.js:263:5)
    at Timer.processTimers (timers.js:223:10))

I don't get a status change when pushing the button.

[Koenkk]

Do you by any change have another CC2531 where you can sniff the traffic with? https://www.zigbee2mqtt.io/how_tos/how_to_sniff_zigbee_traffic.html

[FutureCow]

I've flashed my old CC2531 with the sniffer firmware, and running ZBOSS and see the traffic. But I don't know how and what to read? What do you want to see?

[Koenkk]

Somewhere in the log you will see a bind request, does the switch respond with a bind response?

[FutureCow]

The messages are flying around in WireShark:

[Koenkk]

Could you send me the wireshark trace? (if you want to send it in private contact me on telegram, @koenkk).

[runningman84]

My sp 120 report power just fine. But they send a lot of messages especially for voltage change. It looks like my xiamoi sensor messages sometimes get lost... Maybe because the network is overloaded?

[FutureCow]

The problem is not the overload of the network or the SP-120. But the new coordinator (1352p). It can't configure the SP-120 right...

[Koenkk]

I've just checked with the CC1352-P but it works correctly in my case, so that doesn't seem to be the problem (honestly I don't know what causes it now).

[FutureCow]

Can reflashing the CC1352 solve the problem (without repairing al devices?) Or start Z2M from scratch? Or...?

[Koenkk]

@FutureCow you can try to reflash the CC1352-P (doesn't require repairing as zigbee2mqtt will automatically restore coordinator_backup.json)

[FutureCow]

Reflashed my CC1352 (erased twice) with UniFlash, but the same problem is still there...

[Koenkk]

Can you try with temporarily moving data/coordinator_backup.json (so that it won't restore your network), reflash the CC1352, change the channel and pair the SP 120 (so that only the SP 120 and the CC1352P are in the network)

[wisekki]

I'm currently having the same problem with my Innr sockets. I have three of them and they worked with CC2530 very nicely. I changed my coordinator to CC2530+CC2591 and used the latest Z-Stack_Home_1.2 firmware CC2530_CC2591_DEFAULT_20190608.zip. Zigbee2mqtt is 1.7.1+dev. Now they do not report power consumption at all :(

I've tried to rejoin but the logs show:
warn 2019-12-13 20:44:10: Device '0x00158d00034450be' left the network info 2019-12-13 20:44:10: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_removed","message":"left_network","meta":{"friendly_name":"0x00158d00034450be"}}' info 2019-12-13 20:44:16: Device '0x00158d00034450be' joined info 2019-12-13 20:44:16: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x00158d00034450be"}}' info 2019-12-13 20:44:16: Starting interview of '0x00158d00034450be' info 2019-12-13 20:44:16: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x00158d00034450be"}}' info 2019-12-13 20:44:17: Successfully interviewed '0x00158d00034450be', device has successfully been paired info 2019-12-13 20:44:17: Device '0x00158d00034450be' is supported, identified as: Innr Smart plug (SP 120) info 2019-12-13 20:44:17: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x00158d00034450be","model":"SP 120","vendor":"Innr","description":"Smart plug","supported":true}}' info 2019-12-13 20:44:17: Configuring '0x00158d00034450be' error 2019-12-13 20:44:27: Failed to configure '0x00158d00034450be', attempt 2 (Error: AREQ - ZDO - bindRsp after 10000ms at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) at ontimeout (timers.js:436:11) at tryOnTimeout (timers.js:300:5) at listOnTimeout (timers.js:263:5) at Timer.processTimers (timers.js:223:10))

[FutureCow]

• reflashed my 1352-P2
• Started a new z2m from scratch
• Paired the SP-120
• Eveything seems to work now!

zigbee2mqtt:info 2019-12-14 15:09:25: Device '0x00158d000342af39' joined zigbee2mqtt:info 2019-12-14 15:09:25: MQTT publish: topic 'zigbee2mqtt3/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x00158d000342af39"}}' zigbee2mqtt:info 2019-12-14 15:09:25: Starting interview of '0x00158d000342af39' zigbee2mqtt:info 2019-12-14 15:09:25: MQTT publish: topic 'zigbee2mqtt3/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x00158d000342af39"}}' zigbee2mqtt:debug 2019-12-14 15:09:25: Device '0x00158d000342af39' announced itself zigbee2mqtt:debug 2019-12-14 15:09:25: Received Zigbee message from '0x00158d000342af39', type 'readResponse', cluster 'genBasic', data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}' from endpoint 1 with groupID 0 zigbee2mqtt:debug 2019-12-14 15:09:25: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}' zigbee2mqtt:debug 2019-12-14 15:09:25: Received Zigbee message from '0x00158d000342af39', type 'readResponse', cluster 'genBasic', data '{"zclVersion":2,"appVersion":1,"stackVersion":2}' from endpoint 1 with groupID 0 zigbee2mqtt:debug 2019-12-14 15:09:25: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"zclVersion":2,"appVersion":1,"stackVersion":2}' zigbee2mqtt:debug 2019-12-14 15:09:25: Received Zigbee message from '0x00158d000342af39', type 'readResponse', cluster 'genBasic', data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' from endpoint 1 with groupID 0 zigbee2mqtt:debug 2019-12-14 15:09:25: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' zigbee2mqtt:info 2019-12-14 15:09:25: Successfully interviewed '0x00158d000342af39', device has successfully been paired zigbee2mqtt:info 2019-12-14 15:09:25: Device '0x00158d000342af39' is supported, identified as: Innr Smart plug (SP 120) zigbee2mqtt:info 2019-12-14 15:09:25: MQTT publish: topic 'zigbee2mqtt3/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x00158d000342af39","model":"SP 120","vendor":"Innr","description":"Smart plug","supported":true}}' zigbee2mqtt:info 2019-12-14 15:09:25: Configuring '0x00158d000342af39' zigbee2mqtt:info 2019-12-14 15:09:25: Succesfully configured '0x00158d000342af39' zigbee2mqtt:debug 2019-12-14 15:09:33: Received Zigbee message from '0x00158d000342af39', type 'attributeReport', cluster 'haElectricalMeasurement', data '{"rmsVoltage":232}' from endpoint 1 with groupID 0 zigbee2mqtt:info 2019-12-14 15:09:33: MQTT publish: topic 'zigbee2mqtt3/0x00158d000342af39', payload '{"voltage":232,"linkquality":87}'
Can there be something wrong with the state.json? I don't like te repair all my devices again....

[wisekki]

I made a fresh install of Zigee2mqtt and joined SP120 to the network. It seems it doesn't report power at all anymore.. only voltage and link :(

joulu 15 20:54:17 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:17: Device '0x00158d00034450be' joined joulu 15 20:54:17 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:17: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":{"friendly_name":"0x00158d00034450be"}}' joulu 15 20:54:17 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:17: Starting interview of '0x00158d00034450be' joulu 15 20:54:17 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:17: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"0x00158d00034450be"}}' joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: MQTT publish: topic 'homeassistant/switch/0x00158d00034450be/switch/config', payload '{"payload_off":"OFF","payload_on":"ON","value_template":"{{ value_json.state }}","command_topic":"zigbee2mqtt/0x00158d00034450be/set","state_topic":"zigbee2mqtt/0x00158d00034450be","json_attributes_topic":"zigbee2mqtt/0x00158d00034450be","name":"0x00158d00034450be_switch","unique_id":"0x00158d00034450be_switch_zigbee2mqtt","device":{"identifiers":["zigbee2mqtt_0x00158d00034450be"],"name":"0x00158d00034450be","sw_version":"Zigbee2mqtt 1.8.0","model":"Smart plug (SP 120)","manufacturer":"Innr"},"availability_topic":"zigbee2mqtt/bridge/state"}' joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: MQTT publish: topic 'homeassistant/sensor/0x00158d00034450be/power/config', payload '{"unit_of_measurement":"W","icon":"mdi:factory","value_template":"{{ value_json.power }}","state_topic":"zigbee2mqtt/0x00158d00034450be","json_attributes_topic":"zigbee2mqtt/0x00158d00034450be","name":"0x00158d00034450be_power","unique_id":"0x00158d00034450be_power_zigbee2mqtt","device":{"identifiers":["zigbee2mqtt_0x00158d00034450be"],"name":"0x00158d00034450be","sw_version":"Zigbee2mqtt 1.8.0","model":"Smart plug (SP 120)","manufacturer":"Innr"},"availability_topic":"zigbee2mqtt/bridge/state"}' joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: MQTT publish: topic 'homeassistant/sensor/0x00158d00034450be/linkquality/config', payload '{"unit_of_measurement":"-","value_template":"{{ value_json.linkquality }}","state_topic":"zigbee2mqtt/0x00158d00034450be","json_attributes_topic":"zigbee2mqtt/0x00158d00034450be","name":"0x00158d00034450be_linkquality","unique_id":"0x00158d00034450be_linkquality_zigbee2mqtt","device":{"identifiers":["zigbee2mqtt_0x00158d00034450be"],"name":"0x00158d00034450be","sw_version":"Zigbee2mqtt 1.8.0","model":"Smart plug (SP 120)","manufacturer":"Innr"},"availability_topic":"zigbee2mqtt/bridge/state"}' joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: Successfully interviewed '0x00158d00034450be', device has successfully been paired joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: Device '0x00158d00034450be' is supported, identified as: Innr Smart plug (SP 120) joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x00158d00034450be","model":"SP 120","vendor":"Innr","description":"Smart plug","supported":true}}' joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: Configuring '0x00158d00034450be' joulu 15 20:54:18 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:18: Succesfully configured '0x00158d00034450be' joulu 15 20:54:25 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:54:25: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":242,"linkquality":57}' joulu 15 20:55:22 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:55:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":240,"linkquality":59}' joulu 15 20:55:35 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:55:35: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":242,"linkquality":57}' joulu 15 20:55:50 zigbeegw npm[31097]: zigbee2mqtt:info 2019-12-15 20:55:50: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":240,"linkquality":57}'

-- edited.. never mind about this.. it started reporting power and current after a few resets.

[CSchlipp]

I'm having exactly the same issues with 1.8.0-dev (commit #e63d196) after pairing four Innr Plugs to my CC2531. Everything else is working fine, so I'd really appreciate a solution that does not force me to repair all other devices...

[elsbrock]

It took some time for me until it started reporting power.

[CSchlipp]

Until today, I've still just received mentioned error messages whenever I've plugged in one of the Innr Plugs. They did neither send any state updates when turned on manually, nor power/current/voltage readings with the most recent dev or stable versions

I've finally worked around this by using zigbee2mqtt version 1.6 with the old zigbee-shepherd module:
Using the old version, all plugs could be configured sucessfully and immediately reported all readings after repairing. The plugs continue to work and keep reporting the values correctly after reverting back to the most recent dev-version.
Just found out that this actually wiped my old config, had to repair everything again... :(

Seems like this error is related to Zigbee-Herdsman...

[dersparkiie]

Similar problem here after updating from Version 1.5.1 to 1.8.0.
With Version 1.5.1 there were no problems. Readings have been updated every few seconds. Under Version 1.8.0 only on/off states are commited. Power readings seem to be wrong:
2020-01-08 08:06:24: MQTT publish: topic 'zigbee2mqtt/Plug_Alexa', payload '{"voltage":229,"linkquality":52,"state":"OFF","power":7,"current":0.067}'
The plug is turned off but power reading isn't 0!

[runningman84]

It works for me just fine in 1.8.0. Although I think the amount of updates are too much... but I guess you can change the update interval.

[wisekki]

It works for me just fine in 1.8.0. Although I think the amount of updates are too much... but I guess you can change the update interval.

Could you please be kind enough and tell me how to do that? :) I have multiple Innr's and they really flood the logs.

About the devices itself.. 1.8.0 keeps forgetting the devices. I have to rejoin them few times a month. Didn't happen with 1.6.0 :(

[runningman84]

I have found this:
https://zigbee2mqtt.discourse.group/t/configure-attribute-reporting-for-innr-sp120-or-any-zigbee-device/457

[wisekki]

I have found this:
https://zigbee2mqtt.discourse.group/t/configure-attribute-reporting-for-innr-sp120-or-any-zigbee-device/457

Yes that's my original post :) but if you read it i didn't get it to work...

[0rn0lf]

Any update about how to change the reporting interval? I installed the plug last week and its flooding my HA database. Over 3GB in a week just from the plug.

[dersparkiie]

Any update about how to change the reporting interval? I installed the plug last week and its flooding my HA database. Over 3GB in a week just from the plug.

Totaly different here. My SP120 doesn't update the current at all. 1.8.0 dev commit e766335

[0rn0lf]

Any update about how to change the reporting interval? I installed the plug last week and its flooding my HA database. Over 3GB in a week just from the plug.

Totaly different here. My SP120 doesn't update the current at all. 1.8.0 dev commit e766335

I'm on 1.9.0 and it updates nearly every second.

[dersparkiie]

My SP120 can not be configured.
Jan 18 22:43:43 sparkie xiaomi[2015]: zigbee2mqtt:error 2020-01-18 22:43:43: Failed to configure 'Plug_Alexa', attempt 1 (Error: AREQ - ZDO - bindRsp after 10000ms Jan 18 22:43:43 sparkie xiaomi[2015]: at Timeout._onTimeout (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) Jan 18 22:43:43 sparkie xiaomi[2015]: at listOnTimeout (internal/timers.js:531:17) Jan 18 22:43:43 sparkie xiaomi[2015]: at processTimers (internal/timers.js:475:7)) Jan 18 22:43:43 sparkie xiaomi[2015]: zigbee2mqtt:info 2020-01-18 22:43:43: Configuring '0x00158d0003569804' Jan 18 22:43:53 sparkie xiaomi[2015]: zigbee2mqtt:error 2020-01-18 22:43:53: Failed to configure '0x00158d0003569804', attempt 1 (Error: AREQ - ZDO - bindRsp after 10000ms Jan 18 22:43:53 sparkie xiaomi[2015]: at Timeout._onTimeout (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) Jan 18 22:43:53 sparkie xiaomi[2015]: at listOnTimeout (internal/timers.js:531:17) Jan 18 22:43:53 sparkie xiaomi[2015]: at processTimers (internal/timers.js:475:7))

[runningman84]

@0rn0lf @wisekki
@Koenkk wrote two posts how to reduce the amount of message:
Changing the interval (this seems to be the best solution but needs code change):
https://github.com/Koenkk/zigbee2mqtt/issues/588#issuecomment-575166329
Adding the debounce option (this is just a configuration entry):
https://github.com/Koenkk/zigbee2mqtt/issues/2114

From my point of view the first method is the best because it would also reduce the zigbee traffic. The second option just holds back messages from homeassistant. I hope we get some option in the future which would allow us the change the interval from the configuration.yaml...

[IcedEarth]

@0rn0lf @wisekki
@Koenkk wrote two posts how to reduce the amount of message:
Changing the interval (this seems to be the best solution but needs code change):
#588 (comment)
Adding the debounce option (this is just a configuration entry):

2114

From my point of view the first method is the best because it would also reduce the zigbee traffic. The second option just holds back messages from homeassistant. I hope we get some option in the future which would allow us the change the interval from the configuration.yaml...

I agree on making it changeable. Indeed, I experience similar isssues with status reports flooding my FHEM server putting a huge load on my zigbee network making other sensor elss responsible.

[runningman84]

My impression is that alot of motion events get's lost since I have installed the sp-120 plugs (I have about 10 of them). Furthermore my mariadb server is under a lot of load... (which I could reduce using the debounce option):

Fun fact the disk write rate dropped from 30MB/s to 2MB/s for the whole system. The system laod also dropped a lot.

[Koenkk]

Instead of making this configurable, the default should be good out-of-the-box.

If somebody can experiment with changing:

• https://github.com/Koenkk/zigbee-herdsman-converters/blob/master/devices.js#L240
• https://github.com/Koenkk/zigbee-herdsman-converters/blob/master/devices.js#L249
• https://github.com/Koenkk/zigbee-herdsman-converters/blob/master/devices.js#L258

to minimumReportInterval: 5,, this should change the min report interval to 5 seconds (instead of 1)

After making these changes in devices.js trigger a configure via https://www.zigbee2mqtt.io/information/mqtt_topics_and_message_structure.html#zigbee2mqttbridgeconfigure

Guide how to get to devices.js: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html

If this fixes the above issues I can integrate this.

[wisekki]

I did the experiment, thnx @Koenkk, for one of the innr's. Seems to be 5 seconds now except for a few lines.. but you guys can decide if it works :)

First one is before the modification. Latter after the change. I also turned off the plug to see how it reports off-status.

2020-01-23 09:47:47: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":65,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:49:11: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":65,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:49:25: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":65,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:50:02: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":65,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:51:03: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":65,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:51:04: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":65,"power":0,"current":0,"state":"ON"}'
2020-01-23 09:51:05: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":0,"current":0,"state":"ON"}'
2020-01-23 09:51:07: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":22,"current":0.31,"state":"ON"}'
2020-01-23 09:51:08: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":40,"current":0.344,"state":"ON"}'
2020-01-23 09:51:09: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":68,"current":0.566,"state":"ON"}'
2020-01-23 09:51:10: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":80,"current":0.643,"state":"ON"}'
2020-01-23 09:51:11: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":48,"current":0.605,"state":"ON"}'
2020-01-23 09:51:12: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":48,"current":0.452,"state":"ON"}'
2020-01-23 09:51:14: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":37,"current":0.428,"state":"ON"}'
2020-01-23 09:51:18: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":34,"current":0.428,"state":"ON"}'
2020-01-23 09:51:19: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":37,"current":0.39,"state":"ON"}'
2020-01-23 09:51:20: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":34,"current":0.39,"state":"ON"}'
2020-01-23 09:51:21: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":34,"current":0.386,"state":"ON"}'
2020-01-23 09:51:23: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":37,"current":0.386,"state":"ON"}'
2020-01-23 09:51:24: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":65,"current":0.413,"state":"ON"}'
2020-01-23 09:51:25: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":68,"current":0.559,"state":"ON"}'
2020-01-23 09:51:26: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":60,"current":0.574,"state":"ON"}'
2020-01-23 09:51:27: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":30,"current":0.51,"state":"ON"}'
2020-01-23 09:51:28: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":30,"current":0.36,"state":"ON"}'

After mod:

2020-01-23 09:56:20: Configuring '0x00158d00034450be'
2020-01-23 09:56:21: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.306,"state":"ON"}'
2020-01-23 09:56:21: Successfully configured '0x00158d00034450be'
2020-01-23 09:56:22: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":52,"power":20,"current":0.306,"state":"ON"}'
2020-01-23 09:56:26: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":19,"current":0.31,"state":"ON"}'
2020-01-23 09:56:31: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":19,"current":0.307,"state":"ON"}'
2020-01-23 09:56:43: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":19,"current":0.31,"state":"ON"}'
2020-01-23 09:56:49: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":19,"current":0.307,"state":"ON"}'
2020-01-23 09:56:52: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":17,"current":0.307,"state":"ON"}'
2020-01-23 09:56:54: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":17,"current":0.31,"state":"ON"}'
2020-01-23 09:56:57: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.31,"state":"ON"}'
2020-01-23 09:57:00: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.306,"state":"ON"}'
2020-01-23 09:57:07: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":54,"power":20,"current":0.306,"state":"ON"}'
2020-01-23 09:57:10: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":54,"power":20,"current":0.31,"state":"ON"}'
2020-01-23 09:57:15: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":54,"power":20,"current":0.307,"state":"ON"}'
2020-01-23 09:57:20: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":54,"power":20,"current":0.31,"state":"ON"}'
2020-01-23 09:57:21: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.31,"state":"ON"}'
2020-01-23 09:57:25: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.307,"state":"ON"}'
2020-01-23 09:57:30: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.31,"state":"ON"}'
2020-01-23 09:57:40: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":52,"power":20,"current":0.307,"state":"ON"}'
2020-01-23 09:58:08: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.31,"state":"ON"}'
2020-01-23 09:58:08: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":54,"power":20,"current":0.31,"state":"OFF"}'
2020-01-23 09:58:09: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":65,"power":20,"current":0.31,"state":"OFF"}'
2020-01-23 09:58:10: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":62,"power":0,"current":0.31,"state":"OFF"}'
2020-01-23 09:58:13: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":65,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:58:31: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":236,"linkquality":59,"power":0,"current":0,"state":"OFF"}'
2020-01-23 09:58:45: MQTT publish: topic 'zigbee2mqtt/0x00158d00034450be', payload '{"voltage":239,"linkquality":65,"power":0,"current":0,"state":"OFF"}'

[wisekki]

I'm not sure if this modification has anything to do with the 'off' -statusreporting but I measured and compared off-reporting from two devices for one hour. Newly configured device reported off-status for 144 times and an old one only 90 times.

[Koenkk]

@wisekki thanks, I've made 5 seconds the default now.

[turboproc]

Running

info 2020-01-29 14:59:29: Starting zigbee2mqtt version 1.9.0 (commit #287f843)
info 2020-01-29 14:59:29: Starting zigbee-herdsman...
info 2020-01-29 14:59:31: zigbee-herdsman started
info 2020-01-29 14:59:31: Coordinator firmware version: '{"type":"zStack12","meta":{"transportrev":2,"product":0,"majorrel":2,"minorrel":6,"maintrel":3,"revision":20190608}
}'

I've exactly the same issue with 2 SP 120 devices that refuse to be configured.

`{"id":14,"type":"Router","ieeeAddr":"0x00158d000388f6ff","nwkAddr":21318,"manufId":4454,"manufName":"innr","powerSource":"Mains (single phase)","modelId":"SP 120","epList":[
1,2],"endpoints":{"1":{"profId":49246,"epId":1,"devId":16,"inClusterList":[0,4,3,6,8,5,2820,1794,10],"outClusterList":[3,25,10],"clusters":{"genBasic":{"attributes":{"modelI
d":"SP 120","manufacturerName":"innr","powerSource":1,"zclVersion":2,"appVersion":1,"stackVersion":2,"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}},"genOnOff":{
"attributes":{"onOff":1}}},"binds":[]},"2":{"profId":49246,"epId":2,"devId":4096,"inClusterList":[4096],"outClusterList":[],"clusters":{},"binds":[]}},"appVersion":1,"stackV
ersion":2,"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0","zclVersion":2,"interviewCompleted":true,"meta":{},"lastSeen":1580248978754}
{"id":15,"type":"Router","ieeeAddr":"0x00158d000388f73e","nwkAddr":12532,"manufId":4454,"manufName":"innr","powerSource":"Mains (single phase)","modelId":"SP 120","epList":[
1,2],"endpoints":{"1":{"profId":49246,"epId":1,"devId":16,"inClusterList":[0,4,3,6,8,5,2820,1794,10],"outClusterList":[3,25,10],"clusters":{"genBasic":{"attributes":{"modelI
d":"SP 120","manufacturerName":"innr","powerSource":1,"zclVersion":2,"appVersion":1,"stackVersion":2,"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}}},"binds":[]}
,"2":{"profId":49246,"epId":2,"devId":4096,"inClusterList":[4096],"outClusterList":[],"clusters":{},"binds":[]}},"appVersion":1,"stackVersion":2,"hwVersion":1,"dateCode":"20
171027-100","swBuildId":"2.0","zclVersion":2,"interviewCompleted":true,"meta":{},"lastSeen":1580306330952}

so interview phase seems completed but configuration is not.

Any idea how to solve this?`

[turboproc]

Providing some further details when forcing a configure of the device:

zigbee2mqtt:debug 2020-01-29 19:10:23: Received MQTT message on 'zigbee2mqtt/bridge/configure' with data '0x00158d000388f73e' zigbee2mqtt:info 2020-01-29 19:10:23: Configuring '0x00158d000388f73e' zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - bindReq - {"dstaddr":12532,"srcaddr":"0x00158d000388f73e","srcendpoint":1,"clusterid":6,"dstaddrmode":3,"dstaddress":"0x00124b00193664ab","dstendpoint":1} +7s zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,23,37,33,244,48,62,247,136,3,0,141,21,0,1,6,0,3,171,100,54,25,0,75,18,0,1,177] +7s zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,33,0,69] +6s zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,33,0,69] +0ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 33 - [0] - 69 +1ms zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - bindReq - {"status":0} +7s zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms zigbee2mqtt:error 2020-01-29 19:10:33: Failed to configure '0x00158d000388f73e', attempt 6 (Error: AREQ - ZDO - bindRsp after 10000ms at Timeout.object.timer.setTimeout [as _onTimeout] (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/utils/waitress.js:44:24) at ontimeout (timers.js:436:11) at tryOnTimeout (timers.js:300:5) at listOnTimeout (timers.js:263:5) at Timer.processTimers (timers.js:223:10))

[Koenkk]

@turboproc could you check if it works correctly with zigbee2mqtt 1.6.0?

[turboproc]

@Koenkk : Oops, downgrade ? Can of course give it a try. Any instruction to do so ?

[Koenkk]

@turboproc I would recommend to do it on a separate (temporary) setup, perhaps with a different CC2531. Do you have one?

[turboproc]

@Koenkk . Yes, that would be possible. Having another raspberry available and CC2531. Just need to understand how to install version 1.6.0

[Koenkk]

@turboproc when following https://www.zigbee2mqtt.io/getting_started/running_zigbee2mqtt.html, after sudo git clone https://github.com/Koenkk/zigbee2mqtt.git /opt/zigbee2mqtt do

sudo git checkout tags/1.6.0

[turboproc]

Weird, can;t get the second CC2531 (same firmware) with z2m v1.6.0 not really into action. Trying to bind the SP-120 doesn;t show any message although joining is enabled.

[Koenkk]

@turboproc probably because it pairs to your existing network. Try powering that down. (https://www.zigbee2mqtt.io/information/FAQ.html#no-logging-is-shown-at-all)

[turboproc]

Indeed, had to remove the device from my main network using config/remove. Good news, the SP-120 pairs with the 1.6.0 version of z2m.

[turboproc]

`zigbee2mqtt:info 2/1/2020, 12:17:21 AM Removed 0x00158d000388f73e
zigbee2mqtt:debug 2/1/2020, 12:17:22 AM Saving state to file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:info 2/1/2020, 12:17:22 AM Successfully removed 0x00158d000388f73e
zigbee2mqtt:info 2/1/2020, 12:17:22 AM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_removed","message":"0x00158d000388f73e"}'

zigbee-herdsman:unpi:parser <-- [254,12,69,202,172,125,62,247,136,3,0,141,21,0,0,0,136] +2m
zigbee-herdsman:unpi:parser --- parseNext [254,12,69,202,172,125,62,247,136,3,0,141,21,0,0,0,136] +1ms
zigbee-herdsman:unpi:parser --> parsed 12 - 2 - 5 - 202 - [�}>���] - 136 +1ms
zigbee-herdsman:znp:AREQ <-- ZDO - tcDeviceInd - {"nwkaddr":32172,"extaddr":"0x00158d000388f73e","parentaddr":0} +2m
zigbee-herdsman:unpi:parser --- parseNext [] +3ms
zigbee-herdsman:unpi:parser <-- [254,13,69,193,172,125,172,125,62,247,136,3,0,141,21,0,142,221] +76ms
zigbee-herdsman:unpi:parser --- parseNext [254,13,69,193,172,125,172,125,62,247,136,3,0,141,21,0,142,221] +1ms
zigbee-herdsman:unpi:parser --> parsed 13 - 2 - 5 - 193 - [�}�}>����] - 221 +1ms
zigbee-herdsman:znp:AREQ <-- ZDO - endDeviceAnnceInd - {"srcaddr":32172,"nwkaddr":32172,"ieeeaddr":"0x00158d000388f73e","capabilities":142} +81ms
zigbee-herdsman:znp:SREQ --> ZDO - nodeDescReq - {"dstaddr":32172,"nwkaddrofinterest":32172} +2m
zigbee-herdsman:unpi:writer --> frame [254,4,37,2,172,125,172,125,35] +2m
zigbee-herdsman:unpi:parser --- parseNext [] +8ms
zigbee-herdsman:unpi:parser <-- [254,1,101,2,0,102] +326ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,101,2,0,102] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 5 - 2 - [] - 102 +1ms
zigbee-herdsman:znp:SRSP <-- ZDO - nodeDescReq - {"status":0} +2m
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,18,69,130,172,125,0,172,125,1,64,142,102,17,127,80,0,0,0,80,0,0,18] +29ms
zigbee-herdsman:unpi:parser --- parseNext [254,18,69,130,172,125,0,172,125,1,64,142,102,17,127,80,0,0,0,80,0,0,18] +1ms
zigbee-herdsman:unpi:parser --> parsed 18 - 2 - 5 - 130 - [�}�}@�PP] - 18 +0ms
zigbee-herdsman:znp:AREQ <-- ZDO - nodeDescRsp - {"srcaddr":32172,"status":0,"nwkaddr":32172,"logicaltype_cmplxdescavai_userdescavai":1,"apsflags_freqband":64,"maccapflags":142,"manufacturercode":4454,"maxbuffersize":127,"maxintransfersize":80,"servermask":0,"maxouttransfersize":80,"descriptorcap":0} +366ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:znp:SREQ --> ZDO - activeEpReq - {"dstaddr":32172,"nwkaddrofinterest":32172} +365ms
zigbee-herdsman:unpi:writer --> frame [254,4,37,5,172,125,172,125,36] +364ms
zigbee-herdsman:unpi:parser <-- [254,1,101,5,0,97] +15ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,101,5,0,97] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 5 - 5 - [] - 97 +1ms
zigbee-herdsman:znp:SRSP <-- ZDO - activeEpReq - {"status":0} +49ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,8,69,133,172,125,0,172,125,2,1,2,201] +27ms
zigbee-herdsman:unpi:parser --- parseNext [254,8,69,133,172,125,0,172,125,2,1,2,201] +1ms
zigbee-herdsman:unpi:parser --> parsed 8 - 2 - 5 - 133 - [�}�}] - 201 +0ms
zigbee-herdsman:znp:AREQ <-- ZDO - activeEpRsp - {"srcaddr":32172,"status":0,"nwkaddr":32172,"activeepcount":2,"activeeplist":{"type":"Buffer","data":[1,2]}} +49ms
zigbee-herdsman:unpi:parser --- parseNext [] +3ms
zigbee-herdsman:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":32172,"nwkaddrofinterest":32172,"endpoint":1} +50ms
zigbee-herdsman:unpi:writer --> frame [254,5,37,4,172,125,172,125,1,37] +50ms
zigbee-herdsman:unpi:parser <-- [254,1,101,4,0,96] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,101,4,0,96] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 5 - 4 - [] - 96 +1ms
zigbee-herdsman:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +50ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,38,69,132,172,125,0,172,125,32,1,94,192,16,0,2,9,0,0,4,0,3,0,6,0,8,0,5,0,4,11,2,7,10,0,3,3,0,25,0,10,0,92] +27ms
zigbee-herdsman:unpi:parser --- parseNext [254,38,69,132,172,125,0,172,125,32,1,94,192,16,0,2,9,0,0,4,0,3,0,6,0,8,0,5,0,4,11,2,7,10,0,3,3,0,25,0,10,0,92] +1ms
zigbee-herdsman:unpi:parser --> parsed 38 - 2 - 5 - 132 - [�}�} ^�

zigbee-herdsman:unpi:parser
zigbee-herdsman:unpi:parser ] - 92 +1ms
zigbee-herdsman:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":32172,"status":0,"nwkaddr":32172,"len":32,"endpoint":1,"profileid":49246,"deviceid":16,"deviceversion":2,"numinclusters":9,"inclusterlist":[0,4,3,6,8,5,2820,1794,10],"numoutclusters":3,"outclusterlist":[3,25,10]} +51ms
zigbee-herdsman:unpi:parser --- parseNext [] +3ms
zigbee-herdsman:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":32172,"nwkaddrofinterest":32172,"endpoint":2} +51ms
zigbee-herdsman:unpi:writer --> frame [254,5,37,4,172,125,172,125,2,38] +52ms
zigbee-herdsman:unpi:parser <-- [254,1,101,4,0,96] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,101,4,0,96] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 5 - 4 - [] - 96 +1ms
zigbee-herdsman:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +52ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,16,69,132,172,125,0,172,125,10,2,94,192,0,16,2,1,0,16,0,68] +27ms
zigbee-herdsman:unpi:parser --- parseNext [254,16,69,132,172,125,0,172,125,10,2,94,192,0,16,2,1,0,16,0,68] +2ms
zigbee-herdsman:unpi:parser --> parsed 16 - 2 - 5 - 132 - [�}�}
zigbee-herdsman:unpi:parser ^�] - 68 +0ms
zigbee-herdsman:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":32172,"status":0,"nwkaddr":32172,"len":10,"endpoint":2,"profileid":49246,"deviceid":4096,"deviceversion":2,"numinclusters":1,"inclusterlist":[4096],"numoutclusters":0,"outclusterlist":[]} +51ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
PuTTY zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":3,"options":48,"radius":30,"len":9,"data":{"type":"Buffer","data":[0,3,0,4,0,5,0,7,0]}} +78ms
zigbee-herdsman:unpi:writer --> frame [254,19,36,1,172,125,1,1,0,0,3,48,30,9,0,3,0,4,0,5,0,7,0,198] +78ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +45ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +79ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,3,197] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,3,197] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 197 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":3} +69ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,48,68,129,0,0,0,0,172,125,1,1,0,55,0,29,63,29,0,0,28,24,3,1,4,0,0,66,4,105,110,110,114,5,0,0,66,6,83,80,32,49,50,48,7,0,0,48,1,172,125,29,216] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,48,68,129,0,0,0,0,172,125,1,1,0,55,0,29,63,29,0,0,28,24,3,1,4,0,0,66,4,105,110,110,114,5,0,0,66,6,83,80,32,49,50,48,7,0,0,48,1,172,125,29,216] +2ms
zigbee-herdsman:unpi:parser --> parsed 48 - 2 - 4 - 129 - [�}7?BinnrBSP 1200�}] - 216 +0ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":55,"securityuse":0,"timestamp":1916701,"transseqnumber":0,"len":28,"data":{"type":"Buffer","data":[24,3,1,4,0,0,66,4,105,110,110,114,5,0,0,66,6,83,80,32,49,50,48,7,0,0,48,1]}} +23ms
PuTTY zigbee-herdsman:unpi:parser --- parseNext [] +36ms
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"manufacturerName":"innr","modelId":"SP 120","powerSource":1}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:info 2/1/2020, 12:19:17 AM New device 'SP 120' with address 0x00158d000388f73e connected!
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Saving state to file /opt/zigbee2mqtt/data/state.json
zigbee2mqtt:info 2/1/2020, 12:19:17 AM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":"0x00158d000388f73e","meta":{"modelID":"SP 120"}}'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":4,"options":48,"radius":30,"len":15,"data":{"type":"Buffer","data":[0,4,0,0,0,1,0,2,0,3,0,6,0,0,64]}} +169ms
zigbee-herdsman:unpi:writer --> frame [254,25,36,1,172,125,1,1,0,0,4,48,30,15,0,4,0,0,0,1,0,2,0,3,0,6,0,0,64,138] +168ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +83ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +163ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,4,194] +30ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,4,194] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 194 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":4} +150ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,68,68,129,0,0,0,0,172,125,1,1,0,60,0,10,65,29,0,0,48,24,4,1,0,0,0,32,2,1,0,0,32,1,2,0,0,32,2,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48,172,125,29,162] +8ms
zigbee-herdsman:unpi:parser --- parseNext [254,68,68,129,0,0,0,0,172,125,1,1,0,60,0,10,65,29,0,0,48,24,4,1,0,0,0,32,2,1,0,0,32,1,2,0,0,32,2,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48,172,125,29,162] +1ms
zigbee-herdsman:unpi:parser --> parsed 68 - 2 - 4 - 129 - [�}<
zigbee-herdsman:unpi:parser A0 B
[email protected]�}] - 162 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":60,"securityuse":0,"timestamp":1917194,"transseqnumber":0,"len":48,"data":{"type":"Buffer","data":[24,4,1,0,0,0,32,2,1,0,0,32,1,2,0,0,32,2,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48]}} +12ms
zigbee-herdsman:unpi:parser --- parseNext [] +47ms
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":2,"appVersion":1,"stackVersion":2,"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":5,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,5,12,0,0,240]}} +136ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,0,0,5,48,30,6,0,5,12,0,0,240,48] +136ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +46ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +137ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,5,195] +26ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,5,195] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 195 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":5} +121ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,54,68,129,0,0,0,0,172,125,1,1,0,57,0,173,66,29,0,0,34,24,5,13,1,0,0,32,1,0,32,2,0,32,3,0,32,4,0,66,5,0,66,6,0,66,7,0,48,10,0,65,0,64,66,172,125,29,45] +4ms
zigbee-herdsman:unpi:parser --- parseNext [254,54,68,129,0,0,0,0,172,125,1,1,0,57,0,173,66,29,0,0,34,24,5,13,1,0,0,32,1,0,32,2,0,32,3,0,32,4,0,66,5,0,66,6,0,66,7,0,48,10,0,65,0,64,66,172,125,29,45] +1ms
BBB0-herdsman:unpi:parser --> parsed 54 - 2 - 4 - 129 - [�}9�B"
zigbee-herdsman:unpi:parser A@B�}] - 45 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":57,"securityuse":0,"timestamp":1917613,"transseqnumber":0,"len":34,"data":{"type":"Buffer","data":[24,5,13,1,0,0,32,1,0,32,2,0,32,3,0,32,4,0,66,5,0,66,6,0,66,7,0,48,10,0,65,0,64,66]}} +8ms
PuTTYPuTTYPuTTY zigbee-herdsman:unpi:parser --- parseNext [] +46ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":6,"options":48,"radius":30,"len":13,"data":{"type":"Buffer","data":[0,6,0,0,0,1,0,2,0,3,0,4,0]}} +108ms
zigbee-herdsman:unpi:writer --> frame [254,23,36,1,172,125,1,1,0,0,6,48,30,13,0,6,0,0,0,1,0,2,0,3,0,4,0,196] +109ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +26ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +107ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,6,192] +19ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,6,192] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 192 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":6} +94ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,52,68,129,0,0,0,0,172,125,1,1,0,55,0,17,68,29,0,0,32,24,6,1,0,0,0,32,2,1,0,0,32,1,2,0,0,32,2,3,0,0,32,1,4,0,0,66,4,105,110,110,114,172,125,29,245] +15ms
zigbee-herdsman:unpi:parser --- parseNext [254,52,68,129,0,0,0,0,172,125,1,1,0,55,0,17,68,29,0,0,32,24,6,1,0,0,0,32,2,1,0,0,32,1,2,0,0,32,2,3,0,0,32,1,4,0,0,66,4,105,110,110,114,172,125,29,245] +1ms
zigbee-herdsman:unpi:parser --> parsed 52 - 2 - 4 - 129 - [�}7D Binnr�}] - 245 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":55,"securityuse":0,"timestamp":1917969,"transseqnumber":0,"len":32,"data":{"type":"Buffer","data":[24,6,1,0,0,0,32,2,1,0,0,32,1,2,0,0,32,2,3,0,0,32,1,4,0,0,66,4,105,110,110,114]}} +18ms
zigbee-herdsman:unpi:parser --- parseNext [] +41ms
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":2,"appVersion":1,"stackVersion":2,"hwVersion":1,"manufacturerName":"innr"}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":7,"options":48,"radius":30,"len":13,"data":{"type":"Buffer","data":[0,7,0,5,0,6,0,7,0,10,0,0,64]}} +107ms
zigbee-herdsman:unpi:writer --> frame [254,23,36,1,172,125,1,1,0,0,7,48,30,13,0,7,0,5,0,6,0,7,0,10,0,0,64,142] +106ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +107ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,7,193] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,7,193] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 193 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":7} +95ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,78,68,129,0,0,0,0,172,125,1,1,0,60,0,127,69,29,0,0,58,24,7,1,5,0,0,66,6,83,80,32,49,50,48,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,7,0,0,48,1,10,0,0,65,9,48,49,48,52,48,48,48,56,50,0,64,0,66,3,50,46,48,172,125,29,202] +24ms
zigbee-herdsman:unpi:parser --- parseNext [254,78,68,129,0,0,0,0,172,125,1,1,0,60,0,127,69,29,0,0,58,24,7,1,5,0,0,66,6,83,80,32,49,50,48,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,7,0,0,48,1,10,0,0,65,9,48,49,48,52,48,48,48,56,50,0,64,0,66,3,50,46,48,172,125,29,202] +1ms
zigbee-herdsman:unpi:parser --> parsed 78 - 2 - 4 - 129 - [�}E:BSP 120B
20171027-1000
zigbee-herdsman:unpi:parser A [email protected]�}] - 202 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":60,"securityuse":0,"timestamp":1918335,"transseqnumber":0,"len":58,"data":{"type":"Buffer","data":[24,7,1,5,0,0,66,6,83,80,32,49,50,48,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,7,0,0,48,1,10,0,0,65,9,48,49,48,52,48,48,48,56,50,0,64,0,66,3,50,46,48]}} +28ms
PuTTY zigbee-herdsman:unpi:parser --- parseNext [] +38ms
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"10":{"type":"Buffer","data":[48,49,48,52,48,48,48,56,50]},"modelId":"SP 120","dateCode":"20171027-100","powerSource":1,"swBuildId":"2.0"}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":3,"transid":8,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,8,12,0,0,240]}} +126ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,3,0,8,48,30,6,0,8,12,0,0,240,51] +126ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +31ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +126ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,8,206] +27ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,8,206] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - ] - 206 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":8} +98ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,27,68,129,0,0,3,0,172,125,1,1,0,57,0,5,71,29,0,0,7,24,8,13,1,0,0,33,172,125,29,156] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,27,68,129,0,0,3,0,172,125,1,1,0,57,0,5,71,29,0,0,7,24,8,13,1,0,0,33,172,125,29,156] +0ms
!�}] - 156 +1msan:unpi:parser --> parsed 27 - 2 - 4 - 129 - [�}9G
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":3,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":57,"securityuse":0,"timestamp":1918725,"transseqnumber":0,"len":7,"data":{"type":"Buffer","data":[24,8,13,1,0,0,33]}} +19ms
zigbee-herdsman:unpi:parser --- parseNext [] +8ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":3,"transid":9,"options":48,"radius":30,"len":5,"data":{"type":"Buffer","data":[0,9,0,0,0]}} +72ms
zigbee-herdsman:unpi:writer --> frame [254,15,36,1,172,125,1,1,3,0,9,48,30,5,0,9,0,0,0,211] +72ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +71ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,9,207] +29ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,9,207] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [ ] - 207 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":9} +56ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,29,68,129,0,0,3,0,172,125,1,1,0,70,0,194,71,29,0,0,9,24,9,1,0,0,0,33,0,0,172,125,29,32] +6ms
zigbee-herdsman:unpi:parser --- parseNext [254,29,68,129,0,0,3,0,172,125,1,1,0,70,0,194,71,29,0,0,9,24,9,1,0,0,0,33,0,0,172,125,29,32] +1ms
zigbee-herdsman:unpi:parser --> parsed 29 - 2 - 4 - 129 - [�}F�G !�}] - 32 +0ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":3,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":70,"securityuse":0,"timestamp":1918914,"transseqnumber":0,"len":9,"data":{"type":"Buffer","data":[24,9,1,0,0,0,33,0,0]}} +8ms
PuTTY zigbee-herdsman:unpi:parser --- parseNext [] +9ms
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'readRsp' with data '{"cid":"genIdentify","data":{"identifyTime":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":4,"transid":10,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,10,12,0,0,240]}} +81ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,4,0,10,48,30,6,0,10,12,0,0,240,52] +81ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +32ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +82ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,10,204] +21ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,10,204] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [
zigbee-herdsman:unpi:parser ] - 204 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":10} +64ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,27,68,129,0,0,4,0,172,125,1,1,0,70,0,209,72,29,0,0,7,24,10,13,1,0,0,24,172,125,29,4] +17ms
zigbee-herdsman:unpi:parser --- parseNext [254,27,68,129,0,0,4,0,172,125,1,1,0,70,0,209,72,29,0,0,7,24,10,13,1,0,0,24,172,125,29,4] +1ms
zigbee-herdsman:unpi:parser --> parsed 27 - 2 - 4 - 129 - [�}F�H
�}] - 4 +0msdsman:unpi:parser
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":4,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":70,"securityuse":0,"timestamp":1919185,"transseqnumber":0,"len":7,"data":{"type":"Buffer","data":[24,10,13,1,0,0,24]}} +20ms
zigbee-herdsman:unpi:parser --- parseNext [] +8ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":4,"transid":11,"options":48,"radius":30,"len":5,"data":{"type":"Buffer","data":[0,11,0,0,0]}} +67ms
zigbee-herdsman:unpi:writer --> frame [254,15,36,1,172,125,1,1,4,0,11,48,30,5,0,11,0,0,0,212] +67ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +66ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,11,205] +22ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,11,205] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [
] - 205 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":11} +48ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,28,68,129,0,0,4,0,172,125,1,1,0,57,0,167,73,29,0,0,8,24,11,1,0,0,0,24,0,172,125,29,8] +17ms
zigbee-herdsman:unpi:parser --- parseNext [254,28,68,129,0,0,4,0,172,125,1,1,0,57,0,167,73,29,0,0,8,24,11,1,0,0,0,24,0,172,125,29,8] +0ms
zigbee-herdsman:unpi:parser --> parsed 28 - 2 - 4 - 129 - [�}9�I
�}] - 8 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":4,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":57,"securityuse":0,"timestamp":1919399,"transseqnumber":0,"len":8,"data":{"type":"Buffer","data":[24,11,1,0,0,0,24,0]}} +20ms
zigbee-herdsman:unpi:parser --- parseNext [] +9ms
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'readRsp' with data '{"cid":"genGroups","data":{"nameSupport":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:17 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":5,"transid":12,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,12,12,0,0,240]}} +77ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,5,0,12,48,30,6,0,12,12,0,0,240,53] +77ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +78ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,12,202] +31ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,12,202] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [
] - 202 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":12} +67ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,42,68,129,0,0,5,0,172,125,1,1,0,63,0,137,74,29,0,0,22,24,12,13,1,0,0,32,1,0,32,2,0,33,3,0,16,4,0,24,5,0,240,172,125,29,192] +5ms
zigbee-herdsman:unpi:parser --- parseNext [254,42,68,129,0,0,5,0,172,125,1,1,0,63,0,137,74,29,0,0,22,24,12,13,1,0,0,32,1,0,32,2,0,33,3,0,16,4,0,24,5,0,240,172,125,29,192] +1ms
zigbee-herdsman:unpi:parser --> parsed 42 - 2 - 4 - 129 - [�}?�J
!�}] - 192 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":5,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":63,"securityuse":0,"timestamp":1919625,"transseqnumber":0,"len":22,"data":{"type":"Buffer","data":[24,12,13,1,0,0,32,1,0,32,2,0,33,3,0,16,4,0,24,5,0,240]}} +9ms
PuTTYPuTTY zigbee-herdsman:unpi:parser --- parseNext [] +25ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":5,"transid":13,"options":48,"radius":30,"len":13,"data":{"type":"Buffer","data":[0,13,0,0,0,1,0,2,0,3,0,4,0]}} +95ms
zigbee-herdsman:unpi:writer --> frame [254,23,36,1,172,125,1,1,5,0,13,48,30,13,0,13,0,0,0,1,0,2,0,3,0,4,0,193] +96ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +28ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +96ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,13,203] +20ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,13,203] +1ms
] - 203 +0msdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":13} +77ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,49,68,129,0,0,5,0,172,125,1,1,0,0,0,182,75,29,0,0,29,24,13,1,0,0,0,32,1,1,0,0,32,0,2,0,0,33,0,0,3,0,0,16,0,4,0,0,24,0,172,125,29,41] +15ms
zigbee-herdsman:unpi:parser --- parseNext [254,49,68,129,0,0,5,0,172,125,1,1,0,0,0,182,75,29,0,0,29,24,13,1,0,0,0,32,1,1,0,0,32,0,2,0,0,33,0,0,3,0,0,16,0,4,0,0,24,0,172,125,29,41] +1ms
!�}] - 41 +1msn:unpi:parser --> parsed 49 - 2 - 4 - 129 - [�}�K
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":5,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":0,"securityuse":0,"timestamp":1919926,"transseqnumber":0,"len":29,"data":{"type":"Buffer","data":[24,13,1,0,0,0,32,1,1,0,0,32,0,2,0,0,33,0,0,3,0,0,16,0,4,0,0,24,0]}} +19ms
zigbee-herdsman:unpi:parser --- parseNext [] +37ms
PuTTY zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'readRsp' with data '{"cid":"genScenes","data":{"count":1,"currentScene":0,"currentGroup":0,"sceneValid":0,"nameSupport":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":5,"transid":14,"options":48,"radius":30,"len":5,"data":{"type":"Buffer","data":[0,14,0,5,0]}} +118ms
zigbee-herdsman:unpi:writer --> frame [254,15,36,1,172,125,1,1,5,0,14,48,30,5,0,14,0,5,0,208] +117ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +39ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +118ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,14,200] +37ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,14,200] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 200 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":14} +115ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,35,68,129,0,0,5,0,172,125,1,1,0,86,0,82,77,29,0,0,15,24,14,1,5,0,0,240,255,255,255,255,255,255,255,255,172,125,29,71] +11ms
zigbee-herdsman:unpi:parser --- parseNext [254,35,68,129,0,0,5,0,172,125,1,1,0,86,0,82,77,29,0,0,15,24,14,1,5,0,0,240,255,255,255,255,255,255,255,255,172,125,29,71] +1ms
zigbee-herdsman:unpi:parser --> parsed 35 - 2 - 4 - 129 - [�}VRM����������}] - 71 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":5,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":86,"securityuse":0,"timestamp":1920338,"transseqnumber":0,"len":15,"data":{"type":"Buffer","data":[24,14,1,5,0,0,240,255,255,255,255,255,255,255,255]}} +15ms
zigbee-herdsman:unpi:parser --- parseNext [] +12ms
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'readRsp' with data '{"cid":"genScenes","data":{"lastCfgBy":"0xffffffffffffffff"}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":6,"transid":15,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,15,12,0,0,240]}} +98ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,6,0,15,48,30,6,0,15,12,0,0,240,54] +98ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +32ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +98ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,15,201] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,15,201] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 201 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":15} +71ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,36,68,129,0,0,6,0,172,125,1,1,0,94,0,114,78,29,0,0,16,24,15,13,1,0,0,16,0,64,16,1,64,33,2,64,33,172,125,29,205] +17ms
zigbee-herdsman:unpi:parser --- parseNext [254,36,68,129,0,0,6,0,172,125,1,1,0,94,0,114,78,29,0,0,16,24,15,13,1,0,0,16,0,64,16,1,64,33,2,64,33,172,125,29,205] +1ms
@@!@!�}] - 205 +0msnpi:parser --> parsed 36 - 2 - 4 - 129 - [�}^rN
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":94,"securityuse":0,"timestamp":1920626,"transseqnumber":0,"len":16,"data":{"type":"Buffer","data":[24,15,13,1,0,0,16,0,64,16,1,64,33,2,64,33]}} +20ms
PuTTYPuTTY zigbee-herdsman:unpi:parser --- parseNext [] +18ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":6,"transid":16,"options":48,"radius":30,"len":11,"data":{"type":"Buffer","data":[0,16,0,0,0,0,64,1,64,2,64]}} +83ms
zigbee-herdsman:unpi:writer --> frame [254,21,36,1,172,125,1,1,6,0,16,48,30,11,0,16,0,0,0,0,64,1,64,2,64,129] +84ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +17ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +82ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,16,214] +21ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,16,214] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 214 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":16} +58ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,45,68,129,0,0,6,0,172,125,1,1,0,94,0,102,79,29,0,0,25,24,16,1,0,0,0,16,0,0,64,0,16,1,1,64,0,33,0,0,2,64,0,33,0,0,172,125,29,203] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,45,68,129,0,0,6,0,172,125,1,1,0,94,0,102,79,29,0,0,25,24,16,1,0,0,0,16,0,0,64,0,16,1,1,64,0,33,0,0,2,64,0,33,0,0,172,125,29,203] +1ms
zigbee-herdsman:unpi:parser --> parsed 45 - 2 - 4 - 129 - [�}^fO@@!@!�}] - 203 +0ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":94,"securityuse":0,"timestamp":1920870,"transseqnumber":0,"len":25,"data":{"type":"Buffer","data":[24,16,1,0,0,0,16,0,0,64,0,16,1,1,64,0,33,0,0,2,64,0,33,0,0]}} +21ms
zigbee-herdsman:unpi:parser --- parseNext [] +22ms
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'readRsp' with data '{"cid":"genOnOff","data":{"onOff":0,"globalSceneCtrl":1,"onTime":0,"offWaitTime":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:info 2/1/2020, 12:19:18 AM MQTT publish: topic 'zigbee2mqtt/0x00158d000388f73e', payload '{"state":"OFF","linkquality":94}'
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":8,"transid":17,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,17,12,0,0,240]}} +102ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,8,0,17,48,30,6,0,17,12,0,0,240,56] +101ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +36ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +102ms
zigbee-herdsman:unpi:parser --- parseNext [] +0ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,17,215] +31ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,17,215] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 215 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":17} +91ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,33,68,129,0,0,8,0,172,125,1,1,0,89,0,151,80,29,0,0,13,24,17,13,1,0,0,32,1,0,33,16,0,33,172,125,29,75] +6ms
zigbee-herdsman:unpi:parser --- parseNext [254,33,68,129,0,0,8,0,172,125,1,1,0,89,0,151,80,29,0,0,13,24,17,13,1,0,0,32,1,0,33,16,0,33,172,125,29,75] +1ms
!!�}] - 75 +0msn:unpi:parser --> parsed 33 - 2 - 4 - 129 - �}Y�P
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":8,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":89,"securityuse":0,"timestamp":1921175,"transseqnumber":0,"len":13,"data":{"type":"Buffer","data":[24,17,13,1,0,0,32,1,0,33,16,0,33]}} +8ms
zigbee-herdsman:unpi:parser --- parseNext [] +14ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":8,"transid":18,"options":48,"radius":30,"len":9,"data":{"type":"Buffer","data":[0,18,0,0,0,1,0,16,0]}} +72ms
zigbee-herdsman:unpi:writer --> frame [254,19,36,1,172,125,1,1,8,0,18,48,30,9,0,18,0,0,0,1,0,16,0,217] +72ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +72ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,18,212] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,18,212] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 212 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":18} +51ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,40,68,129,0,0,8,0,172,125,1,1,0,94,0,111,81,29,0,0,20,24,18,1,0,0,0,32,254,1,0,0,33,0,0,16,0,0,33,0,0,172,125,29,85] +14ms
zigbee-herdsman:unpi:parser --- parseNext [254,40,68,129,0,0,8,0,172,125,1,1,0,94,0,111,81,29,0,0,20,24,18,1,0,0,0,32,254,1,0,0,33,0,0,16,0,0,33,0,0,172,125,29,85] +1ms
zigbee-herdsman:unpi:parser --> parsed 40 - 2 - 4 - 129 - �}^oQ �!!�}] - 85 +0ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":8,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":94,"securityuse":0,"timestamp":1921391,"transseqnumber":0,"len":20,"data":{"type":"Buffer","data":[24,18,1,0,0,0,32,254,1,0,0,33,0,0,16,0,0,33,0,0]}} +17ms
zigbee-herdsman:unpi:parser --- parseNext [] +23ms
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'readRsp' with data '{"cid":"genLevelCtrl","data":{"currentLevel":254,"remainingTime":0,"onOffTransitionTime":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":10,"transid":19,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,19,12,0,0,240]}} +89ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,10,0,19,48,30,6,0,19,12,0,0,240,58] +89ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +28ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +89ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,19,213] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,19,213] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 213 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":19} +78ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,30,68,129,0,0,10,0,172,125,1,1,0,92,0,159,82,29,0,0,10,24,19,13,1,0,0,226,1,0,24,172,125,29,182] +14ms
zigbee-herdsman:unpi:parser --- parseNext [254,30,68,129,0,0,10,0,172,125,1,1,0,92,0,159,82,29,0,0,10,24,19,13,1,0,0,226,1,0,24,172,125,29,182] +1ms
zigbee-herdsman:unpi:parser --> parsed 30 - 2 - 4 - 129 - [
zigbee-herdsman:unpi:parser �}\�R
��}] - 182 +1msan:unpi:parser
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":10,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":92,"securityuse":0,"timestamp":1921695,"transseqnumber":0,"len":10,"data":{"type":"Buffer","data":[24,19,13,1,0,0,226,1,0,24]}} +17ms
zigbee-herdsman:unpi:parser --- parseNext [] +10ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":10,"transid":20,"options":48,"radius":30,"len":7,"data":{"type":"Buffer","data":[0,20,0,0,0,1,0]}} +71ms
zigbee-herdsman:unpi:writer --> frame [254,17,36,1,172,125,1,1,10,0,20,48,30,7,0,20,0,0,0,1,0,199] +71ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +70ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,20,210] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,20,210] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 210 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":20} +47ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,36,68,129,0,0,10,0,172,125,1,1,0,94,0,89,83,29,0,0,16,24,20,1,0,0,0,226,0,0,0,0,1,0,0,24,0,172,125,29,89] +12ms
zigbee-herdsman:unpi:parser --- parseNext [254,36,68,129,0,0,10,0,172,125,1,1,0,94,0,89,83,29,0,0,16,24,20,1,0,0,0,226,0,0,0,0,1,0,0,24,0,172,125,29,89] +1ms
zigbee-herdsman:unpi:parser --> parsed 36 - 2 - 4 - 129 - [
zigbee-herdsman:unpi:parser �}^YS��}] - 89 +0ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":10,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":94,"securityuse":0,"timestamp":1921881,"transseqnumber":0,"len":16,"data":{"type":"Buffer","data":[24,20,1,0,0,0,226,0,0,0,0,1,0,0,24,0]}} +15ms
zigbee-herdsman:unpi:parser --- parseNext [] +13ms
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'readRsp' with data '{"cid":"genTime","data":{"time":0,"timeStatus":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":25,"transid":21,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,21,12,0,0,240]}} +71ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,25,0,21,48,30,6,0,21,12,0,0,240,41] +72ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +73ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,21,211] +19ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,21,211] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 211 +0ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":21} +60ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,24,68,129,0,0,25,0,172,125,1,1,0,97,0,89,84,29,0,0,4,24,21,13,1,172,125,29,173] +21ms
zigbee-herdsman:unpi:parser --- parseNext [254,24,68,129,0,0,25,0,172,125,1,1,0,97,0,89,84,29,0,0,4,24,21,13,1,172,125,29,173] +1ms
�}] - 173 +1msman:unpi:parser --> parsed 24 - 2 - 4 - 129 - [�}aYT
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":25,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":97,"securityuse":0,"timestamp":1922137,"transseqnumber":0,"len":4,"data":{"type":"Buffer","data":[24,21,13,1]}} +24ms
zigbee-herdsman:unpi:parser --- parseNext [] +7ms
zigbee2mqtt:debug 2/1/2020, 12:19:18 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":1794,"transid":22,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,22,12,0,0,240]}} +85ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,2,7,22,48,30,6,0,22,12,0,0,240,53] +85ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +31ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +0ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +85ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,22,208] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,22,208] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 208 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":22} +67ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,39,68,129,0,0,2,7,172,125,1,1,0,89,0,109,85,29,0,0,19,24,22,13,1,0,0,37,0,2,24,0,3,48,3,3,24,6,3,24,172,125,29,158] +15ms
zigbee-herdsman:unpi:parser --- parseNext [254,39,68,129,0,0,2,7,172,125,1,1,0,89,0,109,85,29,0,0,19,24,22,13,1,0,0,37,0,2,24,0,3,48,3,3,24,6,3,24,172,125,29,158] +1ms
%0�}] - 158 +1msn:unpi:parser --> parsed 39 - 2 - 4 - 129 - [�}YmU
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":1794,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":89,"securityuse":0,"timestamp":1922413,"transseqnumber":0,"len":19,"data":{"type":"Buffer","data":[24,22,13,1,0,0,37,0,2,24,0,3,48,3,3,24,6,3,24]}} +20ms
zigbee-herdsman:unpi:parser --- parseNext [] +21ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":1794,"transid":23,"options":48,"radius":30,"len":13,"data":{"type":"Buffer","data":[0,23,0,0,0,0,2,0,3,3,3,6,3]}} +86ms
zigbee-herdsman:unpi:writer --> frame [254,23,36,1,172,125,1,1,2,7,23,48,30,13,0,23,0,0,0,0,2,0,3,3,3,6,3,193] +87ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +19ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +88ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,23,209] +17ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,23,209] +1ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 209 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":23} +60ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,53,68,129,0,0,2,7,172,125,1,1,0,86,0,99,86,29,0,0,33,24,23,1,0,0,0,37,0,0,0,0,0,0,0,2,0,24,0,0,3,0,48,0,3,3,0,24,42,6,3,0,24,0,172,125,29,154] +16ms
zigbee-herdsman:unpi:parser --- parseNext [254,53,68,129,0,0,2,7,172,125,1,1,0,86,0,99,86,29,0,0,33,24,23,1,0,0,0,37,0,0,0,0,0,0,0,2,0,24,0,0,3,0,48,0,3,3,0,24,42,6,3,0,24,0,172,125,29,154] +1ms
zigbee-herdsman:unpi:parser --> parsed 53 - 2 - 4 - 129 - [�}VcV!%0*�}] - 154 +2ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":1794,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":86,"securityuse":0,"timestamp":1922659,"transseqnumber":0,"len":33,"data":{"type":"Buffer","data":[24,23,1,0,0,0,37,0,0,0,0,0,0,0,2,0,24,0,0,3,0,48,0,3,3,0,24,42,6,3,0,24,0]}} +21ms
zigbee-herdsman:unpi:parser --- parseNext [] +30ms
zigbee2mqtt:debug 2/1/2020, 12:19:19 AM Received zigbee message of type 'readRsp' with data '{"cid":"seMetering","data":{"currentSummDelivered":[0,0],"status":0,"unitOfMeasure":0,"summaFormatting":42,"meteringDeviceType":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:debug 2/1/2020, 12:19:19 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":2820,"transid":24,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,24,12,0,0,240]}} +125ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,1,1,4,11,24,48,30,6,0,24,12,0,0,240,63] +124ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +52ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +124ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,24,222] +25ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,24,222] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 222 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":24} +111ms
zigbee-herdsman:unpi:parser --- parseNext [] +2ms
zigbee-herdsman:unpi:parser <-- [254,36,68,129,0,0,4,11,172,125,1,1,0,94,0,11,88,29,0,0,16,24,24,13,1,0,0,27,5,5,33,8,5,33,11,5,41,172,125,29,206] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,36,68,129,0,0,4,11,172,125,1,1,0,94,0,11,88,29,0,0,16,24,24,13,1,0,0,27,5,5,33,8,5,33,11,5,41,172,125,29,206] +1ms
zigbee-herdsman:unpi:parser --> parsed 36 - 2 - 4 - 129 - [
�}^
X ▒▒}] - 206 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":2820,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":94,"securityuse":0,"timestamp":1923083,"transseqnumber":0,"len":16,"data":{"type":"Buffer","data":[24,24,13,1,0,0,27,5,5,33,8,5,33,11,5,41]}} +22ms
PuTTYPuTTYPuTTYPuTTY zigbee-herdsman:unpi:parser --- parseNext [] +28ms
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":2820,"transid":25,"options":48,"radius":30,"len":11,"data":{"type":"Buffer","data":[0,25,0,0,0,5,5,8,5,11,5]}} +97ms
zigbee-herdsman:unpi:writer --> frame [254,21,36,1,172,125,1,1,4,11,25,48,30,11,0,25,0,0,0,5,5,8,5,11,5,200] +97ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +18ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +96ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,25,223] +24ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,25,223] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 223 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":25} +73ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,49,68,129,0,0,4,11,172,125,1,1,0,102,0,36,89,29,0,0,29,24,25,1,0,0,0,27,0,0,0,0,5,5,0,33,0,0,8,5,0,33,0,0,11,5,0,41,0,0,172,125,29,204] +14ms
zigbee-herdsman:unpi:parser --- parseNext [254,49,68,129,0,0,4,11,172,125,1,1,0,102,0,36,89,29,0,0,29,24,25,1,0,0,0,27,0,0,0,0,5,5,0,33,0,0,8,5,0,33,0,0,11,5,0,41,0,0,172,125,29,204] +1ms
zigbee-herdsman:unpi:parser --> parsed 49 - 2 - 4 - 129 - [
�}f$Y
▒▒}] - 204 +1ms
zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":2820,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":102,"securityuse":0,"timestamp":1923364,"transseqnumber":0,"len":29,"data":{"type":"Buffer","data":[24,25,1,0,0,0,27,0,0,0,0,5,5,0,33,0,0,8,5,0,33,0,0,11,5,0,41,0,0]}} +17ms
zigbee-herdsman:unpi:parser --- parseNext [] +25ms
PuTTYPuTTYPuTTYPuTTY zigbee2mqtt:debug 2/1/2020, 12:19:19 AM Received zigbee message of type 'readRsp' with data '{"cid":"haElectricalMeasurement","data":{"measurementType":0,"rmsVoltage":0,"rmsCurrent":0,"activePower":0}}' of device 'SP 120' (0x00158d000388f73e) of endpoint 1
zigbee2mqtt:info 2/1/2020, 12:19:19 AM MQTT publish: topic 'zigbee2mqtt/0x00158d000388f73e', payload '{"state":"OFF","linkquality":102,"power":0,"current":0,"voltage":0}'
zigbee2mqtt:debug 2/1/2020, 12:19:19 AM Received zigbee message of type 'devInterview' with data '"0x00158d000388f73e"'
zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":2,"srcendpoint":1,"clusterid":4096,"transid":26,"options":48,"radius":30,"len":6,"data":{"type":"Buffer","data":[0,26,12,0,0,240]}} +128ms
zigbee-herdsman:unpi:writer --> frame [254,16,36,1,172,125,2,1,0,16,26,48,30,6,0,26,12,0,0,240,35] +128ms
zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +60ms
zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms
zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +129ms
zigbee-herdsman:unpi:parser --- parseNext [] +1ms
zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,26,220] +23ms
zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,26,220] +0ms
zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 220 +1ms
zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"stat`

[turboproc]

@Koenkk

Made a first comparison between V1.6.0 and V1.9.0. May be these snippets provide a hint already:

In v.1.6.0 the following happens:
zigbee-herdsman:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":32172,"status":0,"nwkaddr":32172,"len":32,"endpoint":1,"profileid":49246,"deviceid":16,"deviceversion":2,"numinclusters":9,"inclusterlist":[0,4,3,6,8,5,2820,1794,10],"numoutclusters":3,"outclusterlist":[3,25,10]} +51ms zigbee-herdsman:unpi:parser --- parseNext [] +3ms zigbee-herdsman:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":32172,"nwkaddrofinterest":32172,"endpoint":2} +51ms zigbee-herdsman:unpi:writer --> frame [254,5,37,4,172,125,172,125,2,38] +52ms zigbee-herdsman:unpi:parser <-- [254,1,101,4,0,96] +16ms zigbee-herdsman:unpi:parser --- parseNext [254,1,101,4,0,96] +1ms zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 5 - 4 - [] - 96 +1ms zigbee-herdsman:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +52ms zigbee-herdsman:unpi:parser --- parseNext [] +1ms zigbee-herdsman:unpi:parser <-- [254,16,69,132,172,125,0,172,125,10,2,94,192,0,16,2,1,0,16,0,68] +27ms zigbee-herdsman:unpi:parser --- parseNext [254,16,69,132,172,125,0,172,125,10,2,94,192,0,16,2,1,0,16,0,68] +2ms zigbee-herdsman:unpi:parser --> parsed 16 - 2 - 5 - 132 - [�}�} zigbee-herdsman:unpi:parser ^�] - 68 +0ms zigbee-herdsman:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":32172,"status":0,"nwkaddr":32172,"len":10,"endpoint":2,"profileid":49246,"deviceid":4096,"deviceversion":2,"numinclusters":1,"inclusterlist":[4096],"numoutclusters":0,"outclusterlist":[]} +51ms zigbee-herdsman:unpi:parser --- parseNext [] +2ms PuTTY zigbee-herdsman:znp:SREQ --> AF - dataRequest - {"dstaddr":32172,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":3,"options":48,"radius":30,"len":9,"data":{"type":"Buffer","data":[0,3,0,4,0,5,0,7,0]}} +78ms zigbee-herdsman:unpi:writer --> frame [254,19,36,1,172,125,1,1,0,0,3,48,30,9,0,3,0,4,0,5,0,7,0,198] +78ms zigbee-herdsman:unpi:parser <-- [254,1,100,1,0,100] +45ms zigbee-herdsman:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms zigbee-herdsman:unpi:parser --> parsed 1 - 3 - 4 - 1 - [] - 100 +1ms zigbee-herdsman:znp:SRSP <-- AF - dataRequest - {"status":0} +79ms zigbee-herdsman:unpi:parser --- parseNext [] +2ms zigbee-herdsman:unpi:parser <-- [254,3,68,128,0,1,3,197] +18ms zigbee-herdsman:unpi:parser --- parseNext [254,3,68,128,0,1,3,197] +1ms zigbee-herdsman:unpi:parser --> parsed 3 - 2 - 4 - 128 - [] - 197 +1ms zigbee-herdsman:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":3} +69ms zigbee-herdsman:unpi:parser --- parseNext [] +1ms zigbee-herdsman:unpi:parser <-- [254,48,68,129,0,0,0,0,172,125,1,1,0,55,0,29,63,29,0,0,28,24,3,1,4,0,0,66,4,105,110,110,114,5,0,0,66,6,83,80,32,49,50,48,7,0,0,48,1,172,125,29,216] +18ms zigbee-herdsman:unpi:parser --- parseNext [254,48,68,129,0,0,0,0,172,125,1,1,0,55,0,29,63,29,0,0,28,24,3,1,4,0,0,66,4,105,110,110,114,5,0,0,66,6,83,80,32,49,50,48,7,0,0,48,1,172,125,29,216] +2ms zigbee-herdsman:unpi:parser --> parsed 48 - 2 - 4 - 129 - [�}7?BinnrBSP 1200�}] - 216 +0ms zigbee-herdsman:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":32172,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":55,"securityuse":0,"timestamp":1916701,"transseqnumber":0,"len":28,"data":{"type":"Buffer","data":[24,3,1,4,0,0,66,4,105,110,110,114,5,0,0,66,6,83,80,32,49,50,48,7,0,0,48,1]}} +23ms
Where as in v.1.9.0 the following occurs:
zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":25003,"status":0,"nwkaddr":25003,"len":32,"endpoint":1,"profileid":49246,"deviceid":16,"deviceversion":2,"numinclusters":9,"inclusterlist":[0,4,3,6,8,5,2820,1794,10],"numoutclusters":3,"outclusterlist":[3,25,10]} +89ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +3ms zigbee-herdsman:controller:device Interview - got simple descriptor for endpoint '1' device '0x00158d000388f73e' +78ms zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - simpleDescReq - {"dstaddr":25003,"nwkaddrofinterest":25003,"endpoint":2} +102ms zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,37,4,171,97,171,97,2,38] +102ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,4,0,96] +57ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,4,0,96] +1ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 4 - [0] - 96 +1ms zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - simpleDescReq - {"status":0} +112ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +2ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,16,69,132,171,97,0,171,97,10,2,94,192,0,16,2,1,0,16,0,68] +19ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,16,69,132,171,97,0,171,97,10,2,94,192,0,16,2,1,0,16,0,68] +2ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 16 - 2 - 5 - 132 - [171,97,0,171,97,10,2,94,192,0,16,2,1,0,16,0] - 68 +2ms zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - simpleDescRsp - {"srcaddr":25003,"status":0,"nwkaddr":25003,"len":10,"endpoint":2,"profileid":49246,"deviceid":4096,"deviceversion":2,"numinclusters":1,"inclusterlist":[4096],"numoutclusters":0,"outclusterlist":[]} +88ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +5ms zigbee-herdsman:controller:device Interview - got simple descriptor for endpoint '2' device '0x00158d000388f73e' +90ms zigbee-herdsman:adapter:zStack:znp:SREQ --> AF - dataRequest - {"dstaddr":25003,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":13,"options":0,"radius":30,"len":9,"data":{"type":"Buffer","data":[16,14,0,5,0,4,0,7,0]}} +92ms zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,19,36,1,171,97,1,1,0,0,13,0,30,9,16,14,0,5,0,4,0,7,0,254] +93ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,100,1,0,100] +50ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,100,1,0,100] +2ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 4 - 1 - [0] - 100 +2ms zigbee-herdsman:adapter:zStack:znp:SRSP <-- AF - dataRequest - {"status":0} +85ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +4ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,68,128,0,1,13,203] +3ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,68,128,0,1,13,203] +2ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 4 - 128 - [0,1,13] - 203 +1ms zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":13} +67ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +3ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,48,68,129,0,0,0,0,171,97,1,1,0,26,0,240,184,104,0,0,28,24,14,1,5,0,0,66,6,83,80,32,49,50,48,4,0,0,66,4,105,110,110,114,7,0,0,48,1,171,97,29,231] +18ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,48,68,129,0,0,0,0,171,97,1,1,0,26,0,240,184,104,0,0,28,24,14,1,5,0,0,66,6,83,80,32,49,50,48,4,0,0,66,4,105,110,110,114,7,0,0,48,1,171,97,29,231] +2ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 48 - 2 - 4 - 129 - [0,0,0,0,171,97,1,1,0,26,0,240,184,104,0,0,28,24,14,1,5,0,0,66,6,83,80,32,49,50,48,4,0,0,66,4,105,110,110,114,7,0,0,48,1,171,97,29] - 231 +2ms zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":25003,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":26,"securityuse":0,"timestamp":6863088,"transseqnumber":0,"len":28,"data":{"type":"Buffer","data":[24,14,1,5,0,0,66,6,83,80,32,49,50,48,4,0,0,66,4,105,110,110,114,7,0,0,48,1]}} +26ms zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true},"transactionSequenceNumber":14,"manufacturerCode":null,"commandIdentifier":1},"Payload":[{"attrId":5,"status":0,"dataType":66,"attrData":"SP 120"},{"attrId":4,"status":0,"dataType":66,"attrData":"innr"},{"attrId":7,"status":0,"dataType":48,"attrData":1}],"Cluster":{"ID":0,"attributes":{"zclVersion":{"ID":0,"type":32,"name":"zclVersion"},"appVersion":{"ID":1,"type":32,"name":"appVersion"},"stackVersion":{"ID":2,"type":32,"name":"stackVersion"},"hwVersion":{"ID":3,"type":32,"name":"hwVersion"},"manufacturerName":{"ID":4,"type":66,"name":"manufacturerName"},"modelId":{"ID":5,"type":66,"name":"modelId"},"dateCode":{"ID":6,"type":66,"name":"dateCode"},"powerSource":{"ID":7,"type":48,"name":"powerSource"},"appProfileVersion":{"ID":8,"type":48,"name":"appProfileVersion"},"swBuildId":{"ID":16384,"type":66,"name":"swBuildId"},"locationDesc":{"ID":16,"type":66,"name":"locationDesc"},"physicalEnv":{"ID":17,"type":48,"name":"physicalEnv"},"deviceEnabled":{"ID":18,"type":16,"name":"deviceEnabled"},"alarmMask":{"ID":19,"type":24,"name":"alarmMask"},"disableLocalConfig":{"ID":20,"type":24,"name":"disableLocalConfig"}},"name":"genBasic","commands":{"resetFactDefault":{"ID":0,"parameters":[],"name":"resetFactDefault"}},"commandsResponse":{}}},"address":25003,"endpoint":1,"linkquality":26,"groupID":0}' +3s zigbee2mqtt:debug 2020-02-01 10:31:41: Received Zigbee message from '0x00158d000388f73e', type 'readResponse', cluster 'genBasic', data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}' from endpoint 1 with groupID 0 zigbee2mqtt:debug 2020-02-01 10:31:41: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"modelId":"SP 120","manufacturerName":"innr","powerSource":1}'

So both version find the same endpoints and within these endpoints they find the same clusters. In the next step where cluster 0 of endpoint 1 is being queried, the difference starts as v.1.6.0 queries for
"data":{"type":"Buffer","data":[0,3,0,4,0,5,0,7,0]}

and v1.9.0 queries for
"data":{"type":"Buffer","data":[16,14,0,5,0,4,0,7,0]}

''

[turboproc]

@Koenkk , learning fast, when doing a deep dive it seems that V1.6.0 and v.1.9.0 have (by design some fundamental difference:
V.1.6.0: reads all endpoint and cluster within endpoints as part of the binding process
V.1.9.0: reads only on the genBasic endpoint and when done it considers Interviewing complete. As a next phase it starts the Configuration phase to get the other data. (If I'm correct).

What I notice regarding the Configuration phase, z2m sends a bindReq where it looks like srcaddr and dstaddr have been swapped (at least compared to all dataRequest that have done before). If this is not intended it would explain why z2m would never receive a response.

zigbee-herdsman:adapter:zStack:znp:SREQ --> AF - dataRequest - {"dstaddr":3259,"destendpoint":1,"srcendpoint":1,"clusterid":0,"transid":3,"options":0,"radius":30,"len":9,"data":{"type":"Buffer","data":[16,4,0,3,0,6,0,0,64]}} +82ms zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,19,36,1,187,12,1,1,0,0,3,0,30,9,16,4,0,3,0,6,0,0,64,196] +82ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,100,1,0,100] +26ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,100,1,0,100] +1ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 4 - 1 - [0] - 100 +0ms zigbee-herdsman:adapter:zStack:znp:SRSP <-- AF - dataRequest - {"status":0} +83ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,68,128,0,1,3,197] +16ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,68,128,0,1,3,197] +0ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 4 - 128 - [0,1,3] - 197 +1ms zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":3} +58ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,53,68,129,0,0,0,0,187,12,1,1,0,21,0,212,78,103,0,0,33,24,4,1,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48,30,99,28,169] +30ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,53,68,129,0,0,0,0,187,12,1,1,0,21,0,212,78,103,0,0,33,24,4,1,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48,30,99,28,169] +1ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 53 - 2 - 4 - 129 - [0,0,0,0,187,12,1,1,0,21,0,212,78,103,0,0,33,24,4,1,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48,30,99,28] - 169 +1ms zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":0,"srcaddr":3259,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":21,"securityuse":0,"timestamp":6770388,"transseqnumber":0,"len":33,"data":{"type":"Buffer","data":[24,4,1,3,0,0,32,1,6,0,0,66,12,50,48,49,55,49,48,50,55,45,49,48,48,0,64,0,66,3,50,46,48]}} +34ms zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true},"transactionSequenceNumber":4,"manufacturerCode":null,"commandIdentifier":1},"Payload":[{"attrId":3,"status":0,"dataType":32,"attrData":1},{"attrId":6,"status":0,"dataType":66,"attrData":"20171027-100"},{"attrId":16384,"status":0,"dataType":66,"attrData":"2.0"}],"Cluster":{"ID":0,"attributes":{"zclVersion":{"ID":0,"type":32,"name":"zclVersion"},"appVersion":{"ID":1,"type":32,"name":"appVersion"},"stackVersion":{"ID":2,"type":32,"name":"stackVersion"},"hwVersion":{"ID":3,"type":32,"name":"hwVersion"},"manufacturerName":{"ID":4,"type":66,"name":"manufacturerName"},"modelId":{"ID":5,"type":66,"name":"modelId"},"dateCode":{"ID":6,"type":66,"name":"dateCode"},"powerSource":{"ID":7,"type":48,"name":"powerSource"},"appProfileVersion":{"ID":8,"type":48,"name":"appProfileVersion"},"swBuildId":{"ID":16384,"type":66,"name":"swBuildId"},"locationDesc":{"ID":16,"type":66,"name":"locationDesc"},"physicalEnv":{"ID":17,"type":48,"name":"physicalEnv"},"deviceEnabled":{"ID":18,"type":16,"name":"deviceEnabled"},"alarmMask":{"ID":19,"type":24,"name":"alarmMask"},"disableLocalConfig":{"ID":20,"type":24,"name":"disableLocalConfig"}},"name":"genBasic","commands":{"resetFactDefault":{"ID":0,"parameters":[],"name":"resetFactDefault"}},"commandsResponse":{}}},"address":3259,"endpoint":1,"linkquality":21,"groupID":0}' +91ms zigbee2mqtt:debug 2020-02-01 10:31:12: Received Zigbee message from '0x00158d000388f73e', type 'readResponse', cluster 'genBasic', data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' from endpoint 1 with groupID 0 zigbee2mqtt:debug 2020-02-01 10:31:12: No converter available for 'SP 120' with cluster 'genBasic' and type 'readResponse' and data '{"hwVersion":1,"dateCode":"20171027-100","swBuildId":"2.0"}' zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +11ms zigbee-herdsman:controller:device Interview - got 'hwVersion,dateCode,swBuildId' for device '0x00158d000388f73e' +89ms zigbee-herdsman:controller:device Interview - completed for device '0x00158d000388f73e' +7ms zigbee-herdsman:controller:log Succesfully interviewed '0x00158d000388f73e' +23ms zigbee2mqtt:info 2020-02-01 10:31:12: Successfully interviewed '0x00158d000388f73e', device has successfully been paired zigbee2mqtt:info 2020-02-01 10:31:12: Device '0x00158d000388f73e' is supported, identified as: Innr Smart plug (SP 120) zigbee2mqtt:info 2020-02-01 10:31:12: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"0x00158d000388f73e","model":"SP 120","vendor":"Innr","description":"Smart plug","supported":true}}' zigbee2mqtt:info 2020-02-01 10:31:12: Configuring '0x00158d000388f73e' zigbee-herdsman:adapter:zStack:znp:SREQ --> ZDO - bindReq - {"dstaddr":3259,"srcaddr":"0x00158d000388f73e","srcendpoint":1,"clusterid":6,"dstaddrmode":3,"dstaddress":"0x00124b00193664ab","dstendpoint":1} +106ms zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,23,37,33,187,12,62,247,136,3,0,141,21,0,1,6,0,3,171,100,54,25,0,75,18,0,1,194] +106ms zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,101,33,0,69] +42ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,101,33,0,69] +1ms zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 5 - 33 - [0] - 69 +1ms zigbee-herdsman:adapter:zStack:znp:SRSP <-- ZDO - bindReq - {"status":0} +105ms zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms

[Koenkk]

@turboproc there is a very big difference between 1.6.0 and 1.7.0 + (zigbee-shepherd, partially herdsman) vs full zigbee-herdsman, basically the whole underlying zigbee library has been changed).

• Does the power reporting/configure work correctly on zigbee2mqtt 1.6.0?
• If yes, could you create a sniff log for both 1.6.0 and 1.9.0 (https://www.zigbee2mqtt.io/how_tos/how_to_sniff_zigbee_traffic.html). These sniffer logs shows exactly what is happening and we can easily compare them.

What I notice regarding the Configuration phase, z2m sends a bindReq where it looks like srcaddr and dstaddr have been swapped (at least compared to all dataRequest that have done before).

I don't think this is the issue, srcaddr should be the address you want to bind (= SP 120) and dstaddress the address you want to bind it to (= coordinator). If this would be wrong, binding shouldn't work at all in Zigbee2mqtt (for no device) but this doesn't seem to be the case.

[dersparkiie]

Same problem here since updating from 1.5.1 to 1.9.0. Repairing doesn't solve it!

[turboproc]

@Koenkk

• reporting and configure under 1.6.0 works OK, getting values that make sense
• sniffing is ofcourse an option, just need to order an addition CC2531 for this (having 1 now on 1.6.0 and one on 1.9.0)
• what I learned in the meantime is that when deleting the "await bind ...." line in devices.js int the block that defines the SP-120, the configuration process gets completed but values are still not being reported. So deletion is not the option, but change of that line is still required.

[turboproc]

@Koenkk , while waiting for additional C2531, I explored a bit futher the traces and what I see now is that V1.6.0 does not use reporting, in fact it does a Discover of attributes and then reads the attributes.
So changed now in V1.9.0 the devices.js file: removed the bind line and the configure report lines (all). When configuring the SP-120, it comes to life, reporting status, activepower, rmsvoltage and rms current. So that's more now.
When requesting a new status via MQTT, z2m reaches out to the SP-120 and provides an updated status. However, when requesting an new activepower it throws an error "no converter available". Do understand yet where to look for creating of the convertor.

[Koenkk]

@turboproc zigbee2mqtt 1.6.0 also bound it (https://github.com/Koenkk/zigbee-herdsman-converters/blob/zigbee-shepherd-converters/devices.js#L2006) and the power value was definitely not read manually.

The strange thing: I also have this device and it configures fine with the latest zigbee2mqtt dev branch. I don't understand why it doesn't work on some cases

[FutureCow]

I did some testing 2 months ago and if i remember correctly this was the outcome:

z2m 1.6.0 fresh install --> Pairing SP-120 without a problem
z2m 1.8.0 fresh install --> Pairing SP-120 without a problem
z2m 1.6.0 fresh install --> Pairing SP-120 --> Update to 1.8.0 --> without a problem
z2m update from 1.6.0 --> 1.8.0 --> Pairing SP-120, Not working correctly!

So if you already used the SP-120 in a older version of z2m, you don't have any problems. But if you update from 1.6.0 to a newer version and pair the SP-120 after it, it doesn't work correctly.
Maybe turboproc can verify this?

[turboproc]

@Koenkk , @FutureCow , done some more work on a rainy Sunday. Suddenly understood that for requesting values on demand from the SP 120 one needs a toZigbee converter t get the commands out. So quickly added a tz.SP-120 convertor that can request power, current, voltage. That works. (Not really exciting but hey, first time everything is a bit exciting.)

So the key question that remains is why reporting cannot be configured. Sunday isn;t over yet...

mosquitto_pub -t "zigbee2mqtt/0x00158d000388f73e/get" -m "{\"power\":\"\"}" -d
results in
Received Zigbee message from '0x00158d000388f73e', type 'readResponse', cluster 'haElectricalMeasurement', data '{"activePower":24}' from endpoint 1 with groupID 0
Same for the other attributes.

[turboproc]

So it seems the issue has been resolved where the solution was found in a completely different area. By coincidence I discovered that the MAC address of the coordinator as mentioned in the database was not equal to the real MAC address. This was problably caused by switching my 2 C2531 dongles once in a while. As a consequence the BindReq commands reffered to a non active destination rather than the active coordinator. Logically all bind requests would fail.

Once I'd changed the entry in the database file and restarted z2m everything started to work.

So what might be helpful is that the startup code of z2m compares the MAC address of the dongle with the MAC captured in the database and if not equal, either stops or updates the database. @Koenkk ?

[Koenkk]

@turboproc lol, well found! I will implement it.

[Koenkk]

Implemented, thank you very much @turboproc for finding this bug!

I assume this issue can be closed now.

[turboproc]

Hi @Koenkk .

Sure, thnx for fixing. Issue can be closed