search

dresden-elektronik / deconz-rest-plugin

deCONZ REST-API plugin to control ZigBee devices
BSD 3-Clause "New" or "Revised" License
1.9k stars 505 forks source link

Websockets for Aqara Sensors not working after reboot (alternate) #637

Closed terafin closed 5 years ago

terafin commented 6 years ago

Hi there. Every reboot of my Raspberry Pi 3B+ I lose all all web socket messages coming from them.

This is with SW version: 2.05.25 Firmware: 261F0500

Here are the startup logs, couple with me tapping the button on the devices once to check them in a 30 seconds after or so.

[marthoc/deconz] Current deCONZ version: 2.05.25 [marthoc/deconz] Web UI port: 80 [marthoc/deconz] Websockets port: 443 libpng warning: iCCP: known incorrect sRGB profile This plugin does not support propagateSizeHints() This plugin does not support propagateSizeHints() This plugin does not support propagateSizeHints() 17:11:30:906 HTTP Server listen on address 0.0.0.0, port: 80, root: /usr/share/deCONZ/webapp/ 17:11:31:132 dev /dev/ttyAMA0 17:11:31:132 ZCLDB init file /root/.local/share/dresden-elektronik/deCONZ/zcldb.txt 17:11:31:317 parent process /bin/sh 17:11:31:317 gw run mode: normal 17:11:31:317 sd-card cid: 1b534d454231515430ffffffff0114a1 17:11:31:339 don't close database yet, keep open for 900 seconds 10:11:31:340 Daylight now: goldenHour1, status: 160 10:11:31:342 started websocket server at port 443 10:11:31:344 discovery updated announce interval to 10 minutes 10:11:31:347 found node plugin: libde_rest_plugin.so - REST API Plugin 10:11:31:350 found node plugin: libde_signal_plugin.so - Signal Monitor Plugin 10:11:31:368 found node plugin: libstd_otau_plugin.so - STD OTAU Plugin 10:11:31:406 dev /dev/ttyAMA0 10:11:31:446 discard sensor state push for state/status (already pushed) 10:11:31:454 discard sensor state push for state/status (already pushed) 10:11:31:558 Device firmware version 0x261F0500 10:11:31:570 unlocked max nodes: 200 10:11:31:765 Device protocol version: 0x0106 10:11:31:778 CTRL restore cached node 0x00212effff0229cd 10:11:31:779 new node - ext: 0x00212effff0229cd, nwk: 0x0000 10:11:31:904 Current channel 15 10:11:31:947 CTRL ANT_CTRL 0x03 10:11:32:052 Device protocol version: 0x0106 10:11:32:191 Current channel 15 10:11:32:235 CTRL ANT_CTRL 0x03 10:11:32:459 neigbor 0x00158d00022c644b is unknown child 10:11:33:456 neigbor 0x00158d0002019bfc is unknown child 10:11:33:811 New websocket 10.0.90.243:45128 (state: 3) 10:11:33:849 CTRL restore cached node 0x00158d00022c644b 10:11:33:852 new node - ext: 0x00158d00022c644b, nwk: 0xDA95 10:11:33:852 SensorNode 4 set node 0x00158d00022c644b 10:11:33:853 SensorNode 5 set node 0x00158d00022c644b 10:11:33:853 SensorNode 6 set node 0x00158d00022c644b 10:11:33:858 discard sensor config push for config/reachable (already pushed) 10:11:33:859 discard sensor config push for config/reachable (already pushed) 10:11:33:860 discard sensor config push for config/reachable (already pushed) 10:11:34:329 CTRL restore cached node 0x00158d0002019bfc 10:11:34:331 new node - ext: 0x00158d0002019bfc, nwk: 0xC89C 10:11:34:331 SensorNode 3 set node 0x00158d0002019bfc 10:11:34:336 discard sensor config push for config/reachable (already pushed) 10:11:36:582 dev /dev/ttyAMA0 10:11:36:584 GW update firmware found: /usr/share/deCONZ/firmware/deCONZ_Rpi_0x261f0500.bin.GCF 10:11:36:584 GW firmware version: 0x261f0500 10:11:36:584 GW firmware version is up to date: 0x261f0500 10:11:36:718 Announced to internet 10:11:36:718 discovery server date: Sun, 10 Jun 2018 17:11:36 GMT 10:11:36:718 local time seems to be ok 10:11:36:718 discovery found version 2.04.35 for update channel stable 10:11:39:939 New websocket 10.0.1.132:51517 (state: 3) 10:11:41:501 Daylight now: goldenHour1, status: 160 10:11:42:790 New websocket 10.0.90.243:55278 (state: 3) 10:11:47:232 no button map for: lumi.sensor_magnet.aq2 cl: 0x0000 cmd: 0x0A pl[0]: 005 10:11:47:232 ZCL attribute report 0x00158D0002019BFC for cluster 0x0000, ep 0x01 10:11:47:232 0x00158D0002019BFC skip Xiaomi attribute 0x0005 10:11:47:232 0x00158D0002019BFC extract Xiaomi special 10:11:47:232 01 battery 3055 (0x0BEF) 10:11:47:232 03 temperature 19 °C 10:11:47:232 04 unknown 5032 (0x13A8) 10:11:47:232 05 unknown 83 (0x0053) 10:11:47:232 06 unknown 279172874753 (0x0000004100000201) 10:11:47:232 64 on/off 0 10:11:47:235 discard sensor config push for config/battery (already pushed) 10:11:47:236 discard sensor config push for config/temperature (already pushed) 10:11:47:237 discard sensor state push for state/open (already pushed) 10:11:51:501 Daylight now: goldenHour1, status: 160 10:11:53:903 scan skip host .210 10:11:54:822 no button map for: lumi.weather cl: 0x0000 cmd: 0x0A pl[0]: 001 10:11:54:822 ZCL attribute report 0x00158D00022C644B for cluster 0x0000, ep 0x01 10:11:54:823 0x00158D00022C644B extract Xiaomi special 10:11:54:823 01 battery 3015 (0x0BC7) 10:11:54:823 04 unknown 5032 (0x13A8) 10:11:54:823 05 unknown 6 (0x0006)

