search

OpenZWave / qt-openzwave

QT5 Wrapper for OpenZWave
GNU Lesser General Public License v3.0
105 stars 30 forks source link

fatal: supervisor died #128

Closed tompi69 closed 4 years ago

tompi69 commented 4 years ago

set [20200715 22:17:34.394 CEST] [ozw.library] [info]: Info - Node: 0 Stopping DNSThread [22:17:34] INFO: Starting websockify... [22:17:35] 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/" [20200715 22:17:35.610 CEST] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0 [20200715 22:17:35.610 CEST] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized 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 [20200715 22:17:35.891 CEST] [ozwadmin] [info]: OZWCore Initilized QTOpenZwave(0x55a4c31520) QTOZWManager(0x55a4c32100) WebSocket server settings:

After restart the system nn raspberry pi 4 I have this error everytime again.

elahd commented 4 years ago

@tompi69: I occasionally run into the same issue. I can clear it by deleting the $SYS/broker/connection/core-zwave.main-mqtt and OpenZWave/1/status MQTT topics (with MQTT Explorer), then restarting the OpenZWave addin. I'm still not sure of the root cause.

My logs are below.

OpenZWave

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] auth.sh: executing...
[10:34:31] INFO: Auth database exists
[cont-init.d] auth.sh: exited 0.
[cont-init.d] mqtt.sh: executing...
[10:34:33] INFO: Connect to internal MqTT service
[cont-init.d] mqtt.sh: exited 0.
[cont-init.d] network_key.sh: executing...
[cont-init.d] network_key.sh: exited 0.
[cont-init.d] novnc.sh: executing...
[cont-init.d] novnc.sh: exited 0.
[cont-init.d] structure.sh: executing...
[cont-init.d] structure.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[10:34:35] INFO: Starting internal MQTT broker...
1594910075: mosquitto version 1.6.8 starting
1594910075: Config loaded from /etc/mosquitto.conf.
1594910075: Opening ipv4 listen socket on port 1883.
1594910075: Opening ipv6 listen socket on port 1883.
1594910075: Warning: Mosquitto should not be run as root/administrator.
1594910075: Connecting bridge main-mqtt (core-mosquitto:1883)
[10:34:36] INFO: Starting OpenZWave...
1594910076: New connection from 127.0.0.1 on port 1883.
1594910076: Socket error on client <unknown>, disconnecting.
ozw.daemon: Checking  "/data/ozw/config"  for manufacturer_specific.xml
ozw.daemon: Checking  "/data/ozw/config"  for options.xml
ozw.daemon: DBPath:  "/data/ozw/config/"
ozw.daemon: userPath:  "/data/ozw/config/"
ozw.daemon: Network Key Specified in Enviroment is Valid
ozw.daemon: Didn't Find Network Key File. Skipping
ozw.daemon: We Have what appears to be a valid Network Key - Passing to OZW
ozw.daemon: Didn't Find Auth Key File. Skipping
QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build
[20200716 10:34:36.834 EDT] [ozw.manager] [debug]: Database Path:  "/data/ozw/config/"  User Path "/data/ozw/config/"
[20200716 10:34:36.836 EDT] [ozw.manager] [debug]: Models Created
[20200716 10:34:36.840 EDT] [qt.remoteobjects] [warning]:  Tried to register QRemoteObjectRootSource twice "QTOZWLog"
[20200716 10:34:36.841 EDT] [ozw.manager] [debug]: QTOZWManager Ready!
[20200716 10:34:36.842 EDT] [ozw.daemon] [debug]: Ready
[20200716 10:34:36.843 EDT] [ozw.manager] [debug]: QTOZWLog Ready!
[20200716 10:34:36.844 EDT] [ozw.manager] [debug]: QTOZWOptions Ready!
[20200716 10:34:36.845 EDT] [ozw.daemon] [info]: Staring  "ozwdaemon"  Version:  "0.1.0"
[20200716 10:34:36.846 EDT] [ozw.daemon] [info]: OpenZWave Version:  "1.6.1198"
[20200716 10:34:36.846 EDT] [ozw.daemon] [info]: QT-OpenZWave Version:  "1.2.0"
[20200716 10:34:36.846 EDT] [ozw.daemon] [info]: QT Version:  5.12.5
[20200716 10:34:36.846 EDT] [default] [info]: Docker MQTT_PASSWORD Secret Missing....
[20200716 10:34:36.846 EDT] [default] [info]: Using MQTT_PASSWORD from Enviroment

[...Command registration...]

