Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

QBKG04LM: Z2M registers state changes when physically pressing the button, but cannot send MQTT msgs to it. #593

Closed
HKC001 opened this issue Nov 14, 2018 · 13 comments

Comments

@HKC001
Copy link

HKC001 commented Nov 14, 2018

I have 2x QBKG04LM located right beside a few QBKG03LM. The QBKG03LM works perfectly, so I know its not a signal strength issue. When I physically toggle the QBKG04LMs, the state change is registered on HA. But when I try to send it on/off commands, it doesn't respond, and this also causes the whole network to lag. Devices that normally respond instantly will pause for about 10 seconds immediately after the command is sent to the QBKG03LM, then returns to working normally.

Are there any settings in the firmware and / or zigbee2mqtt I can try tweaking?

@Koenkk
Copy link
Owner

Koenkk commented Nov 14, 2018

Can you provide your log?

@HKC001
Copy link
Author

HKC001 commented Nov 16, 2018

Switch 1: When sending on command via Hass.IO:

Received MQTT message on 'zig/mhall_swds_1/set' with data 'ON'
Zigbee publish to '0x00158d00029b45fe', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null

Switch 1: When physically turning on the switch:

Received MQTT message on 'zig/mhall_swds_1/set' with data 'ON'
Zigbee publish to '0x00158d00029b45fe', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"61440":60740352,"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
MQTT publish, topic: 'zig/mhall_swds_1', payload: '{"state":"ON","linkquality":13}'
Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"61440":60740352,"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)

Switch 2: When sending on command via Hass.IO:

Received MQTT message on 'zig/balc_swds_1/set' with data 'ON'
Zigbee publish to '0x00158d00029b4632', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null

Switch 2: When physically turning on the switch:

Received zigbee message of type 'attReport' with data '{"cid":"genBasic","data":{"65281":{"1":3300,"3":37,"5":77,"8":9750,"10":0,"100":0,"101":0,"110":0,"111":0,"153":0,"155":0}}}' of device 'lumi.ctrl_neutral2' (0x00158d0002a35d1e)
Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"61440":60740352,"onOff":0}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
MQTT publish, topic: 'zig/mhall_swds_1', payload: '{"state":"OFF","linkquality":39}'
Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)

@Koenkk
Copy link
Owner

Koenkk commented Nov 16, 2018

Could you provide a bit more logging after sending the command?

@HKC001
Copy link
Author

HKC001 commented Nov 17, 2018