It's worth noting that the WebUI does update but about 1-2 seconds slower than usual - however I never get any web socket updates.

terafin commented 6 years ago

I did just notice this oddity in the zll.db

sqlite> select * from sensors; sid = 2 name = Window / Door Sensor type = ZHAOpenClose modelid = lumi.sensor_magnet.aq2 manufacturername = LUMI uniqueid = 00:15:8d:00:02:01:9b:fc-01-0006 swversion = state = {"lastupdated":"2018-06-03T22:06:44","open":false} config = {"battery":100,"on":true,"reachable":true,"temperature":2300} fingerprint = {"d":65535,"ep":1,"in":[6],"p":260} deletedState = deleted mode = 1

         sid = 3
        name = Window / Door Sensor
        type = ZHAOpenClose
     modelid = lumi.sensor_magnet.aq2

manufacturername = LUMI uniqueid = 00:15:8d:00:02:01:9b:fc-01-0006 swversion = state = {"lastupdated":"2018-06-10T06:39:03","open":true} config = {"battery":100,"on":true,"reachable":true,"temperature":2400} fingerprint = {"d":65535,"ep":1,"in":[6],"p":260} deletedState = normal mode = 1

Two entries for this sensor, same unique ID - but one is deleted?

terafin commented 6 years ago

Tried on a clean install. Added one sensor. Worked until reboot, then same as above.

terafin commented 6 years ago

Keen vents work fine (unresponsive for maybe 5 minutes post reboot - but do recover).

terafin commented 6 years ago

Updated to the latest version, which I saw had some logging and flushing. New logs here which cover.

Pairing, verifying working, restarting docker (same result with the .deb fwiw), and logging

20:51:09:140 SensorNode 6: OpenClose 6 added 20:51:09:145 Websocket 10.0.1.132:49977 send message: {"e":"added","id":"6","r":"sensors","sensor":{"config":{"battery":null,"on":true,"reachable":true,"temperature":null},"ep":1,"etag":"dc5fea78cf284ff7d316e6080d0ff7a5","id":"6","manufacturername":"LUMI","modelid":"lumi.sensor_magnet.aq2","name":"OpenClose 6","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"type":"ZHAOpenClose","uniqueid":"00:15:8d:00:02:01:9b:fc-01-0006"},"t":"event"} (ret = 396) 20:51:09:145 Websocket 10.0.1.132:49992 send message: {"e":"added","id":"6","r":"sensors","sensor":{"config":{"battery":null,"on":true,"reachable":true,"temperature":null},"ep":1,"etag":"dc5fea78cf284ff7d316e6080d0ff7a5","id":"6","manufacturername":"LUMI","modelid":"lumi.sensor_magnet.aq2","name":"OpenClose 6","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"type":"ZHAOpenClose","uniqueid":"00:15:8d:00:02:01:9b:fc-01-0006"},"t":"event"} (ret = 396) 20:51:09:149 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"t":"event"} (ret = 108) 20:51:09:149 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"t":"event"} (ret = 108) 20:51:09:151 discard sensor state push for 6: state/lastupdated (already pushed) 20:51:09:312 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:51:09:312 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:51:09:314 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":false},"t":"event"} (ret = 109) 20:51:09:314 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":false},"t":"event"} (ret = 109) 20:51:09:315 discard sensor state push for 6: state/lastupdated (already pushed) 20:51:09:336 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"3","name":"Multi Sensor (2)","r":"sensors","t":"event"} (ret = 76) 20:51:09:337 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"3","name":"Multi Sensor (2)","r":"sensors","t":"event"} (ret = 76) 20:51:09:338 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"4","name":"Multi Sensor (2)","r":"sensors","t":"event"} (ret = 76) 20:51:09:338 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"4","name":"Multi Sensor (2)","r":"sensors","t":"event"} (ret = 76) 20:51:09:339 no button map for: lumi.sensor_magnet.aq2 cl: 0x0000 cmd: 0x0A pl[0]: 001 20:51:09:339 ZCL attribute report 0x00158D0002019BFC for cluster 0x0000, ep 0x01 20:51:09:339 0x00158D0002019BFC extract Xiaomi special 20:51:09:339 04 unknown 5032 (0x13A8) 20:51:09:341 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"5","name":"Multi Sensor (2)","r":"sensors","t":"event"} (ret = 76) 20:51:09:341 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"5","name":"Multi Sensor (2)","r":"sensors","t":"event"} (ret = 76) 20:51:09:360 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:51:09:360 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:51:09:362 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"t":"event"} (ret = 108) 20:51:09:363 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"t":"event"} (ret = 108) 20:51:09:364 discard sensor state push for 6: state/lastupdated (already pushed) 20:51:09:460 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:51:09:460 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:51:09:462 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"t":"event"} (ret = 108) 20:51:09:462 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:09","open":true},"t":"event"} (ret = 108) 20:51:11:779 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:51:11:779 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:51:11:782 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:11","open":false},"t":"event"} (ret = 109) 20:51:11:782 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:11","open":false},"t":"event"} (ret = 109) 20:51:11:784 discard sensor state push for 6: state/lastupdated (already pushed) 20:51:13:916 Content not completely loaded (got 0 of 0), wait 20ms 20:51:13:954 Bind response success 20:51:13:954 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:14:342 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:51:14:342 DB save zll database items 0x00000880 20:51:14:381 DB saved in 39 ms 20:51:14:381 don't close database yet, keep open for 900 seconds 20:51:14:394 Current channel 11 20:51:14:951 Bind response success 20:51:14:951 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:18:382 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:51:18:383 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:51:18:386 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:18","open":true},"t":"event"} (ret = 108) 20:51:18:386 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:18","open":true},"t":"event"} (ret = 108) 20:51:18:387 discard sensor state push for 6: state/lastupdated (already pushed) 20:51:18:848 Content not completely loaded (got 0 of 0), wait 20ms 20:51:19:313 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:51:19:313 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:51:19:316 Websocket 10.0.1.132:49977 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:19","open":false},"t":"event"} (ret = 109) 20:51:19:316 Websocket 10.0.1.132:49992 send message: {"e":"changed","id":"6","r":"sensors","state":{"lastupdated":"2018-06-13T03:51:19","open":false},"t":"event"} (ret = 109) 20:51:19:318 discard sensor state push for 6: state/lastupdated (already pushed) 20:51:23:677 Remove websocket 10.0.1.132:49977 after error Unknown error 20:51:24:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:51:24:749 New websocket 10.0.1.132:50399 (state: 3) 20:51:28:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:32:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:32:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0006 20:51:32:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0008 20:51:33:012 Bind response success 20:51:33:012 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:34:010 Bind response success 20:51:34:010 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:34:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:51:38:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:42:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:42:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0006 20:51:42:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0008 20:51:44:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:51:45:092 Bind response success 20:51:45:093 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:46:092 Bind response success 20:51:46:092 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:46:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:46:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0008 20:51:50:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:50:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0006 20:51:54:342 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:51:55:164 Bind response success 20:51:55:164 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:56:156 Bind response success 20:51:56:156 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 20:51:56:843 poll node 00:22:a3:00:00:13:39:9b-01 20:51:56:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0008 20:51:57:155 verified group capacity: 255 and group count: 1 of LightNode 0x0022a3000013399b 20:51:57:156 0x0022a3000013399b found group 0x0001 20:52:00:154 Bind response success 20:52:00:154 skip configure report for cluster: 0x0006 attr: 0x000[marthoc/deconz] Starting deCONZ... [marthoc/deconz] Current deCONZ version: 2.05.29 [marthoc/deconz] Web UI port: 80 [marthoc/deconz] Websockets port: 443 libpng warning: iCCP: known incorrect sRGB profile This plugin does not support propagateSizeHints() This plugin does not support propagateSizeHints() This plugin does not support propagateSizeHints()

