search

dresden-elektronik / deconz-rest-plugin

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

Deconz app crash at startup #5523

Closed RodEzIO closed 2 years ago

RodEzIO commented 2 years ago

Describe the bug

Deconz app crash at startup. The system was running since month and was stable. I don't do any HW/SW modification and now it doesn't work anymore.

Steps to reproduce the behavior

Expected behavior

Screenshots

Environment

deCONZ Logs

[07:51:26] INFO: deCONZ waiting for VNC to start [07:51:26] INFO: Starting the deCONZ gateway... libpng warning: iCCP: known incorrect sRGB profile libpng warning: iCCP: known incorrect sRGB profile [07:51:27] INFO: Starting Nginx... 2021/11/27 07:51:28 [notice] 309#309: using the "epoll" event method 2021/11/27 07:51:28 [notice] 309#309: nginx/1.14.2 2021/11/27 07:51:28 [notice] 309#309: OS: Linux 5.10.17-v8 2021/11/27 07:51:28 [notice] 309#309: getrlimit(RLIMIT_NOFILE): 1048576:1048576 2021/11/27 07:51:28 [notice] 309#309: start worker processes 2021/11/27 07:51:28 [notice] 309#309: start worker process 1361 07:51:27:734 HTTP Server listen on address 0.0.0.0, port: 40850, root: /usr/share/deCONZ/webapp/ 07:51:27:828 COM: use stable device path /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2432026-if00 07:51:27:891 COM: /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2432026-if00 / serialno: DE2432026, ConBee II 07:51:27:891 ZCLDB init file /data/.local/share/dresden-elektronik/deCONZ/zcldb.txt 07:51:28:032 parent process s6-supervise 07:51:28:032 gw run mode: docker/hassio 07:51:28:032 GW sd-card image version file does not exist: /data/.local/share/dresden-elektronik/deCONZ/gw-version 07:51:28:032 sd-card cid: 035344534533324780ffffffff013800 07:51:28:034 DB sqlite version 3.27.2 07:51:28:035 DB PRAGMA page_count: 39 07:51:28:035 DB PRAGMA page_size: 4096 07:51:28:035 DB PRAGMA freelist_count: 2 07:51:28:035 DB file size 159744 bytes, free pages 2 07:51:28:035 DB PRAGMA user_version: 7 07:51:28:035 DB upgrade to user_version 8 07:51:28:056 DB write sqlite user_version 8 07:51:28:067 DB PRAGMA user_version: 8 07:51:28:067 DB cleanup 07:51:28:067 DB create temporary views 07:51:28:159 started websocket server at port 8081 07:51:28:163 [INFO] - Found file containing button maps. Parsing data... 07:51:28:174 [INFO] - Button maps loaded. 07:51:28:177 dlg action: Read binding table 07:51:28:177 found node plugin: libde_rest_plugin.so - REST API Plugin 07:51:28:180 found node plugin: libde_signal_plugin.so - Signal Monitor Plugin 07:51:33:942 found node plugin: libstd_otau_plugin.so - STD OTAU Plugin 07:51:34:022 LightNode 7: Window covering device 7 added 07:51:34:036 LightNode 4: Window covering device 4 added 07:51:34:038 LightNode 8: Window covering device 8 added 07:51:34:041 LightNode 6: Window covering device 6 added 07:51:34:044 LightNode 19: Window covering device 19 added 07:51:34:045 SensorNode 2 set node 0x00124b0022cf6dea 07:51:34:046 SensorNode 3 set node 0x00124b0022cf6dea 07:51:34:049 LightNode 10: Window covering device 10 added 07:51:34:051 LightNode 14: Window covering device 14 added 07:51:34:053 LightNode 9: Window covering device 9 added 07:51:34:055 LightNode 5: Window covering device 5 added 07:51:34:056 LightNode 13: Window covering device 13 added 07:51:34:058 LightNode 16: Window covering device 16 added 07:51:34:060 LightNode 3: Window covering device 3 added 07:51:34:061 LightNode 18: Window covering device 18 added 07:51:34:063 LightNode 12: Window covering device 12 added 07:51:34:065 LightNode 2: Window covering device 2 added 07:51:34:066 LightNode 11: Window covering device 11 added 07:51:34:068 LightNode 15: Window covering device 15 added 07:51:34:070 LightNode 21: Window covering device 21 added 07:51:34:071 LightNode 20: Window covering device 20 added 07:51:34:073 LightNode 17: Window covering device 17 added 07:51:35:141 COM: /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2432026-if00 / serialno: DE2432026, ConBee II 07:51:35:251 Skip idle timer callback, too early: elapsed 949 msec PROTO: CRC error 07:51:36:725 Device firmware version 0x26680700 ConBee II 07:51:36:727 unlocked max nodes: 512 07:51:36:745 Device protocol version: 0x010E 07:51:36:757 new node - ext: 0x00212effff073849, nwk: 0x0000 07:51:36:826 Current channel 11 07:51:36:831 CTRL got nwk update id 1 07:51:36:832 CTRL ANT_CTRL 0x03 07:51:36:844 Device protocol version: 0x010E 07:51:36:874 CTRL ANT_CTRL 0x03 07:51:36:905 ZCL attribute report 0xF4CE36CAFAB0405B for cluster: 0x0102, ep: 0x0A, frame control: 0x08, mfcode: 0x0000 07:51:36:908 ZCL attribute report 0xF4CE3640ABFB5667 for cluster: 0x0102, ep: 0x0A, frame control: 0x08, mfcode: 0x0000 07:51:36:912 ZCL attribute report 0xF4CE36AF06563F43 for cluster: 0x0102, ep: 0x0A, frame control: 0x08, mfcode: 0x0000 07:51:37:151 Skip idle timer callback, too early: elapsed 949 msec [07:51:37] INFO: Successfully send discovery information to Home Assistant. 07:51:42:026 DB UPDATE device_descriptors SET data = x'10400f3511472b0040002b0000', timestamp = 1637995902 WHERE device_id = (SELECT id FROM devices WHERE mac = '00:21:2e:ff:ff:07:38:49') AND endpoint = 0 AND type = 2 07:51:42:027 DB INSERT INTO device_descriptors (device_id, endpoint, type, data, timestamp) SELECT id, 0, 2, x'10400f3511472b0040002b0000', 1637995902 FROM devices WHERE mac = '00:21:2e:ff:ff:07:38:49' 07:51:42:501 LightNode 1: Configuration tool 1 added 07:51:42:502 DB UPDATE device_descriptors SET data = x'0104010500010400000a0019000105040100200000050205', timestamp = 1637995902 WHERE device_id = (SELECT id FROM devices WHERE mac = '00:21:2e:ff:ff:07:38:49') AND endpoint = 1 AND type = 4 07:51:42:503 DB INSERT INTO device_descriptors (device_id, endpoint, type, data, timestamp) SELECT id, 1, 4, x'0104010500010400000a0019000105040100200000050205', 1637995902 FROM devices WHERE mac = '00:21:2e:ff:ff:07:38:49' 07:51:42:999 DB UPDATE device_descriptors SET data = x'f2e0a164000100012100', timestamp = 1637995902 WHERE device_id = (SELECT id FROM devices WHERE mac = '00:21:2e:ff:ff:07:38:49') AND endpoint = 242 AND type = 4 07:51:43:001 DB INSERT INTO device_descriptors (device_id, endpoint, type, data, timestamp) SELECT id, 242, 4, x'f2e0a164000100012100', 1637995902 FROM devices WHERE mac = '00:21:2e:ff:ff:07:38:49' 07:51:44:141 GW update firmware found: /usr/share/deCONZ/firmware/deCONZ_ConBeeII_0x26660700.bin.GCF 07:51:44:142 GW firmware version: 0x26680700 07:51:44:143 GW firmware version is up to date: 0x26680700 [07:51:50] INFO: Starting VNC server (local/yes)... In exit Closing socket listening at 127.0.0.1:5901 2021/11/27 07:51:50 [notice] 309#309: signal 15 (SIGTERM) received from 303, exiting 2021/11/27 07:51:50 [notice] 1361#1361: exiting 2021/11/27 07:51:50 [notice] 1361#1361: exit 2021/11/27 07:51:50 [notice] 309#309: signal 17 (SIGCHLD) received from 1361 2021/11/27 07:51:50 [notice] 309#309: worker process 1361 exited with code 0 2021/11/27 07:51:50 [notice] 309#309: exit [cont-finish.d] executing container finish scripts... [cont-finish.d] done. [s6-finish] waiting for services. [s6-finish] sending all processes the TERM signal. [s6-finish] sending all processes the KILL signal and exiting.

