search

home-assistant / addons

:heavy_plus_sign: Docker add-ons for Home Assistant
https://home-assistant.io/hassio/
Apache License 2.0
1.55k stars 1.5k forks source link

ozwave 0.5.0 crashing #1454

Closed Cervenka closed 4 years ago

Cervenka commented 4 years ago

ozwave is crashing for me after updating it from 0.4 to 0.5


[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "removeassociation" 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/removeassociation/") 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "removefailednode" 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/removefailednode/") 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "removenode" 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/removenode/") 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "replacefailednode" 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/replacefailednode/") 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestallconfigparam" 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestallconfigparam/") 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestconfigparam" 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestconfigparam/") 
[20200710 16:45:21.032 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnetworkupdate" 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnetworkupdate/") 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnodedynamic" 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodedynamic/") 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnodeneighborupdate" 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodeneighborupdate/") 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "requestnodestate" 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/requestnodestate/") 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "sendnodeinformation" 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/sendnodeinformation/") 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "setpollinterval" 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/setpollinterval/") 
[20200710 16:45:21.033 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "setvalue" 
[20200710 16:45:21.041 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/setvalue/") 
[20200710 16:45:21.041 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "softresetcontroller" 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/softresetcontroller/") 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "syncronisenodeneighbors" 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/syncronisenodeneighbors/") 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "testnetwork" 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/testnetwork/") 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Creating Subscription for  "testnetworknode" 
[20200710 16:45:21.042 CEST] [ozw.mqtt.commands] [debug]: Subscription Setup for  QMqttTopicFilter("OpenZWave/1/command/testnetworknode/") 
[20200710 16:45:21.045 CEST] [ozw.library] [info]: Info - Node: 0 Lookup for mfs.db.openzwave.com returned 108 
[20200710 16:45:21.085 CEST] [ozw.mqtt.publisher] [debug]: Topics:  "OpenZWave/1/status/" 
[20200710 16:45:21.086 CEST] [ozw.mqtt.publisher] [warning]: Another ozwdaemon is running for Instance  1 
[20200710 16:45:21.086 CEST] [ozw.mqtt.publisher] [warning]: If not, please clean up the MQTT Topic:  "OpenZWave/1/status/" 
[20200710 16:45:21.086 CEST] [ozw.mqtt.publisher] [warning]: "{\n    \"OpenZWave_Version\": \"1.6.1201\",\n    \"OZWDaemon_Version\": \"0.1.0\",\n    \"QTOpenZWave_Version\": \"1.2.0\",\n    \"QT_Version\": \"5.14.2\",\n    \"Status\": \"driverRemoved\",\n    \"TimeStamp\": 1594392276,\n    \"homeID\": 0\n}" 
[20200710 16:45:21.086 CEST] [ozw.library] [debug]: Detail - Node: 0 Notification: DriverRemoved 
[20200710 16:45:21.086 CEST] [ozw.notifications] [debug]: Notification pvt_driverRemoved  0 Thread:  0x7fb69f4e38 
[20200710 16:45:21.086 CEST] [ozw.mqtt.publisher] [debug]: Publishing Event stopped 
[20200710 16:45:21.086 CEST] [ozw.mqtt.publisher] [debug]: Publishing Event driverRemoved: 0 
[20200710 16:45:21.087 CEST] [ozw.library] [debug]: Always - Node: 0 *************************************************************************** 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 *********************  Cumulative Network Statistics  ********************* 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 *** General 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Driver run time: . .  . 0 days, 0 hours, 0 minutes 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Frames processed: . . . . . . . . . . . . . . . . . . . . 0 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Total messages successfully received: . . . . . . . . . . 0 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Total Messages successfully sent: . . . . . . . . . . . . 0 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 ACKs received from controller:  . . . . . . . . . . . . . 0 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 *** Errors 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Unsolicited messages received while waiting for ACK:  . . 0 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Reads aborted due to timeouts:  . . . . . . . . . . . . . 0 
[20200710 16:45:21.088 CEST] [ozw.library] [debug]: Always - Node: 0 Bad checksum errors:  . . . . . . . . . . . . . . . . . . 0 
[20200710 16:45:21.089 CEST] [ozw.library] [debug]: Always - Node: 0 CANs received from controller:  . . . . . . . . . . . . . 0 
[20200710 16:45:21.089 CEST] [ozw.library] [debug]: Always - Node: 0 NAKs received from controller:  . . . . . . . . . . . . . 0 
[20200710 16:45:21.090 CEST] [ozw.library] [debug]: Always - Node: 0 Out of frame data flow errors:  . . . . . . . . . . . . . 0 
[20200710 16:45:21.090 CEST] [ozw.library] [debug]: Always - Node: 0 Messages retransmitted: . . . . . . . . . . . . . . . . . 0 
[20200710 16:45:21.090 CEST] [ozw.library] [debug]: Always - Node: 0 Messages dropped and not delivered: . . . . . . . . . . . 0 
[20200710 16:45:21.090 CEST] [ozw.library] [debug]: Always - Node: 0 *************************************************************************** 
[20200710 16:45:21.090 CEST] [ozw.library] [warning]: Warning - Node: 0 WARNING: Tried to write driver config with no home ID set 
[20200710 16:45:21.092 CEST] [ozw.library] [info]: Info - Node: 0 Stopping DNSThread 
[16:45:21] INFO: Starting ozw-admin...
QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-root'
ozwadmin: Settings Path is at  "/root/.config/OpenZWave/ozw-admin.conf"
ozwadmin: Checking  "/data/ozw/config"  for manufacturer_specific.xml
ozwadmin: Checking  "/data/ozw/config"  for options.xml
ozwadmin: DBPath:  "/data/ozw/config/"
ozwadmin: userPath:  "/data/ozw/config/"
WebSocket server settings:
  - Listen on :8099
  - Web server. Web root: /usr/share/novnc
  - No SSL/TLS support (no cert file)
  - proxying from :8099 to 127.0.0.1:5900
ozwadmin: Settings Path:  "/root/.config/OpenZWave/ozw-admin.conf"
ozwadmin: Using Saved Network Cache Size: 1000
QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build
[20200710 16:45:22.078 CEST] [ozwadmin] [info]: OZWCore Initilized QTOpenZwave(0x559b6ec100) QTOZWManager(0x559b72fb80) 
[20200710 16:45:22.133 CEST] [default] [warning]: QVncServer created on port 5900 
[20200710 16:45:22.296 CEST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0 
[20200710 16:45:22.296 CEST] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized 
[20200710 16:45:24.302 CEST] [ozw.library] [info]: Info - Node: 0 mgr,     Driver for controller /dev/serial/by-id/usb-0658_0200-if00 removed 
[20200710 16:45:24.302 CEST] [ozw.manager] [debug]: Driver Removed for  "/dev/serial/by-id/usb-0658_0200-if00" 
[20200710 16:45:24.302 CEST] [ozw.manager] [debug]: OZW Serial Port Closed 
[20200710 16:45:24.302 CEST] [ozw.daemon] [info]: Shutting Down  "ozwdaemon"  Version:  "0.1.0" 
[20200710 16:45:24.303 CEST] [ozw.daemon] [info]: OpenZWave Version:  "1.6.1201" 
[20200710 16:45:24.303 CEST] [ozw.daemon] [info]: QT-OpenZWave Version:  "1.2.0" 
[20200710 16:45:24.303 CEST] [ozw.daemon] [info]: QT Version:  5.14.2 
1594392324: Client qt-openzwave-1 disconnected.
In exit
[cont-finish.d] executing container finish scripts...
[cont-finish.d] done.
[s6-finish] waiting for services.
1594392324: mosquitto version 1.6.9 terminating
1594392324: Saving in-memory database to /data/mosquitto.db.
s6-svwait: fatal: supervisor died
[s6-finish] sending all processes the TERM signal.
[s6-finish] sending all processes the KILL signal and exiting.```
pfinnigan commented 4 years ago

I was having the same problem.

First try deleting the OpenZwave message queue in your MQTT instance and restarting (as implied in the log) this used to work for me in the previous version. In this version (0.5.0) I have to add the instance configuration variable and keep alternating between 1 and 2 while always remembering to delete the old queues from the MQTT server when I restart.

I have other problems but those could be self-inflicted so even with the above my system is not working but at least the add-on stays up. I hope that my comments may help those with more knowledge find the problem.

wjbuys commented 4 years ago

It looks like somehow on unclean shutdown, the bridged MQTT instance inside the OpenZWave addon still has a stale /OpenZWave/1/Status key. Before that internal MQTT server can sync with the main HASS MQTT server, the startup script dies.

For me, this results in a failure to start the addon after an unclean shutdown, even if I delete the /OpenZWave/1 key in the HASS MQTT server. The only way I've found to recover from this is to uninstall and reinstall the OpenZWave addon (which seems to clear out the local data of the OZW MQTT server).

pmaciocia commented 4 years ago

I'm seeing this error as well running a generic linux install. I actually am getting a segfault message appearing in dmesg when the crash happens: [65410.180934] ozwadmin[13807]: segfault at 38 ip 00007f6e9083bd83 sp 00007ffed81961f0 error 4 in libqvnc.so[7f6e90837000+15000]

fmagn commented 4 years ago

I also have this problem. I'm running OpenZwave as a (supervisor) add-on. Any hints on how to diagnose this?