03:52:30:539 HTTP Server listen on address 0.0.0.0, port: 80, root: /usr/share/deCONZ/webapp/ 03:52:30:670 dev /dev/ttyAMA0 03:52:30:670 ZCLDB init file /root/.local/share/dresden-elektronik/deCONZ/zcldb.txt 03:52:30:863 parent process /bin/sh 03:52:30:863 gw run mode: normal 03:52:30:863 sd-card cid: 1b534d454231515430ffffffff0114a1 03:52:30:866 DB sqlite version 3.16.2 03:52:30:867 DB PRAGMA page_count: 37 03:52:30:867 DB PRAGMA page_size: 1024 03:52:30:867 DB PRAGMA freelist_count: 0 03:52:30:867 DB file size 37888 bytes, free pages 0 03:52:30:867 DB PRAGMA user_version: 2 03:52:30:885 don't close database yet, keep open for 900 seconds 20:52:30:885 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:52:30:887 started websocket server at port 443 20:52:30:889 discovery updated announce interval to 10 minutes 20:52:30:892 found node plugin: libde_rest_plugin.so - REST API Plugin 20:52:30:896 found node plugin: libde_signal_plugin.so - Signal Monitor Plugin 20:52:30:913 found node plugin: libstd_otau_plugin.so - STD OTAU Plugin 20:52:30:951 dev /dev/ttyAMA0 20:52:30:991 discard sensor state push for 1: state/daylight (already pushed) 20:52:30:000 discard sensor state push for 1: state/dark (already pushed) 20:52:31:002 discard sensor state push for 1: state/status (already pushed) 20:52:31:068 Device firmware version 0x261F0500 20:52:31:080 discard sensor state push for 1: state/lastupdated (already pushed) 20:52:31:081 unlocked max nodes: 200 20:52:31:321 Device protocol version: 0x0106 20:52:31:334 CTRL restore cached node 0x00212effff0229cd 20:52:31:335 new node - ext: 0x00212effff0229cd, nwk: 0x0000 20:52:31:413 Current channel 11 20:52:31:434 CTRL ANT_CTRL 0x03 20:52:31:490 Device protocol version: 0x0106 20:52:31:561 Current channel 11 20:52:31:580 CTRL ANT_CTRL 0x03 20:52:31:674 APS-DATA.indication from unknown node 0x0022A3000013399B 20:52:31:874 CTRL restore cached node 0x0022a3000013399b 20:52:31:882 new node - ext: 0x0022a3000013399b, nwk: 0x1100 20:52:31:885 don't close database yet, keep open for 900 seconds 20:52:31:886 LightNode 1: Vent added 20:52:32:354 CTRL restore cached node 0x00158d0002019bfc 20:52:32:355 new node - ext: 0x00158d0002019bfc, nwk: 0x987C 20:52:32:355 SensorNode 6 set node 0x00158d0002019bfc 20:52:34:274 CTRL restore cached node 0x00158d00022c644b 20:52:34:276 new node - ext: 0x00158d00022c644b, nwk: 0x4FA0 20:52:34:277 SensorNode 3 set node 0x00158d00022c644b 20:52:34:277 SensorNode 4 set node 0x00158d00022c644b 20:52:34:278 SensorNode 5 set node 0x00158d00022c644b 20:52:35:302 New websocket 10.0.1.132:50401 (state: 3) 20:52:36:219 dev /dev/ttyAMA0 20:52:36:221 GW update firmware found: /usr/share/deCONZ/firmware/deCONZ_Rpi_0x261f0500.bin.GCF 20:52:36:221 GW firmware version: 0x261f0500 20:52:36:221 GW firmware version is up to date: 0x261f0500 20:52:36:341 DB save zll database items 0x00000884 20:52:36:440 DB saved in 99 ms 20:52:36:440 don't close database yet, keep open for 900 seconds 20:52:36:441 Announced to internet 20:52:36:441 discovery server date: Wed, 13 Jun 2018 03:52:36 GMT 20:52:36:441 local time seems to be ok 20:52:36:441 discovery found version 2.04.35 for update channel stable 20:52:41:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:52:50:843 poll node 00:22:a3:00:00:13:39:9b-01 20:52:51:342 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:52:53:379 scan skip host .210 20:52:53:842 poll node 00:22:a3:00:00:13:39:9b-01 20:52:55:465 scan finished 20:52:57:843 poll node 00:22:a3:00:00:13:39:9b-01 20:53:01:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:53:01:843 poll node 00:22:a3:00:00:13:39:9b-01 20:53:05:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:09:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:11:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:53:13:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:17:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:21:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:53:21:842 poll node 00:22:a3:00:00:13:39:9b-01