Additional context

dworkin74 commented 2 years ago

I don't know if it is related but phoscon.de is unavailable. I have the same issue

Smanar commented 2 years ago

And bad error.

Just to try, as you haven't done modification, you haven't an old backup to test a database corruption ?

RodEzIO commented 2 years ago

an hardware reboot strangely solve the problem, however after a week of stable operation it crash again. Almost at the same time, always at Friday evening. An ha host reboot doesn't solve the problem. Tomorrow I will try to remove plug and insert it again. Another strange thing is that HA supervisor is unavailable (some behavior last week) Here is the updated log.

[20:47:54] INFO: Starting VNC server (local/yes)... [20:47:55] INFO: Starting websockify... [20:47:58] INFO: deCONZ waiting for VNC to start [20:47:58] INFO: Starting the deCONZ gateway... WebSocket server settings:

  • Listen on 127.0.0.1:5901
  • Flash security policy server
  • Web server. Web root: /usr/share/novnc
  • No SSL/TLS support (no cert file)
  • proxying from 127.0.0.1:5901 to 127.0.0.1:5900 libpng warning: iCCP: known incorrect sRGB profile libpng warning: iCCP: known incorrect sRGB profile [20:48:02] INFO: Starting Nginx... 2021/12/03 20:48:02 [notice] 312#312: using the "epoll" event method 2021/12/03 20:48:02 [notice] 312#312: nginx/1.14.2 2021/12/03 20:48:02 [notice] 312#312: OS: Linux 5.10.17-v8 2021/12/03 20:48:02 [notice] 312#312: getrlimit(RLIMIT_NOFILE): 1048576:1048576 2021/12/03 20:48:02 [notice] 312#312: start worker processes 2021/12/03 20:48:02 [notice] 312#312: start worker process 1451 20:48:02:326 HTTP Server listen on address 0.0.0.0, port: 40850, root: /usr/share/deCONZ/webapp/ 20:48:02:444 COM: use stable device path /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2432026-if00 20:48:02:516 COM: /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2432026-if00 / serialno: DE2432026, ConBee II 20:48:02:516 ZCLDB init file /data/.local/share/dresden-elektronik/deCONZ/zcldb.txt 20:48:02:858 parent process s6-supervise 20:48:02:858 gw run mode: docker/hassio 20:48:02:858 GW sd-card image version file does not exist: /data/.local/share/dresden-elektronik/deCONZ/gw-version 20:48:02:859 sd-card cid: 035344534533324780ffffffff013800 20:48:02:903 DB sqlite version 3.27.2 20:48:02:910 DB PRAGMA page_count: 48 20:48:02:910 DB PRAGMA page_size: 4096 20:48:02:910 DB PRAGMA freelist_count: 3 20:48:02:910 DB file size 196608 bytes, free pages 3 20:48:02:910 DB PRAGMA user_version: 8 20:48:02:910 DB cleanup 20:48:02:916 DB create temporary views 20:48:02:959 started websocket server at port 8081 20:48:02:985 [INFO] - Found file containing button maps. Parsing data... 20:48:03:009 [INFO] - Button maps loaded. 20:48:03:012 dlg action: Read binding table 20:48:03:012 found node plugin: libde_rest_plugin.so - REST API Plugin 20:48:03:020 found node plugin: libde_signal_plugin.so - Signal Monitor Plugin 20:48:11:363 found node plugin: libstd_otau_plugin.so - STD OTAU Plugin 20:48:11:507 LightNode 1: Configuration tool 1 added 20:48:11:529 LightNode 7: Window covering device 7 added 20:48:11:532 LightNode 4: Window covering device 4 added 20:48:11:535 LightNode 8: Window covering device 8 added 20:48:11:538 LightNode 6: Window covering device 6 added 20:48:11:540 LightNode 19: Window covering device 19 added 20:48:11:542 SensorNode 2 set node 0x00124b0022cf6dea 20:48:11:542 SensorNode 3 set node 0x00124b0022cf6dea 20:48:11:545 LightNode 10: Window covering device 10 added 20:48:11:549 LightNode 14: Window covering device 14 added 20:48:11:552 LightNode 9: Window covering device 9 added 20:48:11:554 LightNode 5: Window covering device 5 added 20:48:11:556 LightNode 13: Window covering device 13 added 20:48:11:560 LightNode 16: Window covering device 16 added 20:48:11:563 LightNode 3: Window covering device 3 added 20:48:11:565 LightNode 18: Window covering device 18 added 20:48:11:568 LightNode 12: Window covering device 12 added 20:48:11:572 LightNode 2: Window covering device 2 added 20:48:11:574 LightNode 11: Window covering device 11 added 20:48:11:576 LightNode 15: Window covering device 15 added 20:48:11:579 LightNode 21: Window covering device 21 added 20:48:11:581 LightNode 20: Window covering device 20 added 20:48:11:583 LightNode 17: Window covering device 17 added 20:48:12:669 COM: /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2432026-if00 / serialno: DE2432026, ConBee II [20:48:12] INFO: Successfully send discovery information to Home Assistant. 20:48:12:819 Skip idle timer callback, too early: elapsed 943 msec PROTO: CRC error PROTO: CRC error 20:48:14:312 Device firmware version 0x26680700 ConBee II 20:48:14:313 unlocked max nodes: 512 20:48:14:333 Device protocol version: 0x010E 20:48:14:394 Current channel 11 20:48:14:398 CTRL got nwk update id 1 20:48:14:402 CTRL ANT_CTRL 0x03 20:48:14:415 Device protocol version: 0x010E 20:48:14:445 CTRL ANT_CTRL 0x03 20:48:14:473 ZCL attribute report 0x00124B0022CF6DEA for cluster: 0x0405, ep: 0x01, frame control: 0x18, mfcode: 0x0000 20:48:14:487 ZCL attribute report 0xF4CE36EF45964830 for cluster: 0x0102, ep: 0x0A, frame control: 0x08, mfcode: 0x0000 20:48:14:491 ZCL attribute report 0xF4CE361968C6BA69 for cluster: 0x0102, ep: 0x0A, frame control: 0x08, mfcode: 0x0000 20:48:14:719 Skip idle timer callback, too early: elapsed 949 msec 20:48:19:386 New websocket 172.30.32.1:35666 (state: 3) 20:48:21:724 GW update firmware found: /usr/share/deCONZ/firmware/deCONZ_ConBeeII_0x26660700.bin.GCF 20:48:21:724 GW firmware version: 0x26680700 20:48:21:724 GW firmware version is up to date: 0x26680700 [20:48:27] INFO: Starting VNC server (local/yes)... In exit 2021/12/03 20:48:28 [notice] 312#312: signal 15 (SIGTERM) received from 304, exiting 2021/12/03 20:48:28 [notice] 1451#1451: exiting Closing socket listening at 127.0.0.1:5901 2021/12/03 20:48:28 [notice] 1451#1451: exit 2021/12/03 20:48:28 [notice] 312#312: signal 17 (SIGCHLD) received from 1451 2021/12/03 20:48:28 [notice] 312#312: worker process 1451 exited with code 0 2021/12/03 20:48:28 [notice] 312#312: exit [cont-finish.d] executing container finish scripts... [cont-finish.d] done. [s6-finish] waiting for services. [s6-finish] sending all processes the TERM signal. [s6-finish] sending all processes the KILL signal and exiting.
Mimiix commented 2 years ago

Probsbly because the Dresden server is down again.

RodEzIO commented 2 years ago

Probsbly because the Dresden server is down again.

thanks for the info, could you please explain better how does impact the Dresden server on local deCONZ operation ?

If it is useful, the last data from my zigbee sensor is at 18:29.

Mimiix commented 2 years ago

There's a discovery server it talks to, something with phoscon.de/discovery, where it shows where on your network it is. There seems to be a problem that causes you to crash when that occurs. However it doesn't affect most of the users (me included, mine works fine).

You can disable this with the rest api.

github-actions[bot] commented 2 years ago

As there has not been any response in 21 days, this issue has been automatically marked as stale. At OP: Please either close this issue or keep it active It will be closed in 7 days if no further activity occurs.

github-actions[bot] commented 2 years ago

As there has not been any response in 28 days, this issue will be closed. @ OP: If this issue is solved post what fixed it for you. If it is not solved, request to get this opened again.