Tested using new install of edge version 0.2.0 (commit #efc11fa) + reflashed your optimised firmware. Starting with only 1 device on the network.

I guess issue might be one of these reasons:

  1. These are new QBKG04LM, shipped out from China on Nov 11, manufactured 2018 Oct. New firmware...?
  2. Related to kirovilya's comment about "problems with the operation of some devices that will not disappear with the change of the coordinator chip." My zigbee2mqtt entities are mostly still appearing in Hass.io even after reflashing, deleting the zigbee2mqtt folder and restarting Hass.io.

Test log is from when restarting zigbee2mqtt to a few minutes after sending the command:

zigbee2mqtt:debug 2018-11-17 07:52:10 Received zigbee message of type 'attReport' with data '{"cid":"genBasic","data":{"65281":{"1":3300,"3":31,"5":26,"8":9750,"10":0,"100":0,"101":0,"110":0,"111":255,"153":0,"155":0}}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
  zigbee2mqtt:debug 2018-11-17 07:52:10 Received zigbee message of type 'devChange' with data '{"cid":"genBasic","data":{"65281":[null,3300,null,31,null,26,null,null,9750,null,0,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,0,0,null,null,null,null,null,null,null,null,0,255,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,0,null,0]}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b45fe)
  zigbee2mqtt:debug 2018-11-17 07:52:24 Check online mhall_swds_1 0x00158d00029b45fe
  zigbee2mqtt:debug 2018-11-17 07:52:51 Received MQTT message on 'hass/status' with data 'online'
  zigbee2mqtt:debug 2018-11-17 07:53:24 Check online mhall_swds_1 0x00158d00029b45fe
  zigbee2mqtt:debug 2018-11-17 07:53:55 Received MQTT message on 'zig/mhall_swds_1/set' with data 'ON'
  zigbee2mqtt:info 2018-11-17 07:53:55 Zigbee publish to '0x00158d00029b45fe', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:debug 2018-11-17 07:54:24 Check online mhall_swds_1 0x00158d00029b45fe
  zigbee2mqtt:error 2018-11-17 07:54:25 Zigbee publish to '0x00158d00029b45fe', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: Timed out after 30000 ms
  zigbee2mqtt:debug 2018-11-17 07:55:24 Check online mhall_swds_1 0x00158d00029b45fe
  zigbee2mqtt:debug 2018-11-17 07:56:22 Saving state to file /share/zigbee2mqtt/state.json
  zigbee2mqtt:debug 2018-11-17 07:56:24 Check online mhall_swds_1 0x00158d00029b45fe
  zigbee2mqtt:debug 2018-11-17 07:57:24 Check online mhall_swds_1 0x00158d00029b45fe

In case its a network signal error, I added another QBKG04LM after the test above. Results:

  zigbee2mqtt:info 2018-11-17 08:58:53 Zigbee publish to '0x00158d00029b4632', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:error 2018-11-17 08:59:23 Zigbee publish to '0x00158d00029b4632', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: Timed out after 30000 ms
  zigbee2mqtt:debug 2018-11-17 08:59:39 Check online mhall_swds_1 0x00158d00029b45fe
  zigbee2mqtt:debug 2018-11-17 08:59:39 Check online balc_swds_1 0x00158d00029b4632

Network map:

digraph G {
node[shape=record];
  "0x00124b00076622b8" [label="{0x00124b00076622b8|Coordinator|No model information available|online}"];
  "0x00124b00076622b8" -> "0x00158d00029b4632" [label="160"]
  "0x00158d00029b45fe" [label="{mhall_swds_1|Router|Xiaomi Aqara single key wired wall switch (QBKG04LM)|online}"];
  "0x00158d00029b45fe" -> "0x00124b00076622b8" [label="88"]
  "0x00158d00029b4632" [label="{balc_swds_1|Router|Xiaomi Aqara single key wired wall switch (QBKG04LM)|online}"];
  "0x00158d00029b4632" -> "0x00124b00076622b8" [label="122"]
}

@HKC001
Copy link
Author

HKC001 commented Nov 17, 2018

Ok, more in depth testing. I deleted MosquittoMQTT to completely remove the device entity from Hass.io. After restarting everything, repaired the device which has better signal link to the coordinator. Here is the result:

  zigbee2mqtt:info 2018-11-17 09:42:44 Connected to MQTT server
  zigbee2mqtt:info 2018-11-17 09:42:44 MQTT publish: topic 'zig/bridge/state', payload 'online'
  zigbee2mqtt:info 2018-11-17 09:42:44 MQTT publish: topic 'homeassistant/switch/0x00158d00029b4632/switch/config', payload '{"payload_off":"OFF","payload_on":"ON","value_template":"{{ value_json.state }}","command_topic":"zig/balc_swds_1/set","state_topic":"zig/balc_swds_1","availability_topic":"zig/bridge/state","name":"balc_swds_1"}'
  zigbee2mqtt:debug 2018-11-17 09:42:55 Received MQTT message on 'zig/balc_swds_1/set' with data 'ON'
  zigbee2mqtt:info 2018-11-17 09:42:55 Zigbee publish to '0x00158d00029b4632', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:error 2018-11-17 09:43:25 Zigbee publish to '0x00158d00029b4632', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: Timed out after 30000 ms
  zigbee2mqtt:debug 2018-11-17 09:43:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:44:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:45:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:46:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:error 2018-11-17 09:46:57 Cannot get the Node Descriptor of the Device: 0x00158d00029b45fe (Error: Timed out after 10000 ms)
  zigbee2mqtt:debug 2018-11-17 09:47:28 Received zigbee message of type 'attReport' with data '{"cid":"genBasic","data":{"65281":{"1":3300,"3":26,"5":20,"8":9750,"10":0,"100":0,"101":0,"110":0,"111":255,"153":0,"155":0}}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:debug 2018-11-17 09:47:42 Saving state to file /share/zigbee2mqtt/state.json
  zigbee2mqtt:debug 2018-11-17 09:47:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:48:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:49:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:50:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:51:44 Check online balc_swds_1 0x00158d00029b4632

After the above, I physically turned on/off the switch, and saw the state change in Hass.io. Log:

  zigbee2mqtt:error 2018-11-17 09:52:44 Cannot get the Node Descriptor of the Device: 0x00158d00029b45fe (Error: Timed out after 10000 ms)
  zigbee2mqtt:debug 2018-11-17 09:52:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:53:19 Received zigbee message of type 'attReport' with data '{"cid":"genBasic","data":{"65281":{"1":3300,"3":26,"5":20,"8":9750,"10":0,"100":0,"101":0,"110":0,"111":255,"153":0,"155":0}}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:debug 2018-11-17 09:53:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:54:44 Check online balc_swds_1 0x00158d00029b4632
  zigbee2mqtt:debug 2018-11-17 09:54:55 Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"61440":53477376,"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:info 2018-11-17 09:54:55 MQTT publish: topic 'zig/balc_swds_1', payload '{"state":"ON","linkquality":101}'
  zigbee2mqtt:debug 2018-11-17 09:54:55 Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"61440":53477376,"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:debug 2018-11-17 09:54:55 Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:debug 2018-11-17 09:54:55 Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:debug 2018-11-17 09:55:08 Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"61440":53477376,"onOff":0}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:info 2018-11-17 09:55:08 MQTT publish: topic 'zig/balc_swds_1', payload '{"state":"OFF","linkquality":78}'
  zigbee2mqtt:debug 2018-11-17 09:55:08 Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)
  zigbee2mqtt:debug 2018-11-17 09:55:08 Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'lumi.ctrl_neutral1' (0x00158d00029b4632)

@HKC001
Copy link
Author

HKC001 commented Nov 17, 2018

More guys with same issues here.

@paskyecijano
Copy link

I have the same problem!!

@jasimancas
Copy link

Me too!

@Koenkk
Copy link
Owner

Koenkk commented Nov 19, 2018

Does this error also happen in 0.2.0 (not the dev version)?

@Koenkk
Copy link
Owner

Koenkk commented Nov 19, 2018

Nvm already know what the issue is. Will post a fix this evening.

For those who want to test, change: https://github.com/Koenkk/zigbee2mqtt/blob/master/lib/extension/devicePublish.js#L55 to

let postfix = '';

@poki123
Copy link

poki123 commented Nov 19, 2018

Hello Koenkk, I tried this change and it is working, thank you 👍

@jasimancas
Copy link

Waiting to fix in docker DEV version.

Koenkk added a commit that referenced this issue Nov 19, 2018
@Koenkk
Copy link
Owner

Koenkk commented Nov 19, 2018

Fixed in dev branch.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants