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

Crash during startup v0.5.2 #175

Open
abmantis opened this issue Oct 3, 2020 · 1 comment
Open

Crash during startup v0.5.2 #175

abmantis opened this issue Oct 3, 2020 · 1 comment

Comments

@abmantis
Copy link

abmantis commented Oct 3, 2020

A lot of times during startup, OZW will crash. This is specially annoying since the network takes 40+ minutes to startup :/
I'm using this in HA with the hass.io plugin.

Here are the last few lines from the log:

[20201003 22:09:24.037 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event valueChanged: 12947851136729108 
[20201003 22:09:24.050 WEST] [ozw.library] [debug]: Detail - Node: 131   Received: 0x01, 0x0b, 0x00, 0x04, 0x00, 0x83, 0x05, 0x70, 0x06, 0x30, 0x01, 0x00, 0x31 
[20201003 22:09:24.050 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.051 WEST] [ozw.library] [info]: Info - Node: 131 Response RTT 35 Average Response RTT 35 
[20201003 22:09:24.051 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.051 WEST] [ozw.library] [debug]: Detail - Node: 131 Initial read of value 
[20201003 22:09:24.052 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.052 WEST] [ozw.library] [info]: Info - Node: 131 Received Configuration report: Parameter=48, Value=0 
[20201003 22:09:24.052 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.053 WEST] [ozw.library] [debug]: Detail - Node: 131 Notification: ValueChanged CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 48 
[20201003 22:09:24.053 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.054 WEST] [ozw.notifications] [debug]: Notification pvt_valueChanged:  13510801090150426 Thread:  0x7fe2b8f29d48 
[20201003 22:09:24.067 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.067 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.067 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.068 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.068 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.068 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.068 WEST] [ozw.mqtt.publisher.value] [warning]: Bitset is Missing Position or Value Members, or Incorrect Types:  "{\n    \"Label\": \"Enable/disable to send a report on Threshold\",\n    \"Value\": [],\n    \"Units\": \"\",\n    \"ValueSet\": false,\n    \"ValuePolled\": false,\n    \"ChangeVerified\": false,\n    \"Min\": 0,\n    \"Max\": 0,\n    \"Type\": \"BitSet\",\n    \"Instance\": 1,\n    \"CommandClass\": \"COMMAND_CLASS_CONFIGURATION\",\n    \"Index\": 48,\n    \"Node\": 131,\n    \"Genre\": \"Config\",\n    \"Help\": \"Enable/disable to send a report when the measurement is more than the upper limit value or less than the lower limit value. Note: If USB power, the Sensor will check the limit every 10 seconds. If battery power, the Sensor will check the limit when it is waken up.\",\n    \"ValueIDKey\": 13510801090150426,\n    \"ReadOnly\": false,\n    \"WriteOnly\": false,\n    \"Event\": \"valueAdded\",\n    \"TimeStamp\": 1601756805\n}" 
[20201003 22:09:24.076 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event valueChanged: 13510801090150426 
[20201003 22:09:24.090 WEST] [ozw.library] [debug]: Detail - Node: 131   Received: 0x01, 0x07, 0x00, 0x13, 0xbc, 0x00, 0x00, 0x07, 0x50 
[20201003 22:09:24.090 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.091 WEST] [ozw.library] [debug]: Detail - Node: 131   ZW_SEND_DATA Request with callback ID 0xbc received (expected 0xbc) 
[20201003 22:09:24.091 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.092 WEST] [ozw.library] [info]: Info - Node: 131 Request RTT 77 Average Request RTT 51 
[20201003 22:09:24.092 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.093 WEST] [ozw.library] [debug]: Detail - Node: 131   Expected callbackId was received 
[20201003 22:09:24.093 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.102 WEST] [ozw.library] [debug]: Detail - Node: 131   Received: 0x01, 0x0b, 0x00, 0x04, 0x00, 0x83, 0x05, 0x70, 0x06, 0x30, 0x01, 0x00, 0x31 
[20201003 22:09:24.102 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.103 WEST] [ozw.library] [info]: Info - Node: 131 Response RTT 87 Average Response RTT 61 
[20201003 22:09:24.103 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.103 WEST] [ozw.library] [debug]: Detail - Node: 131 Value Updated: old value=0, new value=0, type=bitset 
[20201003 22:09:24.103 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.104 WEST] [ozw.library] [debug]: Detail - Node: 131 Changes to this value are not verified 
[20201003 22:09:24.104 WEST] [ozw.logging] [debug]: popping Log Mesages 
[20201003 22:09:24.105 WEST] [ozw.daemon] [warning]: ============================= 
[20201003 22:09:24.105 WEST] [ozw.daemon] [warning]: CRASH!!! - Dumping Backtrace: 
[20201003 22:09:24.105 WEST] [ozw.daemon] [warning]: ============================= 
[20201003 22:09:24.105 WEST] [ozw.daemon] [warning]: #1  0x00007fe2b8eda27d sp=0x00007fe2b5ec5c80 sigwaitinfo + 0x8 
[20201003 22:09:24.105 WEST] [ozw.daemon] [warning]: #2  0xb5ec627000307001 sp=0x00007fe2b5ec5c90  + 0x8 
[20201003 22:09:24.105 WEST] [default] [warning]: Exiting.... 
1601759364: Socket error on client qt-openzwave-1, disconnecting.
In exit
Terminating child 557
Terminating child 558
Process Process-2:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 691, in top_new_client
    client = self.do_handshake(startsock, address)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 619, in do_handshake
    self.RequestHandlerClass(retsock, address, self)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 99, in __init__
    SimpleHTTPRequestHandler.__init__(self, req, addr, server)
  File "/usr/lib/python3.8/http/server.py", line 647, in __init__
    super().__init__(*args, **kwargs)
  File "/usr/lib/python3.8/socketserver.py", line 720, in __init__
    self.handle()
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 315, in handle
    SimpleHTTPRequestHandler.handle(self)
  File "/usr/lib/python3.8/http/server.py", line 429, in handle
    self.handle_one_request()
  File "/usr/lib/python3.8/site-packages/websockify/websocketserver.py", line 47, in handle_one_request
    super(WebSocketRequestHandlerMixIn, self).handle_one_request()
  File "/usr/lib/python3.8/http/server.py", line 395, in handle_one_request
    self.raw_requestline = self.rfile.readline(65537)
  File "/usr/lib/python3.8/socket.py", line 669, in readinto
    return self._sock.recv_into(b)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 683, in do_SIGTERM
    self.terminate()
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 656, in terminate
    raise self.Terminate()
websockify.websockifyserver.WebSockifyServer.Terminate
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 691, in top_new_client
    client = self.do_handshake(startsock, address)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 619, in do_handshake
    self.RequestHandlerClass(retsock, address, self)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 99, in __init__
    SimpleHTTPRequestHandler.__init__(self, req, addr, server)
  File "/usr/lib/python3.8/http/server.py", line 647, in __init__
    super().__init__(*args, **kwargs)
  File "/usr/lib/python3.8/socketserver.py", line 720, in __init__
    self.handle()
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 315, in handle
    SimpleHTTPRequestHandler.handle(self)
  File "/usr/lib/python3.8/http/server.py", line 429, in handle
    self.handle_one_request()
  File "/usr/lib/python3.8/site-packages/websockify/websocketserver.py", line 47, in handle_one_request
    super(WebSocketRequestHandlerMixIn, self).handle_one_request()
  File "/usr/lib/python3.8/http/server.py", line 395, in handle_one_request
    self.raw_requestline = self.rfile.readline(65537)
  File "/usr/lib/python3.8/socket.py", line 669, in readinto
    return self._sock.recv_into(b)
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 683, in do_SIGTERM
    self.terminate()
  File "/usr/lib/python3.8/site-packages/websockify/websockifyserver.py", line 656, in terminate
    raise self.Terminate()
websockify.websockifyserver.WebSockifyServer.Terminate
[cont-finish.d] executing container finish scripts...
[cont-finish.d] mqtt.sh: executing... 
1601759364: mosquitto version 1.6.8 terminating
1601759364: Saving in-memory database to /data/mosquitto.db.
[22:09:24] INFO: �[32mEnsure upstream MQTT server has the correct OZW status�[0m
[cont-finish.d] mqtt.sh: exited 0.
[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.

Not sure if related, but node 131 is a Aeotec Multisensor.

@abmantis abmantis changed the title Crash during startup Crash during startup v0.5.2 Oct 3, 2020
@abmantis
Copy link
Author

abmantis commented Oct 3, 2020

Maybe related or duplicate of #129
Seems like the same issue, also with aeotec multisensor.

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

1 participant