[20200716 10:34:36.851 EDT] [ozw.mqtt.publisher] [debug]: MQTT State Change "Connecting"
[20200716 10:34:36.851 EDT] [ozw.mqtt.publisher] [info]: MQTT Client Connecting
1594910076: New connection from 127.0.0.1 on port 1883.
[20200716 10:34:36.856 EDT] [ozw.library] [debug]: Always - Node: 0 OpenZwave Version 1.6-1198-g6c2ca613 Starting Up
[20200716 10:34:36.910 EDT] [ozw.library] [info]: Info - Node: 0 Loading Localization File /data/ozw/config/Localization.xml
[20200716 10:34:36.916 EDT] [ozw.library] [info]: Info - Node: 0 Loaded /data/ozw/config/Localization.xml With Revision 10
[20200716 10:34:36.921 EDT] [ozw.library] [debug]: Always - Node: 0 Using Language Localization
[20200716 10:34:36.929 EDT] [ozw.library] [info]: Info - Node: 0 Loading NotificationCCTypes File /data/ozw/config/NotificationCCTypes.xml
[20200716 10:34:36.931 EDT] [ozw.library] [info]: Info - Node: 0 Loaded /data/ozw/config/NotificationCCTypes.xml With Revision 11
[20200716 10:34:36.937 EDT] [ozw.library] [info]: Info - Node: 0 Loading SensorMultiLevelCCTypes File /data/ozw/config/SensorMultiLevelCCTypes.xml
[20200716 10:34:36.939 EDT] [ozw.library] [info]: Info - Node: 0 Loaded /data/ozw/config/SensorMultiLevelCCTypes.xml With Revision 4
[20200716 10:34:36.940 EDT] [ozw.manager] [debug]: OpenZWave Manager Instance Created
[20200716 10:34:36.940 EDT] [ozw.manager] [debug]: OpenZWave Watcher Registered
[20200716 10:34:36.940 EDT] [ozw.manager] [debug]: Notification Signals Setup
[20200716 10:34:36.941 EDT] [ozw.library] [info]: Info - Node: 0 Setting Up Provided Network Key for Secure Communications
[20200716 10:34:36.995 EDT] [ozw.library] [info]: Info - Node: 0 Manufacturer_Specific.xml file Revision is 109
[10:34:37] 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/"
[10:34:38] INFO: Successfully send discovery information to Home Assistant.
[20200716 10:34:38.798 EDT] [ozw.library] [info]: Info - Node: 0 Product name collision: SmartCode 910 type 1 id 1 manufacturerid 90, collides with Touchpad Electronic Deadbolt, type 1 id 1 manufacturerid 90
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
[20200716 10:34:39.016 EDT] [ozwadmin] [info]: OZWCore Initilized QTOpenZwave(0x13166b0) QTOZWManager(0x13173f0)
[20200716 10:34:39.137 EDT] [default] [warning]: QVncServer created on port 5900
[10:34:39] INFO: Starting websockify...
[20200716 10:34:39.713 EDT] [ozw.library] [info]: Info - Node: 0 Queuing Lookup on mfs.db.openzwave.com for Node 0
[20200716 10:34:39.715 EDT] [ozw.library] [info]: Info - Node: 0   Opening controller /dev/serial/by-id/usb-0658_0200-if00
[20200716 10:34:39.715 EDT] [ozw.library] [info]: Info - Node: 0 Trying to open serial port /dev/serial/by-id/usb-0658_0200-if00 (attempt 1)
[20200716 10:34:39.716 EDT] [ozw.library] [info]: Info - Node: 0 Starting DNSThread
[20200716 10:34:39.716 EDT] [ozw.library] [info]: Info - Node: 0 LookupTxT Checking mfs.db.openzwave.com
[20200716 10:34:39.717 EDT] [ozw.library] [info]: Info - Node: 0 Serial port /dev/serial/by-id/usb-0658_0200-if00 opened (attempt 1)
[20200716 10:34:39.721 EDT] [ozw.library] [info]: Info - Node: 0 Timer: thread starting
[20200716 10:34:39.721 EDT] [ozw.library] [info]: Info - Node: 0 mgr,     Added driver for controller /dev/serial/by-id/usb-0658_0200-if00
[20200716 10:34:39.722 EDT] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
[20200716 10:34:39.724 EDT] [ozw.manager] [debug]: AddDriver Completed
[20200716 10:34:39.724 EDT] [ozw.library] [debug]: Detail - Node: 0 Timer: waiting with timeout -1 ms
[20200716 10:34:39.740 EDT] [ozw.library] [info]: Info - Node: 0 Lookup for mfs.db.openzwave.com returned 109
1594910079: New client connected from 127.0.0.1 as qt-openzwave-1 (p2, c1, k60, u'ozw').
[20200716 10:34:39.770 EDT] [ozw.mqtt.publisher] [debug]: MQTT State Change "Connected"
[20200716 10:34:39.771 EDT] [ozw.mqtt.publisher] [info]: MQTT Client Connected