20:53:25:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:29:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:30:363 Current channel 11 20:53:31:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:53:33:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:37:842 poll node 00:22:a3:00:00:13:39:9b-01 20:53:37:915 no button map for: lumi.weather cl: 0x0402 cmd: 0x0A pl[0]: 000 20:53:37:915 ZCL attribute report 0x00158D00022C644B for cluster 0x0402, ep 0x01 20:53:37:918 discard sensor state push for 3: state/temperature (already pushed) 20:53:37:919 discard sensor state push for 3: state/lastupdated (already pushed) 20:53:37:933 no button map for: lumi.weather cl: 0x0405 cmd: 0x0A pl[0]: 000 20:53:37:933 ZCL attribute report 0x00158D00022C644B for cluster 0x0405, ep 0x01 20:53:37:935 discard sensor state push for 4: state/humidity (already pushed) 20:53:37:936 discard sensor state push for 4: state/lastupdated (already pushed) 20:53:37:955 no button map for: lumi.weather cl: 0x0403 cmd: 0x0A pl[0]: 000 20:53:37:955 ZCL attribute report 0x00158D00022C644B for cluster 0x0403, ep 0x01 20:53:37:958 discard sensor state push for 5: state/pressure (already pushed) 20:53:37:959 discard sensor state push for 5: state/lastupdated (already pushed) 20:53:41:342 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:53:41:843 poll node 00:22:a3:00:00:13:39:9b-01 20:53:44:936 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:53:44:936 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:53:44:939 discard sensor state push for 6: state/open (already pushed) 20:53:44:941 discard sensor state push for 6: state/lastupdated (already pushed) 20:53:45:843 poll node 00:22:a3:00:00:13:39:9b-01 20:53:46:681 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:53:46:681 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:53:46:684 discard sensor state push for 6: state/open (already pushed) 20:53:46:685 discard sensor state push for 6: state/lastupdated (already pushed) 20:53:46:796 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:53:46:796 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:53:46:799 discard sensor state push for 6: state/lastupdated (already pushed) 20:53:49:843 poll node 00:22:a3:00:00:13:39:9b-01 20:53:51:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:53:51:470 New websocket 10.0.1.132:50420 (state: 3) 20:53:52:370 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:53:52:371 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:53:52:373 discard sensor state push for 6: state/open (already pushed) 20:53:52:375 discard sensor state push for 6: state/lastupdated (already pushed) 20:53:53:360 no button map for: lumi.sensor_magnet.aq2 cl: 0x0006 cmd: 0x0A pl[0]: 000 20:53:53:360 ZCL attribute report 0x00158D0002019BFC for cluster 0x0006, ep 0x01 20:53:53:363 discard sensor state push for 6: state/open (already pushed) 20:53:53:364 discard sensor state push for 6: state/lastupdated (already pushed) 20:53:53:843 poll node 00:22:a3:00:00:13:39:9b-01 20:53:57:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:01:342 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:54:01:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:05:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:09:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:11:342 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:54:13:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:17:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:21:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:54:21:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:25:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:30:362 Current channel 11 20:54:30:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:31:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 20:54:34:843 poll node 00:22:a3:00:00:13:39:9b-01 20:54:36:078 Remove websocket 10.0.1.132:50401 after error Unknown error

