search

OpenZWave / qt-openzwave

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

Crash when doing "removefailednode" #157

Closed perosb closed 2 years ago

perosb commented 3 years ago

Tried to remove a failed node using the "removefailednode" command which makes ozw crash. It looks like the noed was somewhat removed, but it still shows up in mqtt after restart but with 0 topics.


2020-08-20 15:09:58.412308553  [20200820 15:09:58.411 UTC] [ozw.library] [debug]: Detail - Node: 87 Queuing (Controller) Remove Failed Node 
2020-08-20 15:09:58.413030476  [20200820 15:09:58.412 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.423141728  [20200820 15:09:58.422 UTC] [ozw.library] [info]: Info - Node: 0 ControllerCommand_RemoveFailedNode 
2020-08-20 15:09:58.427547070  [20200820 15:09:58.422 UTC] [ozw.mqtt.commands] [info]: Processed Message for  "removefailednode" :  "{\"node\": 87}" 
2020-08-20 15:09:58.427592018  [20200820 15:09:58.423 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.433501676  [20200820 15:09:58.433 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) ControllerCommand_RemoveFailedNode: 0x01, 0x05, 0x00, 0x61, 0x57, 0x74, 0xb8 
2020-08-20 15:09:58.433678186  [20200820 15:09:58.433 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.439102794  [20200820 15:09:58.438 UTC] [ozw.library] [debug]: Detail - Node: 87 Notification: RemoveFailedNode ControllerCommand - Starting 
2020-08-20 15:09:58.439626281  [20200820 15:09:58.439 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.445264690  [20200820 15:09:58.444 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x74, Expected Reply=0x61) - ControllerCommand_RemoveFailedNode: 0x01, 0x05, 0x00, 0x61, 0x57, 0x74, 0xb8 
2020-08-20 15:09:58.445566824  [20200820 15:09:58.445 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand  5 1 0 Thread:  0x73c76010 
2020-08-20 15:09:58.445973124  [20200820 15:09:58.445 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.446723068  [20200820 15:09:58.445 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 87 NotificationTypes::Ctrl_Cmd_RemoveFailedNode NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 
2020-08-20 15:09:58.451523044  [20200820 15:09:58.451 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
2020-08-20 15:09:58.451808460  [20200820 15:09:58.451 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.466610469  [20200820 15:09:58.466 UTC] [ozw.library] [debug]: Detail - Node: 255   Received: 0x01, 0x04, 0x01, 0x61, 0x00, 0x9b 
2020-08-20 15:09:58.466881301  [20200820 15:09:58.466 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.472542575  [20200820 15:09:58.472 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_REMOVE_FAILED_NODE_ID - Command in progress 
2020-08-20 15:09:58.472793303  [20200820 15:09:58.472 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.479726445  [20200820 15:09:58.479 UTC] [ozw.library] [debug]: Detail - Node: 255   Expected reply was received 
2020-08-20 15:09:58.480398057  [20200820 15:09:58.479 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.487205523  [20200820 15:09:58.486 UTC] [ozw.library] [debug]: Detail - Node: 87 Notification: RemoveFailedNode ControllerCommand - InProgress 
2020-08-20 15:09:58.487609896  [20200820 15:09:58.487 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:09:58.494324185  [20200820 15:09:58.494 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand  5 6 0 Thread:  0x73c76010 
2020-08-20 15:09:58.494739495  [20200820 15:09:58.494 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 87 NotificationTypes::Ctrl_Cmd_RemoveFailedNode NotificationTypes::Ctrl_State_InProgress NotificationTypes::Ctrl_Error_None 
2020-08-20 15:10:08.458653426  [20200820 15:10:08.458 UTC] [ozw.library] [critical]: Error - Node: 255 ERROR: Dropping command, expected response not received after 1 attempt(s). Command: "ControllerCommand_RemoveFailedNode: 0x01, 0x05, 0x00, 0x61, 0x57, 0x74, 0xb8" 
2020-08-20 15:10:08.459325089  [20200820 15:10:08.458 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:10:08.468671084  [20200820 15:10:08.467 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 
2020-08-20 15:10:08.469097072  [20200820 15:10:08.468 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:10:08.476670159  [20200820 15:10:08.476 UTC] [ozw.library] [debug]: Detail - Node: 255 Notification: Notification - TimeOut 
2020-08-20 15:10:08.476894272  [20200820 15:10:08.476 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:10:08.482939971  [20200820 15:10:08.482 UTC] [ozw.library] [debug]: Detail - Node: 87 Notification: ControllerCommand - Error - Failed 
2020-08-20 15:10:08.483264761  [20200820 15:10:08.482 UTC] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread:  0x73c76010 
2020-08-20 15:10:08.483291116  [20200820 15:10:08.483 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:10:08.484858972  [20200820 15:10:08.484 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification 
2020-08-20 15:10:08.490177852  [20200820 15:10:08.489 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand  5 3 10 Thread:  0x73c76010 
2020-08-20 15:10:08.490884880  [20200820 15:10:08.490 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 87 NotificationTypes::Ctrl_Cmd_RemoveFailedNode NotificationTypes::Ctrl_State_Error NotificationTypes::Ctrl_Error_Failed 
2020-08-20 15:10:28.185430556  [20200820 15:10:28.185 UTC] [ozw.mqtt.publisher] [debug]: "Thu Aug 20 15:10:28 2020 PingResponse\n" 
2020-08-20 15:10:33.205269901  [20200820 15:10:33.204 UTC] [ozw.library] [debug]: Detail - Node: 0   Received: 0x01, 0x05, 0x00, 0x61, 0x74, 0x01, 0xee 
2020-08-20 15:10:33.206046928  [20200820 15:10:33.205 UTC] [ozw.logging] [debug]: popping Log Mesages 
2020-08-20 15:10:33.372807659  [20200820 15:10:33.372 UTC] [ozw.daemon] [warning]: ============================= 
2020-08-20 15:10:33.373115939  [20200820 15:10:33.372 UTC] [ozw.daemon] [warning]: CRASH!!! - Dumping Backtrace: 
2020-08-20 15:10:33.373576666  [20200820 15:10:33.373 UTC] [ozw.daemon] [warning]: ============================= 
2020-08-20 15:10:33.400259762  [20200820 15:10:33.399 UTC] [ozw.daemon] [warning]: #1  0x000000000052371f sp=0x0000000073c59f58 dumpCallback(google_breakpad::MinidumpDescriptor const&, void*, bool) + 0x12 
2020-08-20 15:10:33.401898660  [20200820 15:10:33.401 UTC] [ozw.daemon] [warning]: #2  0x0000000000533c7d sp=0x0000000073c5a170 google_breakpad::ExceptionHandler::GenerateDump(google_breakpad::ExceptionHandler::CrashContext*) + 0x1b0 
2020-08-20 15:10:33.403449538  [20200820 15:10:33.403 UTC] [ozw.daemon] [warning]: #3  0x0000000000533f57 sp=0x0000000073c5a1b8 google_breakpad::ExceptionHandler::SignalHandler(int, siginfo_t*, void*) + 0x76 
2020-08-20 15:10:33.404995311  [20200820 15:10:33.404 UTC] [ozw.daemon] [warning]: #4  0x0000000076544cb1 sp=0x0000000073c5a268 __default_sa_restorer + 0x10 
2020-08-20 15:10:33.416358796  [20200820 15:10:33.416 UTC] [ozw.daemon] [warning]: #5  0x0000000076eebc56 sp=0x0000000073c5a5e0 OpenZWave::Driver::HandleRemoveFailedNodeRequest(unsigned char*) + 0x49 
2020-08-20 15:10:33.418669149  [20200820 15:10:33.418 UTC] [ozw.daemon] [warning]: #6  0x0000000076eee223 sp=0x0000000073c5a5f0 OpenZWave::Driver::ProcessMsg(unsigned char*, unsigned char) + 0x6d6 
2020-08-20 15:10:33.420707368  [20200820 15:10:33.420 UTC] [ozw.daemon] [warning]: #7  0x0000000076eeec53 sp=0x0000000073c5a728 OpenZWave::Driver::ReadMsg() + 0x37a 
2020-08-20 15:10:33.422891680  [20200820 15:10:33.422 UTC] [ozw.daemon] [warning]: #8  0x0000000076eefb77 sp=0x0000000073c5ab88 OpenZWave::Driver::DriverThreadProc(OpenZWave::Internal::Platform::Event*) + 0x19e 
2020-08-20 15:10:33.424974639  [20200820 15:10:33.424 UTC] [ozw.daemon] [warning]: #9  0x0000000076ecfff5 sp=0x0000000073c5ac10 OpenZWave::Internal::Platform::ThreadImpl::Run() + 0x10 
2020-08-20 15:10:33.426993118  [20200820 15:10:33.426 UTC] [ozw.daemon] [warning]: #10 0x0000000076ed000b sp=0x0000000073c5ac18 OpenZWave::Internal::Platform::ThreadImpl::ThreadProc(void*) + 0x6 
2020-08-20 15:10:33.428540767  [20200820 15:10:33.428 UTC] [ozw.daemon] [warning]: #11 0x00000000767cdbbf sp=0x0000000073c5ac20 start_thread + 0x92 
2020-08-20 15:10:33.429266440  [20200820 15:10:33.428 UTC] [ozw.daemon] [warning]: dumpCallback Succeeded:  true  at  /opt/ozw/config/crashes//0e4d7f7f-8562-45af-0c8555a1-a6c65b2a.dmp 
2020-08-20 15:10:33.429515866  [20200820 15:10:33.429 UTC] [ozw.daemon] [warning]: Uploading MiniDump to  https://sentry.io/api/1868130/minidump/?sentry_key=e086ba93030843199aab391947d205da 
2020-08-20 15:10:34.579505133  [20200820 15:10:34.579 UTC] [ozw.daemon] [warning]: Uploaded Crash minidump With ID:  c1bfd201-4491-4c00-a7a4-0dcef39bd9c7 
2020-08-20 15:11:19.146540861  [20200820 15:11:19.145 UTC] [ozw.daemon] [debug]: Checking  "/opt/ozw/config"  for manufacturer_specific.xml 
2020-08-20 15:11:19.156604665  [20200820 15:11:19.146 UTC] [ozw.daemon] [debug]: Checking  "/opt/ozw/config"  for options.xml 
2020-08-20 15:11:19.156631957  [20200820 15:11:19.146 UTC] [ozw.daemon] [info]: DBPath:  "/opt/ozw/config/" 
2020-08-20 15:11:19.156647634  [20200820 15:11:19.147 UTC] [ozw.daemon] [info]: userPath:  "/opt/ozw/config/" 
2020-08-20 15:11:19.179833612  [20200820 15:11:19.179 UTC] [ozw.daemon] [info]: Network Key Specified in Enviroment is Valid 
2020-08-20 15:11:19.180203402  [20200820 15:11:19.179 UTC] [ozw.daemon] [info]: Didn't Find Network Key File. Skipping 
2020-08-20 15:11:19.180309183  [20200820 15:11:19.180 UTC] [ozw.daemon] [info]: We Have what appears to be a valid Network Key - Passing to OZW 
2020-08-20 15:11:19.180621681  [20200820 15:11:19.180 UTC] [ozw.daemon] [info]: Didn't Find Auth Key File. Skipping 
2020-08-20 15:11:19.182103028  [20200820 15:11:19.181 UTC] [ozw.manager] [debug]: Database Path:  "/opt/ozw/config/"  User Path "/opt/ozw/config/" 
2020-08-20 15:11:19.208383262  [20200820 15:11:19.207 UTC] [ozw.manager] [debug]: Models Created 
2020-08-20 15:11:19.225238542  [20200820 15:11:19.224 UTC] [qt.remoteobjects] [warning]:  Tried to register QRemoteObjectRootSource twice "QTOZWLog" 
2020-08-20 15:11:19.225593853  [20200820 15:11:19.225 UTC] [ozw.manager] [debug]: QTOZWManager Ready! 
2020-08-20 15:11:19.225878904  [20200820 15:11:19.225 UTC] [ozw.daemon] [debug]: Ready 
2020-08-20 15:11:19.226578848  [20200820 15:11:19.225 UTC] [ozw.manager] [debug]: QTOZWLog Ready! 
2020-08-20 15:11:19.227155929  [20200820 15:11:19.226 UTC] [ozw.manager] [debug]: QTOZWOptions Ready!