[... Creating subscriptions ...]

[20200716 10:34:39.820 EDT] [ozw.mqtt.publisher] [debug]: Topics:  "OpenZWave/1/status/"
[20200716 10:34:39.820 EDT] [ozw.mqtt.publisher] [warning]: Another ozwdaemon is running for Instance  1
[20200716 10:34:39.820 EDT] [ozw.mqtt.publisher] [warning]: If not, please clean up the MQTT Topic:  "OpenZWave/1/status/"
[20200716 10:34:39.820 EDT] [ozw.mqtt.publisher] [warning]: "{\n    \"OpenZWave_Version\": \"1.6.1198\",\n    \"OZWDaemon_Version\": \"0.1.0\",\n    \"QTOpenZWave_Version\": \"1.2.0\",\n    \"QT_Version\": \"5.12.5\",\n    \"Status\": \"driverRemoved\",\n    \"TimeStamp\": 1594909953,\n    \"homeID\": 0\n}"

[... Stale topic cleanup ...]

[20200716 10:34:40.009 EDT] [ozw.library] [debug]: Always - Node: 0 ***************************************************************************
[20200716 10:34:40.009 EDT] [ozw.library] [debug]: Always - Node: 0 *********************  Cumulative Network Statistics  *********************
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 *** General
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 Driver run time: . .  . 0 days, 0 hours, 0 minutes
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 Frames processed: . . . . . . . . . . . . . . . . . . . . 0
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 Total messages successfully received: . . . . . . . . . . 0
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 Total Messages successfully sent: . . . . . . . . . . . . 0
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 ACKs received from controller:  . . . . . . . . . . . . . 0
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 *** Errors
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 Unsolicited messages received while waiting for ACK:  . . 0
[20200716 10:34:40.010 EDT] [ozw.library] [debug]: Always - Node: 0 Reads aborted due to timeouts:  . . . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 Bad checksum errors:  . . . . . . . . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 CANs received from controller:  . . . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 NAKs received from controller:  . . . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 Out of frame data flow errors:  . . . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 Messages retransmitted: . . . . . . . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 Messages dropped and not delivered: . . . . . . . . . . . 0
[20200716 10:34:40.011 EDT] [ozw.library] [debug]: Always - Node: 0 ***************************************************************************
[20200716 10:34:40.011 EDT] [ozw.library] [warning]: Warning - Node: 0 WARNING: Tried to write driver config with no home ID set
[20200716 10:34:40.015 EDT] [ozw.library] [info]: Info - Node: 0 Stopping DNSThread
[10:34:40] 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/"
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
[20200716 10:34:41.876 EDT] [ozwadmin] [info]: OZWCore Initilized QTOpenZwave(0x756cfd40) QTOZWManager(0x17bcd60)
[20200716 10:34:41.985 EDT] [default] [warning]: QVncServer created on port 5900
[20200716 10:34:43.229 EDT] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0
[20200716 10:34:43.230 EDT] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized
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
[20200716 10:34:45.233 EDT] [ozw.library] [info]: Info - Node: 0 mgr,     Driver for controller /dev/serial/by-id/usb-0658_0200-if00 removed
[20200716 10:34:45.234 EDT] [ozw.manager] [debug]: Driver Removed for  "/dev/serial/by-id/usb-0658_0200-if00"
[20200716 10:34:45.234 EDT] [ozw.manager] [debug]: OZW Serial Port Closed
[20200716 10:34:45.235 EDT] [ozw.daemon] [info]: Shutting Down  "ozwdaemon"  Version:  "0.1.0"
[20200716 10:34:45.235 EDT] [ozw.daemon] [info]: OpenZWave Version:  "1.6.1198"
[20200716 10:34:45.236 EDT] [ozw.daemon] [info]: QT-OpenZWave Version:  "1.2.0"
[20200716 10:34:45.236 EDT] [ozw.daemon] [info]: QT Version:  5.12.5

[... Stale topic cleanup ...]

1594910086: Socket error on client qt-openzwave-1, disconnecting.
In exit
1594910086: mosquitto version 1.6.8 terminating
1594910086: Saving in-memory database to /data/mosquitto.db.
[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.

Mosquitto

1594910067: Client core-zwave.main-mqtt has exceeded timeout, disconnecting.
1594910075: New connection from 172.30.33.4 on port 1883.
1594910075: New bridge connected from 172.30.33.4 as core-zwave.main-mqtt (p2, c0, k60, u'addons').
1594910091: Socket error on client core-zwave.main-mqtt, disconnecting.
Fishwaldo commented 4 years ago

@tompi69 as pointed out - Need to check your logs for "warning" messages further up (I have no idea how in the addon).

For the official ozwdaemon docker image, the error on why its shutting down should be clearer now.