terafin commented 6 years ago

Quick one for temp: 21:01:18:683 verified group capacity: 255 and group count: 1 of LightNode 0x0022a3000013399b 21:01:18:683 0x0022a3000013399b found group 0x0001 21:01:18:843 poll node 00:22:a3:00:00:13:39:9b-01 21:01:18:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0006 21:01:18:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0008 21:01:19:684 Bind response success 21:01:19:684 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 21:01:20:843 poll node 00:22:a3:00:00:13:39:9b-01 21:01:21:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 21:01:21:681 Bind response success 21:01:21:681 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 21:01:22:843 poll node 00:22:a3:00:00:13:39:9b-01 21:01:28:843 poll node 00:22:a3:00:00:13:39:9b-01 21:01:28:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0006 21:01:28:843 discard double entry in binding queue for for 0x0022A3000013399B, cluster 0x0008 21:01:30:361 Current channel 11 21:01:30:421 no button map for: lumi.weather cl: 0x0402 cmd: 0x0A pl[0]: 000 21:01:30:421 ZCL attribute report 0x00158D00022C644B for cluster 0x0402, ep 0x01 21:01:30:423 discard sensor state push for 3: state/temperature (already pushed) 21:01:30:425 discard sensor state push for 3: state/lastupdated (already pushed) 21:01:30:440 no button map for: lumi.weather cl: 0x0405 cmd: 0x0A pl[0]: 000 21:01:30:440 ZCL attribute report 0x00158D00022C644B for cluster 0x0405, ep 0x01 21:01:30:442 discard sensor state push for 4: state/humidity (already pushed) 21:01:30:444 discard sensor state push for 4: state/lastupdated (already pushed) 21:01:30:463 no button map for: lumi.weather cl: 0x0403 cmd: 0x0A pl[0]: 000 21:01:30:463 ZCL attribute report 0x00158D00022C644B for cluster 0x0403, ep 0x01 21:01:30:465 discard sensor state push for 5: state/pressure (already pushed) 21:01:30:466 discard sensor state push for 5: state/lastupdated (already pushed) 21:01:31:341 Daylight now: sunsetEnd, status: 200, daylight: 0, dark: 1 21:01:31:758 Bind response success 21:01:31:758 skip configure report for cluster: 0x0006 attr: 0x0000 of node 0x0022A3000013399B (wait reading or unsupported) 21:01:32:204 no button map for: lumi.weather cl: 0x0000 cmd: 0x0A pl[0]: 005 21:01:32:204 ZCL attribute report 0x00158D00022C644B for cluster 0x0000, ep 0x01 21:01:32:204 0x00158D00022C644B skip Xiaomi attribute 0x0005 21:01:32:768 Bind response success

terafin commented 6 years ago

Tried with a Conbee as well . Same result :-( likely will have to return both soon.

manup commented 6 years ago

Just a wild guess, but does the Pi has proper time, therefore does NTP work?

20:52:30:991 discard sensor state push for 1: state/daylight (already pushed)
20:52:30:000 discard sensor state push for 1: state/dark (already pushed)
20:52:31:002 discard sensor state push for 1: state/status (already pushed)

The second last log, looks strange since values weren't pushed before. Currently the code uses absolute timestamps to decide if push is needed, might be problematic in some cases.

terafin commented 6 years ago

Thanks you!

The time was right, but the timezone was wrong - and just fixed it - that said, sadly still seems to have the same issue :(

manup commented 6 years ago

I'll see to fix it in the next version by not using timestamp for push handling but a simple flag, but still strange why it doesn't work in your setup.

terafin commented 6 years ago

Thanks! I'll play around with time settings as I can in the mean time. Appreciate!

stale[bot] commented 6 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

stale[bot] commented 5 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.