OpenZWave / qt-openzwave

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

Unable to use/apply network-key/encryption to device #183

Closed jmgiaever closed 3 years ago

jmgiaever commented 3 years ago

Hi,

Sorry. Not sure if my subject is good, but I'm not sure what is wrong as I'm not able to add secure nodes with ozwdaemon. My stick is an Aeotec Z Stick Gen 5 (not the revised version). I guess it's something that is not applied to the stick upon boot.

I'm booting with the following command:

sudo docker run -it 
    --security-opt seccomp=unconfined 
    --device=/dev/ttyAMC0 
    -v $PWD/ozw:/opt/ozw/config 
    -e MQTT_SERVER="192.168.33.19" 
    -e USB_PATH=/dev/ttyAMC0 
    -p 1983:1983 
openzwave/ozwdaemon:latest

It boots successfully, with the following output:

2020-11-07 20:42:15.272485167 [20201107 20:42:15.271 UTC] [ozw.daemon] [debug]: Checking "/opt/ozw/config" for manufacturer_specific.xml 2020-11-07 20:42:15.272930638 [20201107 20:42:15.272 UTC] [ozw.daemon] [warning]: Configuration Database Does Not Exist - Copying Database to Location "/opt/ozw/config/" 2020-11-07 20:42:15.273568298 [20201107 20:42:15.273 UTC] [ozw.database] [debug]: Testing "/run/s6/services/ozwdaemon/qt-openzwavedatabase.rcc" 2020-11-07 20:42:15.274275438 [20201107 20:42:15.273 UTC] [ozw.database] [debug]: Testing "/opt/qt/5.12.9/qt-openzwavedatabase.rcc" 2020-11-07 20:42:15.275033516 [20201107 20:42:15.274 UTC] [ozw.database] [info]: Found qt-openzwavedatabase.rcc at "/opt/qt/5.12.9/qt-openzwavedatabase.rcc" 2020-11-07 20:42:15.276879100 [20201107 20:42:15.276 UTC] [ozw.database] [debug]: copyConfigDatabase: Copying "ge/receptacle.xml" to "/opt/ozw/config/ge/receptacle.xml" [.... removed a lot of these lines ....] 2020-11-07 20:42:16.749033472 [20201107 20:42:16.748 UTC] [ozw.daemon] [debug]: Checking "/opt/ozw/config" for options.xml 2020-11-07 20:42:16.749265036 [20201107 20:42:16.749 UTC] [ozw.daemon] [warning]: User Configuration Path Does Not Exist - Copying Config Files to Location "/opt/ozw/config/" 2020-11-07 20:42:16.749487537 [20201107 20:42:16.749 UTC] [ozw.database] [debug]: Testing "/run/s6/services/ozwdaemon/qt-openzwavedatabase.rcc" 2020-11-07 20:42:16.749803998 [20201107 20:42:16.749 UTC] [ozw.database] [debug]: Testing "/opt/qt/5.12.9/qt-openzwavedatabase.rcc" 2020-11-07 20:42:16.750150666 [20201107 20:42:16.749 UTC] [ozw.database] [info]: Found qt-openzwavedatabase.rcc at "/opt/qt/5.12.9/qt-openzwavedatabase.rcc" 2020-11-07 20:42:16.801081080 [20201107 20:42:16.800 UTC] [ozw.database] [debug]: copyUserDatabase: Copying "options.xml" to "/opt/ozw/config/options.xml" 2020-11-07 20:42:16.804915062 [20201107 20:42:16.804 UTC] [ozw.daemon] [info]: DBPath: "/opt/ozw/config/" 2020-11-07 20:42:16.805072198 [20201107 20:42:16.804 UTC] [ozw.daemon] [info]: userPath: "/opt/ozw/config/" 2020-11-07 20:42:16.806522936 [20201107 20:42:16.806 UTC] [ozw.daemon] [warning]: Network Key Specified in Enviroment is Invalid 2020-11-07 20:42:16.806933095 [20201107 20:42:16.806 UTC] [ozw.daemon] [info]: Didn't Find Network Key File. Skipping 2020-11-07 20:42:16.807154919 [20201107 20:42:16.806 UTC] [ozw.daemon] [info]: Didn't Find Auth Key File. Skipping 2020-11-07 20:42:16.835185923 [20201107 20:42:16.834 UTC] [ozw.manager] [debug]: Database Path: "/opt/ozw/config/" User Path "/opt/ozw/config/" 2020-11-07 20:42:16.847834072 [20201107 20:42:16.847 UTC] [ozw.manager] [debug]: Models Created 2020-11-07 20:42:16.890045683 [20201107 20:42:16.889 UTC] [qt.remoteobjects] [warning]: Tried to register QRemoteObjectRootSource twice "QTOZWLog" 2020-11-07 20:42:16.890511832 [20201107 20:42:16.890 UTC] [ozw.manager] [debug]: QTOZWManager Ready! 2020-11-07 20:42:16.890889699 [20201107 20:42:16.890 UTC] [ozw.daemon] [debug]: Ready 2020-11-07 20:42:16.891324701 [20201107 20:42:16.890 UTC] [ozw.manager] [debug]: QTOZWLog Ready! 2020-11-07 20:42:16.891753246 [20201107 20:42:16.891 UTC] [ozw.manager] [debug]: QTOZWOptions Ready! 2020-11-07 20:42:16.892269134 [20201107 20:42:16.891 UTC] [ozw.daemon] [info]: Staring "ozwdaemon" Version: "0.1.179" 2020-11-07 20:42:16.893054451 [20201107 20:42:16.892 UTC] [ozw.daemon] [info]: OpenZWave Version: "1.6.1520" 2020-11-07 20:42:16.893404193 [20201107 20:42:16.893 UTC] [ozw.daemon] [info]: QT-OpenZWave Version: "1.2.0" 2020-11-07 20:42:16.893790497 [20201107 20:42:16.893 UTC] [ozw.daemon] [info]: QT Version: 5.12.9 2020-11-07 20:42:16.894667638 [20201107 20:42:16.894 UTC] [ozw.mqtt.commands] [debug]: Registering Command "ping" 2020-11-07 20:42:16.895065609 [20201107 20:42:16.894 UTC] [ozw.mqtt.commands] [debug]: Registering Command "open" 2020-11-07 20:42:16.895507487 [20201107 20:42:16.895 UTC] [ozw.mqtt.commands] [debug]: Registering Command "close" 2020-11-07 20:42:16.895846760 [20201107 20:42:16.895 UTC] [ozw.mqtt.commands] [debug]: Registering Command "refreshnodeinfo" 2020-11-07 20:42:16.896027907 [20201107 20:42:16.895 UTC] [ozw.mqtt.commands] [debug]: Registering Command "requestnodestate" 2020-11-07 20:42:16.896220877 [20201107 20:42:16.896 UTC] [ozw.mqtt.commands] [debug]: Registering Command "requestnodedynamic" 2020-11-07 20:42:16.896399315 [20201107 20:42:16.896 UTC] [ozw.mqtt.commands] [debug]: Registering Command "requestconfigparam" 2020-11-07 20:42:16.896581973 [20201107 20:42:16.896 UTC] [ozw.mqtt.commands] [debug]: Registering Command "requestallconfigparam" 2020-11-07 20:42:16.896769005 [20201107 20:42:16.896 UTC] [ozw.mqtt.commands] [debug]: Registering Command "softresetcontroller" 2020-11-07 20:42:16.896948954 [20201107 20:42:16.896 UTC] [ozw.mqtt.commands] [debug]: Registering Command "hardresetcontroller" 2020-11-07 20:42:16.897134632 [20201107 20:42:16.896 UTC] [ozw.mqtt.commands] [debug]: Registering Command "cancelcontrollercommand" 2020-11-07 20:42:16.897316352 [20201107 20:42:16.897 UTC] [ozw.mqtt.commands] [debug]: Registering Command "testnetworknode" 2020-11-07 20:42:16.897494635 [20201107 20:42:16.897 UTC] [ozw.mqtt.commands] [debug]: Registering Command "testnetwork" 2020-11-07 20:42:16.897679844 [20201107 20:42:16.897 UTC] [ozw.mqtt.commands] [debug]: Registering Command "healnetworknode" 2020-11-07 20:42:16.897863491 [20201107 20:42:16.897 UTC] [ozw.mqtt.commands] [debug]: Registering Command "healnetwork" 2020-11-07 20:42:16.898042971 [20201107 20:42:16.897 UTC] [ozw.mqtt.commands] [debug]: Registering Command "addnode" 2020-11-07 20:42:16.898233962 [20201107 20:42:16.898 UTC] [ozw.mqtt.commands] [debug]: Registering Command "removenode" 2020-11-07 20:42:16.898412453 [20201107 20:42:16.898 UTC] [ozw.mqtt.commands] [debug]: Registering Command "removefailednode" 2020-11-07 20:42:16.898592297 [20201107 20:42:16.898 UTC] [ozw.mqtt.commands] [debug]: Registering Command "hasnodefailed" 2020-11-07 20:42:16.898779330 [20201107 20:42:16.898 UTC] [ozw.mqtt.commands] [debug]: Registering Command "requestnodeneighborupdate" 2020-11-07 20:42:16.898959279 [20201107 20:42:16.898 UTC] [ozw.mqtt.commands] [debug]: Registering Command "assignreturnroute" 2020-11-07 20:42:16.899146207 [20201107 20:42:16.898 UTC] [ozw.mqtt.commands] [debug]: Registering Command "deleteallreturnroute" 2020-11-07 20:42:16.899327614 [20201107 20:42:16.899 UTC] [ozw.mqtt.commands] [debug]: Registering Command "sendnodeinformation" 2020-11-07 20:42:16.899536522 [20201107 20:42:16.899 UTC] [ozw.mqtt.commands] [debug]: Registering Command "replacefailednode" 2020-11-07 20:42:16.899730065 [20201107 20:42:16.899 UTC] [ozw.mqtt.commands] [debug]: Registering Command "requestnetworkupdate" 2020-11-07 20:42:16.899905951 [20201107 20:42:16.899 UTC] [ozw.mqtt.commands] [debug]: Registering Command "isnodefailed" 2020-11-07 20:42:16.900086942 [20201107 20:42:16.899 UTC] [ozw.mqtt.commands] [debug]: Registering Command "checklatestconfigfilerevision" 2020-11-07 20:42:16.900272620 [20201107 20:42:16.900 UTC] [ozw.mqtt.commands] [debug]: Registering Command "checklatestmfsrevision" 2020-11-07 20:42:16.900455590 [20201107 20:42:16.900 UTC] [ozw.mqtt.commands] [debug]: Registering Command "downloadlatestconfigfilerevision" 2020-11-07 20:42:16.900640539 [20201107 20:42:16.900 UTC] [ozw.mqtt.commands] [debug]: Registering Command "downloadlatestmfsrevision" 2020-11-07 20:42:16.900820592 [20201107 20:42:16.900 UTC] [ozw.mqtt.commands] [debug]: Registering Command "setvalue" 2020-11-07 20:42:16.901022312 [20201107 20:42:16.900 UTC] [ozw.mqtt.commands] [debug]: Registering Command "getpollinterval" 2020-11-07 20:42:16.901205595 [20201107 20:42:16.901 UTC] [ozw.mqtt.commands] [debug]: Registering Command "setpollinterval" 2020-11-07 20:42:16.901391690 [20201107 20:42:16.901 UTC] [ozw.mqtt.commands] [debug]: Registering Command "syncronisenodeneighbors" 2020-11-07 20:42:16.901571378 [20201107 20:42:16.901 UTC] [ozw.mqtt.commands] [debug]: Registering Command "enablepoll" 2020-11-07 20:42:16.901762577 [20201107 20:42:16.901 UTC] [ozw.mqtt.commands] [debug]: Registering Command "disablepoll" 2020-11-07 20:42:16.901944193 [20201107 20:42:16.901 UTC] [ozw.mqtt.commands] [debug]: Registering Command "refreshvalue" 2020-11-07 20:42:16.902124923 [20201107 20:42:16.901 UTC] [ozw.mqtt.commands] [debug]: Registering Command "addassociation" 2020-11-07 20:42:16.902305185 [20201107 20:42:16.902 UTC] [ozw.mqtt.commands] [debug]: Registering Command "removeassociation" 2020-11-07 20:42:16.903123471 [20201107 20:42:16.902 UTC] [ozw.mqtt.publisher] [debug]: MQTT State Change "Connecting" 2020-11-07 20:42:16.903292899 [20201107 20:42:16.903 UTC] [ozw.mqtt.publisher] [info]: MQTT Client Connecting 2020-11-07 20:42:16.904512646 [20201107 20:42:16.904 UTC] [ozw.daemon] [info]: Using BreakPad - Crash Directory: "/opt/ozw/config/crashes/" 2020-11-07 20:42:16.907288444 [20201107 20:42:16.906 UTC] [ozw.library] [debug]: Always - Node: 0 OpenZwave Version 1.6-1520-g893e076a Starting Up 2020-11-07 20:42:16.931685780 [20201107 20:42:16.931 UTC] [ozw.library] [info]: Info - Node: 0 Loading Localization File /opt/ozw/config/Localization.xml 2020-11-07 20:42:16.937345241 [20201107 20:42:16.936 UTC] [ozw.library] [info]: Info - Node: 0 Loaded /opt/ozw/config/Localization.xml With Revision 12 2020-11-07 20:42:16.941315578 [20201107 20:42:16.940 UTC] [ozw.library] [debug]: Always - Node: 0 Using Language Localization
2020-11-07 20:42:16.949365314 [20201107 20:42:16.948 UTC] [ozw.library] [info]: Info - Node: 0 Loading NotificationCCTypes File /opt/ozw/config/NotificationCCTypes.xml 2020-11-07 20:42:16.950634020 [20201107 20:42:16.950 UTC] [ozw.library] [info]: Info - Node: 0 Loaded /opt/ozw/config/NotificationCCTypes.xml With Revision 11 2020-11-07 20:42:16.954936650 [20201107 20:42:16.954 UTC] [ozw.library] [info]: Info - Node: 0 Loading SensorMultiLevelCCTypes File /opt/ozw/config/SensorMultiLevelCCTypes.xml 2020-11-07 20:42:16.955931188 [20201107 20:42:16.955 UTC] [ozw.library] [info]: Info - Node: 0 Loaded /opt/ozw/config/SensorMultiLevelCCTypes.xml With Revision 4 2020-11-07 20:42:16.956690828 [20201107 20:42:16.956 UTC] [ozw.manager] [debug]: OpenZWave Manager Instance Created 2020-11-07 20:42:16.956887548 [20201107 20:42:16.956 UTC] [ozw.manager] [debug]: OpenZWave Watcher Registered 2020-11-07 20:42:16.957129111 [20201107 20:42:16.956 UTC] [ozw.manager] [debug]: Notification Signals Setup 2020-11-07 20:42:16.961987006 [20201107 20:42:16.961 UTC] [ozw.library] [info]: Info - Node: 0 Setting Up Provided Network Key for Secure Communications 2020-11-07 20:42:16.962326956 [20201107 20:42:16.962 UTC] [ozw.library] [warning]: Warning - Node: 0 Failed - Network Key Not Set 2020-11-07 20:42:16.995952577 [20201107 20:42:16.995 UTC] [ozw.library] [info]: Info - Node: 0 Manufacturer_Specific.xml file Revision is 129 2020-11-07 20:42:18.131208153 [20201107 20:42:18.130 UTC] [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 2020-11-07 20:42:18.694163327 [20201107 20:42:18.693 UTC] [ozw.library] [info]: Info - Node: 0 Queuing Lookup on mfs.db.openzwave.com for Node 0 2020-11-07 20:42:18.695080468 [20201107 20:42:18.694 UTC] [ozw.library] [info]: Info - Node: 0 Opening controller /dev/ttyACM0 2020-11-07 20:42:18.695734430 [20201107 20:42:18.695 UTC] [ozw.library] [info]: Info - Node: 0 Starting DNSThread 2020-11-07 20:42:18.696102401 [20201107 20:42:18.695 UTC] [ozw.library] [info]: Info - Node: 0 mgr, Added driver for controller /dev/ttyACM0 2020-11-07 20:42:18.696465893 [20201107 20:42:18.696 UTC] [ozw.manager] [debug]: AddDriver Completed 2020-11-07 20:42:18.696661623 [20201107 20:42:18.696 UTC] [ozw.library] [info]: Info - Node: 0 Timer: thread starting 2020-11-07 20:42:18.697031053 [20201107 20:42:18.696 UTC] [ozw.library] [debug]: Detail - Node: 0 Timer: waiting with timeout -1 ms 2020-11-07 20:42:18.697404961 [20201107 20:42:18.697 UTC] [ozw.library] [info]: Info - Node: 0 LookupTxT Checking mfs.db.openzwave.com 2020-11-07 20:42:18.697848818 [20201107 20:42:18.697 UTC] [ozw.library] [info]: Info - Node: 0 Trying to open serial port /dev/ttyACM0 (attempt 1) 2020-11-07 20:42:18.700219666 [20201107 20:42:18.699 UTC] [ozw.library] [info]: Info - Node: 0 Serial port /dev/ttyACM0 opened (attempt 1) 2020-11-07 20:42:18.701310714 [20201107 20:42:18.700 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9 2020-11-07 20:42:18.727030140 [20201107 20:42:18.726 UTC] [ozw.library] [info]: Info - Node: 0 Lookup for mfs.db.openzwave.com returned 129 2020-11-07 20:42:18.879888043 [20201107 20:42:18.879 UTC] [ozw.mqtt.publisher] [debug]: MQTT State Change "Connected" 2020-11-07 20:42:18.880063565 [20201107 20:42:18.879 UTC] [ozw.mqtt.publisher] [info]: MQTT Client Connected 2020-11-07 20:42:18.880524454 [20201107 20:42:18.880 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "addassociation" 2020-11-07 20:42:18.880851956 [20201107 20:42:18.880 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/addassociation/") 2020-11-07 20:42:18.881076905 [20201107 20:42:18.880 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "addnode" 2020-11-07 20:42:18.881312792 [20201107 20:42:18.881 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/addnode/") 2020-11-07 20:42:18.881534772 [20201107 20:42:18.881 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "assignreturnroute" 2020-11-07 20:42:18.881792430 [20201107 20:42:18.881 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/assignreturnroute/") 2020-11-07 20:42:18.881996494 [20201107 20:42:18.881 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "cancelcontrollercommand" 2020-11-07 20:42:18.882222589 [20201107 20:42:18.882 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/cancelcontrollercommand/") 2020-11-07 20:42:18.882495768 [20201107 20:42:18.882 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "checklatestconfigfilerevision" 2020-11-07 20:42:18.882737748 [20201107 20:42:18.882 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/checklatestconfigfilerevision/") 2020-11-07 20:42:18.882940093 [20201107 20:42:18.882 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "checklatestmfsrevision" 2020-11-07 20:42:18.883173792 [20201107 20:42:18.882 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/checklatestmfsrevision/") 2020-11-07 20:42:18.883434367 [20201107 20:42:18.883 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "close" 2020-11-07 20:42:18.883705410 [20201107 20:42:18.883 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/close/") 2020-11-07 20:42:18.883904474 [20201107 20:42:18.883 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "deleteallreturnroute" 2020-11-07 20:42:18.884196038 [20201107 20:42:18.883 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/deleteallreturnroute/") 2020-11-07 20:42:18.884394685 [20201107 20:42:18.884 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "disablepoll" 2020-11-07 20:42:18.884642603 [20201107 20:42:18.884 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/disablepoll/") 2020-11-07 20:42:18.884839792 [20201107 20:42:18.884 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "downloadlatestconfigfilerevision" 2020-11-07 20:42:18.885074169 [20201107 20:42:18.884 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/downloadlatestconfigfilerevision/") 2020-11-07 20:42:18.885291149 [20201107 20:42:18.885 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "downloadlatestmfsrevision" 2020-11-07 20:42:18.885535473 [20201107 20:42:18.885 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/downloadlatestmfsrevision/") 2020-11-07 20:42:18.885737610 [20201107 20:42:18.885 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "enablepoll" 2020-11-07 20:42:18.885979539 [20201107 20:42:18.885 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/enablepoll/") 2020-11-07 20:42:18.886173238 [20201107 20:42:18.885 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "getpollinterval" 2020-11-07 20:42:18.886432198 [20201107 20:42:18.886 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/getpollinterval/") 2020-11-07 20:42:18.886648813 [20201107 20:42:18.886 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "hardresetcontroller" 2020-11-07 20:42:18.886866367 [20201107 20:42:18.886 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/hardresetcontroller/") 2020-11-07 20:42:18.887062462 [20201107 20:42:18.886 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "hasnodefailed" 2020-11-07 20:42:18.887295328 [20201107 20:42:18.887 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/hasnodefailed/") 2020-11-07 20:42:18.887545017 [20201107 20:42:18.887 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "healnetwork" 2020-11-07 20:42:18.887795539 [20201107 20:42:18.887 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/healnetwork/") 2020-11-07 20:42:18.887998457 [20201107 20:42:18.887 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "healnetworknode" 2020-11-07 20:42:18.888247417 [20201107 20:42:18.888 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/healnetworknode/") 2020-11-07 20:42:18.888440439 [20201107 20:42:18.888 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "isnodefailed" 2020-11-07 20:42:18.888680388 [20201107 20:42:18.888 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/isnodefailed/") 2020-11-07 20:42:18.888888150 [20201107 20:42:18.888 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "open" 2020-11-07 20:42:18.889122214 [20201107 20:42:18.888 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/open/") 2020-11-07 20:42:18.889337736 [20201107 20:42:18.889 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "ping" 2020-11-07 20:42:18.889574977 [20201107 20:42:18.889 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/ping/") 2020-11-07 20:42:18.889772947 [20201107 20:42:18.889 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "refreshnodeinfo" 2020-11-07 20:42:18.890000292 [20201107 20:42:18.889 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/refreshnodeinfo/") 2020-11-07 20:42:18.890199408 [20201107 20:42:18.890 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "refreshvalue" 2020-11-07 20:42:18.890437899 [20201107 20:42:18.890 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/refreshvalue/") 2020-11-07 20:42:18.890629567 [20201107 20:42:18.890 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "removeassociation" 2020-11-07 20:42:18.890858943 [20201107 20:42:18.890 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/removeassociation/") 2020-11-07 20:42:18.891061965 [20201107 20:42:18.890 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "removefailednode" 2020-11-07 20:42:18.891290821 [20201107 20:42:18.891 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/removefailednode/") 2020-11-07 20:42:18.891579104 [20201107 20:42:18.891 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "removenode" 2020-11-07 20:42:18.891824834 [20201107 20:42:18.891 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/removenode/") 2020-11-07 20:42:18.892016815 [20201107 20:42:18.891 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "replacefailednode" 2020-11-07 20:42:18.892244993 [20201107 20:42:18.892 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/replacefailednode/") 2020-11-07 20:42:18.892446453 [20201107 20:42:18.892 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "requestallconfigparam" 2020-11-07 20:42:18.892676610 [20201107 20:42:18.892 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/requestallconfigparam/") 2020-11-07 20:42:18.892871924 [20201107 20:42:18.892 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "requestconfigparam" 2020-11-07 20:42:18.893150207 [20201107 20:42:18.892 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/requestconfigparam/") 2020-11-07 20:42:18.893351823 [20201107 20:42:18.893 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "requestnetworkupdate" 2020-11-07 20:42:18.893595939 [20201107 20:42:18.893 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/requestnetworkupdate/") 2020-11-07 20:42:18.893793648 [20201107 20:42:18.893 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "requestnodedynamic" 2020-11-07 20:42:18.894028129 [20201107 20:42:18.893 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/requestnodedynamic/") 2020-11-07 20:42:18.894221463 [20201107 20:42:18.894 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "requestnodeneighborupdate" 2020-11-07 20:42:18.894450788 [20201107 20:42:18.894 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/requestnodeneighborupdate/") 2020-11-07 20:42:18.894645945 [20201107 20:42:18.894 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "requestnodestate" 2020-11-07 20:42:18.894876519 [20201107 20:42:18.894 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/requestnodestate/") 2020-11-07 20:42:18.895060427 [20201107 20:42:18.894 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "sendnodeinformation" 2020-11-07 20:42:18.895315064 [20201107 20:42:18.895 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/sendnodeinformation/") 2020-11-07 20:42:18.895560482 [20201107 20:42:18.895 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "setpollinterval" 2020-11-07 20:42:18.895797827 [20201107 20:42:18.895 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/setpollinterval/") 2020-11-07 20:42:18.895988766 [20201107 20:42:18.895 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "setvalue" 2020-11-07 20:42:18.896220486 [20201107 20:42:18.896 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/setvalue/") 2020-11-07 20:42:18.896420018 [20201107 20:42:18.896 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "softresetcontroller" 2020-11-07 20:42:18.896662155 [20201107 20:42:18.896 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/softresetcontroller/") 2020-11-07 20:42:18.896853458 [20201107 20:42:18.896 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "syncronisenodeneighbors" 2020-11-07 20:42:18.897116377 [20201107 20:42:18.896 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/syncronisenodeneighbors/") 2020-11-07 20:42:18.897306847 [20201107 20:42:18.897 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "testnetwork" 2020-11-07 20:42:18.897546223 [20201107 20:42:18.897 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/testnetwork/") 2020-11-07 20:42:18.897741224 [20201107 20:42:18.897 UTC] [ozw.mqtt.commands] [debug]: Creating Subscription for "testnetworknode" 2020-11-07 20:42:18.898035705 [20201107 20:42:18.897 UTC] [ozw.mqtt.commands] [debug]: Subscription Setup for QMqttTopicFilter("OpenZWave/1/command/testnetworknode/") 2020-11-07 20:42:18.906305547 [20201107 20:42:18.905 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/status/" 2020-11-07 20:42:18.910593177 [20201107 20:42:18.910 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/" 2020-11-07 20:42:18.911670736 [20201107 20:42:18.911 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/" 2020-11-07 20:42:18.912352615 [20201107 20:42:18.911 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/" 2020-11-07 20:42:18.912637668 [20201107 20:42:18.912 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/" 2020-11-07 20:42:18.913034181 [20201107 20:42:18.912 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/32/" 2020-11-07 20:42:18.913605070 [20201107 20:42:18.913 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/32/" 2020-11-07 20:42:18.914071375 [20201107 20:42:18.913 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/32/value/17301521/" 2020-11-07 20:42:18.914440231 [20201107 20:42:18.914 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/32/value/17301521/" 2020-11-07 20:42:18.915227945 [20201107 20:42:18.914 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/32/value/281474994012177/" 2020-11-07 20:42:18.915711593 [20201107 20:42:18.915 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/32/value/281474994012177/" 2020-11-07 20:42:18.916102794 [20201107 20:42:18.915 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/32/value/562949970722835/" 2020-11-07 20:42:18.916446337 [20201107 20:42:18.916 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/32/value/562949970722835/" 2020-11-07 20:42:18.916765193 [20201107 20:42:18.916 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/" 2020-11-07 20:42:18.917115508 [20201107 20:42:18.916 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/" 2020-11-07 20:42:18.917431239 [20201107 20:42:18.917 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/value/22799473140563988/" 2020-11-07 20:42:18.917788950 [20201107 20:42:18.917 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/value/22799473140563988/" 2020-11-07 20:42:18.918114056 [20201107 20:42:18.917 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/value/61924494903345172/" 2020-11-07 20:42:18.918480725 [20201107 20:42:18.918 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/value/61924494903345172/" 2020-11-07 20:42:18.918818487 [20201107 20:42:18.918 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/value/68116944390979604/" 2020-11-07 20:42:18.919216771 [20201107 20:42:18.918 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/value/68116944390979604/" 2020-11-07 20:42:18.919641825 [20201107 20:42:18.919 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/value/68398419367690259/" 2020-11-07 20:42:18.919987400 [20201107 20:42:18.919 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/value/68398419367690259/" 2020-11-07 20:42:18.920341778 [20201107 20:42:18.920 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/value/70931694158086164/" 2020-11-07 20:42:18.920683446 [20201107 20:42:18.920 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/value/70931694158086164/" 2020-11-07 20:42:18.921003604 [20201107 20:42:18.920 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/112/value/71776119088218131/" 2020-11-07 20:42:18.921336159 [20201107 20:42:18.921 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/112/value/71776119088218131/" 2020-11-07 20:42:18.921703609 [20201107 20:42:18.921 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/114/" 2020-11-07 20:42:18.922026579 [20201107 20:42:18.921 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/114/" 2020-11-07 20:42:18.922344029 [20201107 20:42:18.922 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/114/value/31227923/" 2020-11-07 20:42:18.922680073 [20201107 20:42:18.922 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/114/value/31227923/" 2020-11-07 20:42:18.923012679 [20201107 20:42:18.922 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/114/value/281475007938579/" 2020-11-07 20:42:18.923382056 [20201107 20:42:18.923 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/114/value/281475007938579/" 2020-11-07 20:42:18.923765861 [20201107 20:42:18.923 UTC] [ozw.mqtt.publisher] [debug]: Topics: "OpenZWave/1/node/1/instance/1/commandclass/114/value/562949984649235/" 2020-11-07 20:42:18.924143467 [20201107 20:42:18.923 UTC] [ozw.mqtt.publisher] [debug]: Removing Stale Topic/Msg: "OpenZWave/1/node/1/instance/1/commandclass/114/value/562949984649235/" 2020-11-07 20:42:19.286563727 [20201107 20:42:19.286 UTC] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/kwikset/916.jpg (Node 0) 2020-11-07 20:42:19.287729984 [20201107 20:42:19.287 UTC] [ozw.library] [info]: Info - Node: 0 Missing Picture /opt/ozw/config/images/kwikset/916.jpg - Starting Download 2020-11-07 20:42:19.288198164 [20201107 20:42:19.287 UTC] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/kwikset/916.jpg (/opt/ozw/config/images/kwikset/916.jpg) 2020-11-07 20:42:20.228215235 [20201107 20:42:20.227 UTC] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/shenzen_neo/ls03ch.jpg (Node 0) 2020-11-07 20:42:20.228788363 [20201107 20:42:20.228 UTC] [ozw.library] [info]: Info - Node: 0 Missing Picture /opt/ozw/config/images/shenzen_neo/ls03ch.jpg - Starting Download 2020-11-07 20:42:20.229171907 [20201107 20:42:20.228 UTC] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/shenzen_neo/ls03ch.jpg (/opt/ozw/config/images/shenzen_neo/ls03ch.jpg) 2020-11-07 20:42:20.461177886 [20201107 20:42:20.460 UTC] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/abus/SHRM10000.jpg (Node 0) 2020-11-07 20:42:20.462105756 [20201107 20:42:20.461 UTC] [ozw.library] [info]: Info - Node: 0 Missing Picture /opt/ozw/config/images/abus/SHRM10000.jpg - Starting Download 2020-11-07 20:42:20.462490498 [20201107 20:42:20.462 UTC] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/abus/SHRM10000.jpg (/opt/ozw/config/images/abus/SHRM10000.jpg) 2020-11-07 20:42:20.463935246 [20201107 20:42:20.463 UTC] [ozw.library] [info]: Info - Node: 0 Queuing download for http://download.db.openzwave.com/images/ecodim/0.7.jpg (Node 0) 2020-11-07 20:42:20.464716605 [20201107 20:42:20.464 UTC] [ozw.library] [info]: Info - Node: 0 Missing Picture /opt/ozw/config/images/ecodim/0.7.jpg - Starting Download 2020-11-07 20:42:20.511262093 [20201107 20:42:20.510 UTC] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 4 2020-11-07 20:42:20.511839909 [20201107 20:42:20.511 UTC] [ozw.library] [info]: Info - Node: 0 Download Finished: /opt/ozw/config/images/kwikset/916.jpg (Node: 0) 2020-11-07 20:42:20.512174130 [20201107 20:42:20.511 UTC] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 3 2020-11-07 20:42:20.512502986 [20201107 20:42:20.512 UTC] [ozw.library] [info]: Info - Node: 0 Download Finished: /opt/ozw/config/images/shenzen_neo/ls03ch.jpg (Node: 0) 2020-11-07 20:42:20.512827572 [20201107 20:42:20.512 UTC] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 2 2020-11-07 20:42:20.648646357 [20201107 20:42:20.647 UTC] [ozw.library] [debug]: Debug - Node: 0 Download Starting for http://download.db.openzwave.com/images/ecodim/0.7.jpg (/opt/ozw/config/images/ecodim/0.7.jpg) 2020-11-07 20:42:20.649602301 [20201107 20:42:20.648 UTC] [ozw.library] [info]: Info - Node: 0 Download Finished: /opt/ozw/config/images/abus/SHRM10000.jpg (Node: 0) 2020-11-07 20:42:20.650420170 [20201107 20:42:20.649 UTC] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 1 2020-11-07 20:42:21.147025030 [20201107 20:42:21.146 UTC] [ozw.library] [info]: Info - Node: 0 Download Finished: /opt/ozw/config/images/ecodim/0.7.jpg (Node: 0) 2020-11-07 20:42:21.147791597 [20201107 20:42:21.147 UTC] [ozw.library] [debug]: Debug - Node: 0 Downloads Remaining: 0 2020-11-07 20:42:21.148517851 [20201107 20:42:21.148 UTC] [ozw.library] [info]: Info - Node: 0 ManufacturerSpecificDB Initialized 2020-11-07 20:42:21.149267752 [20201107 20:42:21.148 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: ManufacturerSpecificDB Ready 2020-11-07 20:42:21.150114111 [20201107 20:42:21.149 UTC] [ozw.notifications] [debug]: Notification pvt_manufacturerSpecificDBReady Thread: 0xffff912bd690 2020-11-07 20:42:21.150555728 [20201107 20:42:21.150 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9 2020-11-07 20:42:21.151233440 [20201107 20:42:21.150 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event manufacturerSpecificDBReady 2020-11-07 20:42:21.151696829 [20201107 20:42:21.151 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.154710388 [20201107 20:42:21.154 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x35, 0x34, 0x00, 0x01, 0x93 2020-11-07 20:42:21.155615758 [20201107 20:42:21.155 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_GET_VERSION: 2020-11-07 20:42:21.156306856 [20201107 20:42:21.155 UTC] [ozw.library] [info]: Info - Node: 255 Static Controller library, version Z-Wave 4.54 2020-11-07 20:42:21.157012225 [20201107 20:42:21.156 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc 2020-11-07 20:42:21.157722386 [20201107 20:42:21.157 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.158313327 [20201107 20:42:21.157 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.158950414 [20201107 20:42:21.158 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.159847398 [20201107 20:42:21.159 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc 2020-11-07 20:42:21.160612820 [20201107 20:42:21.160 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.163504452 [20201107 20:42:21.163 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x08, 0x01, 0x20, 0xf8, 0xd0, 0x44, 0x2f, 0x01, 0x94 2020-11-07 20:42:21.163938673 [20201107 20:42:21.163 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_MEMORY_GET_ID. Home ID = 0xf8d0442f. Our node ID = 1 2020-11-07 20:42:21.164445655 [20201107 20:42:21.164 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9 2020-11-07 20:42:21.164764199 [20201107 20:42:21.164 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.165079096 [20201107 20:42:21.164 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.165388005 [20201107 20:42:21.165 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.165847330 [20201107 20:42:21.165 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9 2020-11-07 20:42:21.166165093 [20201107 20:42:21.165 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.168670316 [20201107 20:42:21.168 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x04, 0x01, 0x05, 0x3c, 0xc3 2020-11-07 20:42:21.169068756 [20201107 20:42:21.168 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 2020-11-07 20:42:21.169401102 [20201107 20:42:21.169 UTC] [ozw.library] [info]: Info - Node: 255 There is a SUC ID Server (SIS) in this network. 2020-11-07 20:42:21.169747562 [20201107 20:42:21.169 UTC] [ozw.library] [info]: Info - Node: 255 The PC controller is an inclusion static update controller (SUC) and was the original primary before the SIS was added. 2020-11-07 20:42:21.170078137 [20201107 20:42:21.169 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa 2020-11-07 20:42:21.170387253 [20201107 20:42:21.170 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.170698245 [20201107 20:42:21.170 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.171012934 [20201107 20:42:21.170 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.171465593 [20201107 20:42:21.171 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa 2020-11-07 20:42:21.171795126 [20201107 20:42:21.171 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.173832639 [20201107 20:42:21.173 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x04, 0x01, 0x56, 0x01, 0xad 2020-11-07 20:42:21.174232276 [20201107 20:42:21.174 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to GET_SUC_NODE_ID. Node ID = 1 2020-11-07 20:42:21.174572278 [20201107 20:42:21.174 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb 2020-11-07 20:42:21.174930874 [20201107 20:42:21.174 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.175240824 [20201107 20:42:21.175 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.175609003 [20201107 20:42:21.175 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.176042912 [20201107 20:42:21.175 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb 2020-11-07 20:42:21.176353956 [20201107 20:42:21.176 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.180366428 [20201107 20:42:21.180 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x2b, 0x01, 0x07, 0x01, 0x01, 0x00, 0x86, 0x00, 0x01, 0x00, 0x5a, 0xfe, 0x81, 0xff, 0x88, 0x4f, 0x1f, 0x00, 0x00, 0xfb, 0x9f, 0x7d, 0xa0, 0x67, 0x00, 0x00, 0x80, 0x00, 0x80, 0x86, 0x00, 0x00, 0x00, 0xe8, 0x73, 0x00, 0x00, 0x0e, 0x00, 0x00, 0x60, 0x00, 0x00, 0xfa 2020-11-07 20:42:21.180771482 [20201107 20:42:21.180 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_SERIAL_API_GET_CAPABILITIES 2020-11-07 20:42:21.181113411 [20201107 20:42:21.180 UTC] [ozw.library] [info]: Info - Node: 255 Serial API Version: 1.1 2020-11-07 20:42:21.181465132 [20201107 20:42:21.181 UTC] [ozw.library] [info]: Info - Node: 255 Manufacturer ID: 0x0086 2020-11-07 20:42:21.181811593 [20201107 20:42:21.181 UTC] [ozw.library] [info]: Info - Node: 255 Product Type: 0x0001 2020-11-07 20:42:21.182181543 [20201107 20:42:21.181 UTC] [ozw.library] [info]: Info - Node: 255 Product ID: 0x005a 2020-11-07 20:42:21.182628525 [20201107 20:42:21.182 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7 2020-11-07 20:42:21.182979621 [20201107 20:42:21.182 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe 2020-11-07 20:42:21.183303268 [20201107 20:42:21.183 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97 2020-11-07 20:42:21.183759156 [20201107 20:42:21.183 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x08, 0x00, 0x03, 0x01, 0x02, 0x01, 0x01, 0x5e, 0xa9 2020-11-07 20:42:21.184082908 [20201107 20:42:21.183 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.184395931 [20201107 20:42:21.184 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.184702495 [20201107 20:42:21.184 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.185100415 [20201107 20:42:21.184 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x1c) - FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7 2020-11-07 20:42:21.185414479 [20201107 20:42:21.185 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.241873151 [20201107 20:42:21.241 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x25, 0x01, 0x1c, 0x01, 0x20, 0x7f, 0x90, 0x20, 0xb8, 0xea, 0x0a, 0x23, 0x32, 0xe3, 0xba, 0xb8, 0x43, 0x28, 0x8e, 0x2e, 0xdd, 0xa2, 0x15, 0xf2, 0xf0, 0xb7, 0x01, 0x8d, 0x09, 0x51, 0xae, 0x81, 0x79, 0xad, 0x50, 0xef, 0xfd, 0xf8 2020-11-07 20:42:21.242803104 [20201107 20:42:21.242 UTC] [ozw.library] [info]: Info - Node: 0 Received reply to FUNC_ID_ZW_GET_RANDOM: true 2020-11-07 20:42:21.243583005 [20201107 20:42:21.243 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.244197540 [20201107 20:42:21.243 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.244842960 [20201107 20:42:21.244 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.245563069 [20201107 20:42:21.245 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x02) - FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe 2020-11-07 20:42:21.246254375 [20201107 20:42:21.245 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.347418576 [20201107 20:42:21.346 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x25, 0x01, 0x02, 0x05, 0x08, 0x1d, 0x01, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x05, 0x00, 0xcd 2020-11-07 20:42:21.348309987 [20201107 20:42:21.347 UTC] [ozw.library] [info]: Info - Node: 0 mgr, Driver with Home ID of 0xf8d0442f is now ready. 2020-11-07 20:42:21.349214993 [20201107 20:42:21.348 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_SERIAL_API_GET_INIT_DATA: 2020-11-07 20:42:21.349864163 [20201107 20:42:21.349 UTC] [ozw.library] [info]: Info - Node: 255 Node 001 - New 2020-11-07 20:42:21.350927086 [20201107 20:42:21.350 UTC] [ozw.library] [debug]: Detail - Node: 1 AdvanceQueries queryPending=0 queryRetries=0 queryStage=None live=1 2020-11-07 20:42:21.351702768 [20201107 20:42:21.351 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_ProtocolInfo 2020-11-07 20:42:21.352423554 [20201107 20:42:21.351 UTC] [ozw.library] [debug]: Detail - Node: 1 Queuing (Query) Get Node Protocol Info (Node=1): 0x01, 0x04, 0x00, 0x41, 0x01, 0xbb 2020-11-07 20:42:21.353115850 [20201107 20:42:21.352 UTC] [ozw.library] [debug]: Detail - Node: 1 Queuing (Query) Query Stage Complete (ProtocolInfo) 2020-11-07 20:42:21.353741635 [20201107 20:42:21.353 UTC] [ozw.library] [info]: Info - Node: 1 Initializing Node. New Node: false (false) 2020-11-07 20:42:21.354554869 [20201107 20:42:21.354 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.355175341 [20201107 20:42:21.354 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.355965085 [20201107 20:42:21.355 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.356378057 [20201107 20:42:21.356 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: DriverReady 2020-11-07 20:42:21.356773580 [20201107 20:42:21.356 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeNew 2020-11-07 20:42:21.357122332 [20201107 20:42:21.356 UTC] [ozw.notifications] [debug]: Notification pvt_driverRead 4174398511 Thread: 0xffff912bd690 2020-11-07 20:42:21.357280979 [20201107 20:42:21.357 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeAdded 2020-11-07 20:42:21.357632023 [20201107 20:42:21.357 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event started 2020-11-07 20:42:21.357894941 [20201107 20:42:21.357 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x06) - FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97 2020-11-07 20:42:21.358207495 [20201107 20:42:21.357 UTC] [ozw.manager] [debug]: setStarted 2020-11-07 20:42:21.358386090 [20201107 20:42:21.358 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.358736300 [20201107 20:42:21.358 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event driverReady: 4174398511 2020-11-07 20:42:21.359038021 [20201107 20:42:21.358 UTC] [ozw.notifications] [debug]: Notification pvt_nodeNew 1 Thread: 0xffff912bd690 2020-11-07 20:42:21.359469950 [20201107 20:42:21.359 UTC] [ozw.nodes] [info]: Adding Node 1 At Row 0 2020-11-07 20:42:21.359855161 [20201107 20:42:21.359 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeQueryStage : QVariant(QString, "ProtocolInfo") Transaction: true 2020-11-07 20:42:21.360500581 [20201107 20:42:21.360 UTC] [ozw.manager] [debug]: ProductPic Path: "/opt/ozw/config/" 2020-11-07 20:42:21.360787094 [20201107 20:42:21.360 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x05, 0x01, 0x06, 0x64, 0x0f, 0x96 2020-11-07 20:42:21.361109543 [20201107 20:42:21.360 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event NodeNew: 1 2020-11-07 20:42:21.361352045 [20201107 20:42:21.361 UTC] [ozw.library] [info]: Info - Node: 255 Received reply to FUNC_ID_SERIAL_API_SET_TIMEOUTS 2020-11-07 20:42:21.361687464 [20201107 20:42:21.361 UTC] [ozw.notifications] [debug]: Notification pvt_nodeAdded 1 Thread: 0xffff912bd690 2020-11-07 20:42:21.361856579 [20201107 20:42:21.361 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:21.362191894 [20201107 20:42:21.361 UTC] [ozw.nodes] [warning]: Node 1 Already Exists 2020-11-07 20:42:21.362358926 [20201107 20:42:21.362 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:21.362707053 [20201107 20:42:21.362 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.363066638 [20201107 20:42:21.362 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event NodeAdded: 1 2020-11-07 20:42:21.363296119 [20201107 20:42:21.363 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x00) - FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x08, 0x00, 0x03, 0x01, 0x02, 0x01, 0x01, 0x5e, 0xa9 2020-11-07 20:42:21.363803518 [20201107 20:42:21.363 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:21.365981708 [20201107 20:42:21.365 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:21.366374210 [20201107 20:42:21.366 UTC] [ozw.library] [info]: Info - Node: 1 Sending (Query) message (Callback ID=0x00, Expected Reply=0x41) - Get Node Protocol Info (Node=1): 0x01, 0x04, 0x00, 0x41, 0x01, 0xbb 2020-11-07 20:42:21.366730410 [20201107 20:42:21.366 UTC] [ozw.library] [info]: Info - Node: 1 Encrypted Flag is 0 2020-11-07 20:42:21.369289645 [20201107 20:42:21.369 UTC] [ozw.library] [debug]: Detail - Node: 1 Received: 0x01, 0x09, 0x01, 0x41, 0x93, 0x16, 0x01, 0x02, 0x02, 0x01, 0x33 2020-11-07 20:42:21.369775950 [20201107 20:42:21.369 UTC] [ozw.library] [info]: Info - Node: 1 Received reply to FUNC_ID_ZW_GET_NODE_PROTOCOL_INFO 2020-11-07 20:42:21.370117358 [20201107 20:42:21.369 UTC] [ozw.library] [info]: Info - Node: 1 Protocol Info for Node 1: 2020-11-07 20:42:21.370432568 [20201107 20:42:21.370 UTC] [ozw.library] [info]: Info - Node: 1 Listening = true 2020-11-07 20:42:21.370738455 [20201107 20:42:21.370 UTC] [ozw.library] [info]: Info - Node: 1 Beaming = true 2020-11-07 20:42:21.371052051 [20201107 20:42:21.370 UTC] [ozw.library] [info]: Info - Node: 1 Routing = false 2020-11-07 20:42:21.371425855 [20201107 20:42:21.371 UTC] [ozw.library] [info]: Info - Node: 1 Max Baud Rate = 100000 2020-11-07 20:42:21.371751430 [20201107 20:42:21.371 UTC] [ozw.library] [info]: Info - Node: 1 Version = 4 2020-11-07 20:42:21.372057422 [20201107 20:42:21.371 UTC] [ozw.library] [info]: Info - Node: 1 Security = false 2020-11-07 20:42:21.380334971 [20201107 20:42:21.379 UTC] [ozw.library] [info]: Info - Node: 1 Basic device class (0x02) - Static Controller 2020-11-07 20:42:21.380711432 [20201107 20:42:21.380 UTC] [ozw.library] [info]: Info - Node: 1 Generic device Class (0x02) - Static Controller 2020-11-07 20:42:21.381748886 [20201107 20:42:21.381 UTC] [ozw.library] [info]: Info - Node: 1 Specific device class (0x01) - Static PC Controller 2020-11-07 20:42:21.382104201 [20201107 20:42:21.381 UTC] [ozw.library] [info]: Info - Node: 1 Mandatory Command Classes for Node 1: 2020-11-07 20:42:21.382470661 [20201107 20:42:21.382 UTC] [ozw.library] [info]: Info - Node: 1 COMMAND_CLASS_MANUFACTURER_SPECIFIC 2020-11-07 20:42:21.382789569 [20201107 20:42:21.382 UTC] [ozw.library] [info]: Info - Node: 1 Mandatory Command Classes controlled by Node 1: 2020-11-07 20:42:21.383110665 [20201107 20:42:21.382 UTC] [ozw.library] [info]: Info - Node: 1 COMMAND_CLASS_BASIC 2020-11-07 20:42:21.383605980 [20201107 20:42:21.383 UTC] [ozw.library] [debug]: Debug - Node: 0 Driver::ReadButtons - zwbutton.xml file not found. 2020-11-07 20:42:21.383950878 [20201107 20:42:21.383 UTC] [ozw.library] [debug]: Detail - Node: 1 Expected reply was received 2020-11-07 20:42:21.384266297 [20201107 20:42:21.384 UTC] [ozw.library] [debug]: Detail - Node: 1 Message transaction complete 2020-11-07 20:42:21.384577445 [20201107 20:42:21.384 UTC] [ozw.library] [debug]: Detail - Node: 1 Removing current message 2020-11-07 20:42:21.384934530 [20201107 20:42:21.384 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeProtocolInfo 2020-11-07 20:42:21.385350262 [20201107 20:42:21.385 UTC] [ozw.library] [debug]: Detail - Node: 1 Query Stage Complete (ProtocolInfo) 2020-11-07 20:42:21.385686566 [20201107 20:42:21.385 UTC] [ozw.notifications] [debug]: Notification pvt_nodeProtocolInfo 1 Thread: 0xffff912bd690 2020-11-07 20:42:21.385853806 [20201107 20:42:21.385 UTC] [ozw.library] [debug]: Detail - Node: 1 AdvanceQueries queryPending=0 queryRetries=0 queryStage=Probe live=1 2020-11-07 20:42:21.386181413 [20201107 20:42:21.385 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeProductName : QVariant(QString, "") Transaction: true 2020-11-07 20:42:21.386352143 [20201107 20:42:21.386 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Probe 2020-11-07 20:42:21.386706989 [20201107 20:42:21.386 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeManufacturerName : QVariant(QString, "") Transaction: true 2020-11-07 20:42:21.386887250 [20201107 20:42:21.386 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_WakeUp 2020-11-07 20:42:21.387214908 [20201107 20:42:21.386 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeManufacturerID : QVariant(QString, "0x0000") Transaction: true 2020-11-07 20:42:21.387499129 [20201107 20:42:21.387 UTC] [ozw.library] [info]: Info - Node: 1 NodeInfo Stage - NodeInfoRecieved 0 - NotInfoSupported 1 2020-11-07 20:42:21.387940225 [20201107 20:42:21.387 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeProductID : QVariant(QString, "0x0000") Transaction: true 2020-11-07 20:42:21.388104810 [20201107 20:42:21.387 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_NodePlusInfo 2020-11-07 20:42:21.388445957 [20201107 20:42:21.388 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeProductType : QVariant(QString, "0x0000") Transaction: true 2020-11-07 20:42:21.388620438 [20201107 20:42:21.388 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_SecurityReport 2020-11-07 20:42:21.388953929 [20201107 20:42:21.388 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeBasicString : QVariant(QString, "Static Controller") Transaction: true 2020-11-07 20:42:21.389128409 [20201107 20:42:21.388 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Versions 2020-11-07 20:42:21.389457838 [20201107 20:42:21.389 ] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeBasic : QVariant(int, 2) Transaction: true 2020-11-07 20:42:21.389669298 [20201107 20:42:21.389 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_ManufacturerSpecific1 2020-11-07 20:42:21.390003102 [20201107 20:42:21.389 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeGenericString : QVariant(QString, "Static Controller") Transaction: true 2020-11-07 20:42:21.390181228 [20201107 20:42:21.389 UTC] [ozw.library] [debug]: Detail - Node: 1 Load Controller Manufacturer Specific Config 2020-11-07 20:42:21.390529772 [20201107 20:42:21.390 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeGeneric : QVariant(int, 2) Transaction: true 2020-11-07 20:42:21.390699617 [20201107 20:42:21.390 UTC] [ozw.library] [info]: Info - Node: 1 Opening config param file /opt/ozw/config/aeotec/zw090.xml 2020-11-07 20:42:21.391021077 [20201107 20:42:21.390 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeSpecific : QVariant(int, 1) Transaction: true 2020-11-07 20:42:21.391282589 [20201107 20:42:21.391 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeSpecificString : QVariant(QString, "Static PC Controller") Transaction: true 2020-11-07 20:42:21.391654727 [20201107 20:42:21.391 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeBaudRate : QVariant(uint, 100000) Transaction: true 2020-11-07 20:42:21.391878270 [20201107 20:42:21.391 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeVersion : QVariant(int, 4) Transaction: true 2020-11-07 20:42:21.392099052 [20201107 20:42:21.391 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeQueryStage : QVariant(QString, "ManufacturerSpecific1") Transaction: true 2020-11-07 20:42:21.392459054 [20201107 20:42:21.392 UTC] [ozw.library] [info]: Info - Node: 1 Queuing Lookup on 005a.0001.0086.db.openzwave.com for Node 1 2020-11-07 20:42:21.392884317 [20201107 20:42:21.392 UTC] [ozw.library] [info]: Info - Node: 1 Configuration File Revision is 6 2020-11-07 20:42:21.393217340 [20201107 20:42:21.392 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event nodeProtocolInfo: 1 2020-11-07 20:42:21.393409685 [20201107 20:42:21.393 UTC] [ozw.library] [info]: Info - Node: 0 LookupTxT Checking 005a.0001.0086.db.openzwave.com 2020-11-07 20:42:21.393786406 [20201107 20:42:21.393 UTC] [ozw.library] [info]: Info - Node: 1 (112 - COMMAND_CLASS_CONFIGURATION) - Compatibility Flags: 2020-11-07 20:42:21.394234325 [20201107 20:42:21.394 UTC] [ozw.library] [info]: Info - Node: 1 (112 - COMMAND_CLASS_CONFIGURATION) - State Flags: 2020-11-07 20:42:21.394890996 [20201107 20:42:21.394 UTC] [ozw.library] [info]: Info - Node: 0 Missing default integer value from xml configuration: node 1, class 0x70, instance 1, index 243 2020-11-07 20:42:21.395626365 [20201107 20:42:21.395 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Instances 2020-11-07 20:42:21.395960742 [20201107 20:42:21.395 UTC] [ozw.library] [info]: Info - Node: 1 Essential node queries are complete 2020-11-07 20:42:21.396281525 [20201107 20:42:21.396 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_ManufacturerSpecific2 2020-11-07 20:42:21.396595850 [20201107 20:42:21.396 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Static 2020-11-07 20:42:21.396949029 [20201107 20:42:21.396 UTC] [ozw.library] [info]: Info - Node: 1 Creating ValueIDs for Instance 1 on COMMAND_CLASS_BASIC 2020-11-07 20:42:21.397264187 [20201107 20:42:21.397 UTC] [ozw.library] [info]: Info - Node: 1 COMMAND_CLASS_BASIC is not mapped to another CC. Exposing ValueID 2020-11-07 20:42:21.397663981 [20201107 20:42:21.397 UTC] [ozw.library] [info]: Info - Node: 1 Creating ValueIDs for Instance 1 on COMMAND_CLASS_MANUFACTURER_SPECIFIC 2020-11-07 20:42:21.398020494 [20201107 20:42:21.397 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Associations 2020-11-07 20:42:21.398336485 [20201107 20:42:21.398 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Neighbors 2020-11-07 20:42:21.398658519 [20201107 20:42:21.398 UTC] [ozw.library] [debug]: Detail - Node: 0 Requesting routing info (neighbor list) for Node 1 2020-11-07 20:42:21.399025031 [20201107 20:42:21.398 UTC] [ozw.library] [debug]: Detail - Node: 1 Queuing (Command) Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a 2020-11-07 20:42:21.399373106 [20201107 20:42:21.399 UTC] [ozw.library] [debug]: Detail - Node: 1 Queuing (Query) Query Stage Complete (Neighbors) 2020-11-07 20:42:21.399938110 [20201107 20:42:21.399 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 81 2020-11-07 20:42:21.400350456 [20201107 20:42:21.400 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 220 2020-11-07 20:42:21.400701760 [20201107 20:42:21.400 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 22799473140563988 Thread: 0xffff912bd690 2020-11-07 20:42:21.400884574 [20201107 20:42:21.400 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 242 2020-11-07 20:42:21.401263482 [20201107 20:42:21.401 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 243 2020-11-07 20:42:21.401647026 [20201107 20:42:21.401 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 252 2020-11-07 20:42:21.402021143 [20201107 20:42:21.401 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 255 2020-11-07 20:42:21.402385104 [20201107 20:42:21.401 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 22799473140563988 2020-11-07 20:42:21.402577657 [20201107 20:42:21.402 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: EssentialNodeQueriesComplete 2020-11-07 20:42:21.402955732 [20201107 20:42:21.402 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 61924494903345172 Thread: 0xffff912bd690 2020-11-07 20:42:21.403127139 [20201107 20:42:21.402 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_BASIC Instance: 1 Index: 0 2020-11-07 20:42:21.403575475 [20201107 20:42:21.403 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_BASIC Instance: 1 Index: 1 2020-11-07 20:42:21.403965790 [20201107 20:42:21.403 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_BASIC Instance: 1 Index: 2 2020-11-07 20:42:21.404305323 [20201107 20:42:21.403 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 61924494903345172 2020-11-07 20:42:21.404513085 [20201107 20:42:21.404 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 0 2020-11-07 20:42:21.404856160 [20201107 20:42:21.404 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 68116944390979604 Thread: 0xffff912bd690 2020-11-07 20:42:21.405044442 [20201107 20:42:21.404 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 1 2020-11-07 20:42:21.405433507 [20201107 20:42:21.405 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueAdded CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 2 2020-11-07 20:42:21.405855906 [20201107 20:42:21.405 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 68116944390979604 2020-11-07 20:42:21.406026532 [20201107 20:42:21.405 UTC] [ozw.library] [info]: Info - Node: 1 Sending (Command) message (Callback ID=0x00, Expected Reply=0x80) - Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a 2020-11-07 20:42:21.406339398 [20201107 20:42:21.406 UTC] [ozw.library] [info]: Info - Node: 1 Encrypted Flag is 0 2020-11-07 20:42:21.406826849 [20201107 20:42:21.406 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 68398419367690259 Thread: 0xffff912bd690 2020-11-07 20:42:21.408007533 [20201107 20:42:21.407 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 68398419367690259 2020-11-07 20:42:21.408264149 [20201107 20:42:21.408 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 70931694158086164 Thread: 0xffff912bd690 2020-11-07 20:42:21.409287228 [20201107 20:42:21.409 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 70931694158086164 2020-11-07 20:42:21.409605980 [20201107 20:42:21.409 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 71776119088218131 Thread: 0xffff912bd690 2020-11-07 20:42:21.411225886 [20201107 20:42:21.410 UTC] [ozw.library] [debug]: Detail - Node: 1 Received: 0x01, 0x20, 0x01, 0x80, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x5e 2020-11-07 20:42:21.411611773 [20201107 20:42:21.411 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 71776119088218131 2020-11-07 20:42:21.411864848 [20201107 20:42:21.411 UTC] [ozw.library] [info]: Info - Node: 1 Received reply to FUNC_ID_ZW_GET_ROUTING_INFO 2020-11-07 20:42:21.412237246 [20201107 20:42:21.412 UTC] [ozw.library] [info]: Info - Node: 1 Neighbors of this node are: 2020-11-07 20:42:21.412562456 [20201107 20:42:21.412 UTC] [ozw.notifications] [debug]: Notification pvt_nodeEssentialNodeQueriesComplete 1 Thread: 0xffff912bd690 2020-11-07 20:42:21.412793551 [20201107 20:42:21.412 UTC] [ozw.library] [info]: Info - Node: 1 (none reported) 2020-11-07 20:42:21.413188189 [20201107 20:42:21.412 UTC] [ozw.library] [debug]: Detail - Node: 1 Expected reply was received 2020-11-07 20:42:21.413512254 [20201107 20:42:21.413 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeQueryStage : QVariant(QString, "Neighbors") Transaction: true 2020-11-07 20:42:21.413713974 [20201107 20:42:21.413 UTC] [ozw.library] [debug]: Detail - Node: 1 Message transaction complete 2020-11-07 20:42:21.414049705 [20201107 20:42:21.413 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeProductName : QVariant(QString, "ZW090 Z-Stick Gen5 EU") Transaction: true 2020-11-07 20:42:21.414224758 [20201107 20:42:21.414 UTC] [ozw.library] [debug]: Detail - Node: 1 Removing current message 2020-11-07 20:42:21.414552781 [20201107 20:42:21.414 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeManufacturerName : QVariant(QString, "AEON Labs") Transaction: true 2020-11-07 20:42:21.414787470 [20201107 20:42:21.414 UTC] [ozw.library] [debug]: Detail - Node: 1 Query Stage Complete (Neighbors) 2020-11-07 20:42:21.415120961 [20201107 20:42:21.414 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeManufacturerID : QVariant(QString, "0x0086") Transaction: true 2020-11-07 20:42:21.415300181 [20201107 20:42:21.415 UTC] [ozw.library] [debug]: Detail - Node: 1 AdvanceQueries queryPending=0 queryRetries=0 queryStage=Session live=1 2020-11-07 20:42:21.415693777 [20201107 20:42:21.415 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeProductID : QVariant(QString, "0x005a") Transaction: true 2020-11-07 20:42:21.415893622 [20201107 20:42:21.415 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Session 2020-11-07 20:42:21.416232478 [20201107 20:42:21.415 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeProductType : QVariant(QString, "0x0001") Transaction: true 2020-11-07 20:42:21.416462115 [20201107 20:42:21.416 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Dynamic 2020-11-07 20:42:21.416930295 [20201107 20:42:21.416 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeGroups : QVariant(int, 0) Transaction: true 2020-11-07 20:42:21.417069306 [20201107 20:42:21.416 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Configuration 2020-11-07 20:42:21.417548267 [20201107 20:42:21.417 UTC] [ozw.library] [debug]: Detail - Node: 1 QueryStage_Complete 2020-11-07 20:42:21.418177125 [20201107 20:42:21.417 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event nodeEssentialNodeQueriesComplete: 1 2020-11-07 20:42:21.418309157 [20201107 20:42:21.418 UTC] [ozw.library] [warning]: Warning - Node: 0 CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=0 2020-11-07 20:42:21.418714629 [20201107 20:42:21.418 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 17301521 Thread: 0xffff912bd690 2020-11-07 20:42:21.418863432 [20201107 20:42:21.418 UTC] [ozw.library] [warning]: Warning - Node: 0 CheckCompletedNodeQueries all=1, deadFound=0 sleepingOnly=1 2020-11-07 20:42:21.419280101 [20201107 20:42:21.419 UTC] [ozw.library] [info]: Info - Node: 0 Node query processing complete. 2020-11-07 20:42:21.419763697 [20201107 20:42:21.419 UTC] [ozw.library] [info]: Info - Node: 0 Saving Cache 2020-11-07 20:42:21.420208335 [20201107 20:42:21.419 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 17301521 2020-11-07 20:42:21.421101414 [20201107 20:42:21.420 UTC] [ozw.library] [info]: Info - Node: 1 Cache Save for Node 1 as its QueryStage_CacheLoad 2020-11-07 20:42:21.421485739 [20201107 20:42:21.421 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 281474994012177 Thread: 0xffff912bd690 2020-11-07 20:42:21.422759757 [20201107 20:42:21.422 UTC] [ozw.library] [info]: Info - Node: 0 Lookup for 005a.0001.0086.db.openzwave.com returned 6 2020-11-07 20:42:21.422968196 [20201107 20:42:21.422 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 281474994012177 2020-11-07 20:42:21.423556168 [20201107 20:42:21.423 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 562949970722835 Thread: 0xffff912bd690 2020-11-07 20:42:21.423975285 [20201107 20:42:21.423 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: NodeQueriesComplete 2020-11-07 20:42:21.424451694 [20201107 20:42:21.424 UTC] [ozw.library] [debug]: Detail - Node: 255 Notification: AllNodesQueried 2020-11-07 20:42:21.424839301 [20201107 20:42:21.424 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 562949970722835 2020-11-07 20:42:21.425020812 [20201107 20:42:21.424 UTC] [ozw.library] [debug]: Detail - Node: 1 Initial read of value 2020-11-07 20:42:21.425436388 [20201107 20:42:21.425 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 31227923 Thread: 0xffff912bd690 2020-11-07 20:42:21.425605087 [20201107 20:42:21.425 UTC] [ozw.library] [debug]: Detail - Node: 1 Notification: ValueChanged CC: COMMAND_CLASS_MANUFACTURER_SPECIFIC Instance: 1 Index: 2 2020-11-07 20:42:21.426665093 [20201107 20:42:21.426 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 31227923 2020-11-07 20:42:21.426904938 [20201107 20:42:21.426 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 281475007938579 Thread: 0xffff912bd690 2020-11-07 20:42:21.428046664 [20201107 20:42:21.427 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 281475007938579 2020-11-07 20:42:21.428275207 [20201107 20:42:21.428 UTC] [ozw.notifications] [debug]: Notification pvt_valueAdded: 562949984649235 Thread: 0xffff912bd690 2020-11-07 20:42:21.429327401 [20201107 20:42:21.429 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueAdded: 562949984649235 2020-11-07 20:42:21.429831727 [20201107 20:42:21.429 UTC] [ozw.notifications] [debug]: Notification pvt_nodeQueriesComplete 1 Thread: 0xffff912bd690 2020-11-07 20:42:21.430107666 [20201107 20:42:21.429 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeDeviceType : QVariant(int, 0) Transaction: true 2020-11-07 20:42:21.430347823 [20201107 20:42:21.430 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeDeviceTypeString : QVariant(QString, "Unknown Type (0x0000)") Transaction: true 2020-11-07 20:42:21.430622565 [20201107 20:42:21.430 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeRole : QVariant(int, 0) Transaction: true 2020-11-07 20:42:21.430890483 [20201107 20:42:21.430 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeRoleString : QVariant(QString, "Central Controller") Transaction: true 2020-11-07 20:42:21.431103349 [20201107 20:42:21.430 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodePlusType : QVariant(int, 0) Transaction: true 2020-11-07 20:42:21.431362309 [20201107 20:42:21.431 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodePlusTypeString : QVariant(QString, "Z-Wave+ node") Transaction: true 2020-11-07 20:42:21.431582779 [20201107 20:42:21.431 UTC] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeQueryStage : QVariant(QString, "Complete") Transaction: true 2020-11-07 20:42:21.432837317 [20201107 20:42:21.432 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event nodeQueriesComplete: 1 2020-11-07 20:42:21.433078725 [20201107 20:42:21.432 UTC] [ozw.notifications] [debug]: Notification pvt_driverAllNodesQueried Thread: 0xffff912bd690 2020-11-07 20:42:21.433373154 [20201107 20:42:21.433 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event driverAllNodesQueried: 2020-11-07 20:42:21.433600187 [20201107 20:42:21.433 UTC] [ozw.notifications] [debug]: Notification pvt_valueChanged: 562949984649235 Thread: 0xffff912bd690 2020-11-07 20:42:31.147103831 [20201107 20:42:31.146 UTC] [ozw.library] [info]: Info - Node: 0 HttpThread Exiting. No Transfers in timeout period 2020-11-07 20:42:58.356876242 [20201107 20:42:58.356 UTC] [ozw.mqtt.commands] [debug]: Got "OpenZWave/1/command/addnode/" Message: "{\"secure\": false}" 2020-11-07 20:42:58.357432284 [20201107 20:42:58.356 UTC] [ozw.library] [debug]: Detail - Node: 0 Queuing (Controller) Add Device 2020-11-07 20:42:58.362694790 [20201107 20:42:58.357 UTC] [ozw.library] [info]: Info - Node: 0 Add Device 2020-11-07 20:42:58.362717082 [20201107 20:42:58.358 UTC] [ozw.mqtt.commands] [info]: Processed Message for "addnode" : "{\"secure\": false}" 2020-11-07 20:42:58.362723228 [20201107 20:42:58.358 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x0a, 0x7b 2020-11-07 20:42:58.362736561 [20201107 20:42:58.359 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Starting 2020-11-07 20:42:58.362742915 [20201107 20:42:58.360 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand 1 1 0 Thread: 0xffff912bd690 2020-11-07 20:42:58.362749374 [20201107 20:42:58.360 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x0a, Expected Reply=0x4a) - ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x0a, 0x7b 2020-11-07 20:42:58.362756509 [20201107 20:42:58.361 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 2020-11-07 20:42:58.362762551 [20201107 20:42:58.362 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:58.365460471 [20201107 20:42:58.365 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x07, 0x00, 0x4a, 0x0a, 0x07, 0x00, 0x00, 0xbf 2020-11-07 20:42:58.366005627 [20201107 20:42:58.365 UTC] [ozw.library] [info]: Info - Node: 255 FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2020-11-07 20:42:58.366348701 [20201107 20:42:58.366 UTC] [ozw.library] [info]: Info - Node: 255 ADD_NODE_STATUS_FAILED 2020-11-07 20:42:58.366662920 [20201107 20:42:58.366 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:58.367008962 [20201107 20:42:58.366 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4 2020-11-07 20:42:58.367472504 [20201107 20:42:58.367 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Failed 2020-11-07 20:42:58.367873598 [20201107 20:42:58.367 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand 1 8 0 Thread: 0xffff912bd690 2020-11-07 20:42:58.368038859 [20201107 20:42:58.367 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x00, Expected Reply=0x4a) - Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4 2020-11-07 20:42:58.368384484 [20201107 20:42:58.368 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Failed NotificationTypes::Ctrl_Error_None 2020-11-07 20:42:58.368563703 [20201107 20:42:58.368 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:42:58.421135432 [20201107 20:42:58.420 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x07, 0x00, 0x4a, 0x0a, 0x06, 0x00, 0x00, 0xbe 2020-11-07 20:42:58.421941839 [20201107 20:42:58.421 UTC] [ozw.library] [info]: Info - Node: 255 FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2020-11-07 20:42:58.422674549 [20201107 20:42:58.422 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:42:58.423437154 [20201107 20:42:58.422 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:42:58.424067467 [20201107 20:42:58.423 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:42:58.424809291 [20201107 20:42:58.424 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Completed 2020-11-07 20:42:58.425618250 [20201107 20:42:58.425 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand 1 7 0 Thread: 0xffff912bd690 2020-11-07 20:42:58.426244449 [20201107 20:42:58.425 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Completed NotificationTypes::Ctrl_Error_None 2020-11-07 20:43:18.583994963 [20201107 20:43:18.583 UTC] [ozw.mqtt.publisher] [debug]: "Sat Nov 7 20:43:18 2020 PingResponse\n" 2020-11-07 20:44:06.085188298 [20201107 20:44:06.084 UTC] [ozw.mqtt.commands] [debug]: Got "OpenZWave/1/command/addnode/" Message: "{\"secure\": false}" 2020-11-07 20:44:06.085631319 [20201107 20:44:06.085 UTC] [ozw.library] [debug]: Detail - Node: 0 Queuing (Controller) Add Device 2020-11-07 20:44:06.086599810 [20201107 20:44:06.086 UTC] [ozw.library] [info]: Info - Node: 0 Add Device 2020-11-07 20:44:06.087255748 [20201107 20:44:06.086 UTC] [ozw.mqtt.commands] [info]: Processed Message for "addnode" : "{\"secure\": false}" 2020-11-07 20:44:06.087701008 [20201107 20:44:06.087 UTC] [ozw.library] [debug]: Detail - Node: 255 Queuing (Command) ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x0b, 0x7a 2020-11-07 20:44:06.088620592 [20201107 20:44:06.088 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Starting 2020-11-07 20:44:06.089731843 [20201107 20:44:06.088 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand 1 1 0 Thread: 0xffff912bd690 2020-11-07 20:44:06.090099552 [20201107 20:44:06.089 UTC] [ozw.library] [info]: Info - Node: 255 Sending (Command) message (Callback ID=0x0b, Expected Reply=0x4a) - ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x0b, 0x7a 2020-11-07 20:44:06.090813459 [20201107 20:44:06.090 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Starting NotificationTypes::Ctrl_Error_None 2020-11-07 20:44:06.090978407 [20201107 20:44:06.090 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 2020-11-07 20:44:06.094669972 [20201107 20:44:06.094 UTC] [ozw.library] [debug]: Detail - Node: 255 Received: 0x01, 0x07, 0x00, 0x4a, 0x0b, 0x01, 0x00, 0x00, 0xb8 2020-11-07 20:44:06.095069087 [20201107 20:44:06.094 UTC] [ozw.library] [info]: Info - Node: 255 FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2020-11-07 20:44:06.095444140 [20201107 20:44:06.095 UTC] [ozw.library] [info]: Info - Node: 255 ADD_NODE_STATUS_LEARN_READY 2020-11-07 20:44:06.095769505 [20201107 20:44:06.095 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected callbackId was received 2020-11-07 20:44:06.096082421 [20201107 20:44:06.095 UTC] [ozw.library] [debug]: Detail - Node: 255 Expected reply was received 2020-11-07 20:44:06.096426745 [20201107 20:44:06.096 UTC] [ozw.library] [debug]: Detail - Node: 255 Message transaction complete 2020-11-07 20:44:06.096748047 [20201107 20:44:06.096 UTC] [ozw.library] [debug]: Detail - Node: 255 Removing current message 2020-11-07 20:44:06.097209245 [20201107 20:44:06.096 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: AddDevice ControllerCommand - Waiting 2020-11-07 20:44:06.097629350 [20201107 20:44:06.097 UTC] [ozw.library] [info]: Info - Node: 0 WriteNextMsg Controller nothing to do 2020-11-07 20:44:06.097968881 [20201107 20:44:06.097 UTC] [ozw.notifications] [debug]: Notification pvt_controllerCommand 1 4 0 Thread: 0xffff912bd690 2020-11-07 20:44:06.098341069 [20201107 20:44:06.098 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event controllerCommand 0 NotificationTypes::Ctrl_Cmd_AddNode NotificationTypes::Ctrl_State_Waiting NotificationTypes::Ctrl_Error_None 2020-11-07 20:44:18.565085460 [20201107 20:44:18.564 UTC] [ozw.mqtt.publisher] [debug]: "Sat Nov 7 20:44:18 2020 PingResponse\n" 2020-11-07 20:45:18.583544774 [20201107 20:45:18.582 UTC] [ozw.mqtt.publisher] [debug]: "Sat Nov 7 20:45:18 2020 PingResponse\n" 2020-11-07 20:46:18.558335449 [20201107 20:46:18.557 UTC] [ozw.mqtt.publisher] [debug]: "Sat Nov 7 20:46:18 2020 PingResponse\n"

I'm honestly not sure what the problem can be, but I have tries to change the network key many times. I've also tried to remove spaces from

"0x65, 0x79, 0x17, 0x3B, 0xE0, 0x8C, 0x3F, 0x7F, 0x8F, 0xB1, 0x13, 0x90, 0x06, 0x00, 0x74, 0x6A"

to

"0x65,0x79,0x17,0x3B,0xE0,0x8C,0x3F,0x7F,0x8F,0xB1,0x13,0x90,0x06,0x00,0x74,0x6A"

and use lowercase characters without success as I read that someone had success with removing them. Also tried to use lowecase letters too.

jmgiaever commented 3 years ago

Screenshot from 2020-11-07 22-08-59

kpine commented 3 years ago

The key is specified with the OZW_NETWORK_KEY environment variable, which is not set in your docker command. It is missing from the example in the instructions, but the docker compose example and the list of supported environment variables show it. https://github.com/OpenZWave/qt-openzwave#using-the-standalone-image

jmgiaever commented 3 years ago

Hi,

Thanks for your reply, but it doesn't seem to help to add

-e OZW_NETWORK_KEY="0x65, 0x79, 0x17, 0x3B, 0xE0, 0x8C, 0x3F, 0x7F, 0x8F, 0xB1, 0x13, 0x90, 0x06, 0x00, 0x74, 0x6A"

to the command. The log now states:

2020-11-07 21:25:42.184369742  [20201107 21:25:42.184 UTC] [ozw.daemon] [info]: Network Key Specified in Enviroment is Valid 

But

[...]
2020-11-07 21:25:45.834496136  [20201107 21:25:45.834 UTC] [ozw.library] [info]: Info - Node: 255 Encrypted Flag is 0 
[...]
2020-11-07 21:44:21.603846939  [20201107 21:44:21.603 UTC] [ozw.library] [info]: Info - Node: 1 Encrypted Flag is 0 

I tried to reset the device too, by pressing the «action button» on the back of it for 20 seconds until it flashes blue.

EDIT: Pressing «add node» results in

2020-11-07 21:47:23.424830630  [20201107 21:47:23.424 UTC] [ozw.mqtt.commands] [info]: Processed Message for  "addnode" :  "{\"secure\": false}" 
kpine commented 3 years ago

You are including it unsecurely.

jmgiaever commented 3 years ago

There is no other option than «add node» (except from remove node). Should there be a button «add secure node», like the built-in Z-wave integration of Home Assistant? If so, I guess it's not there because the key is not applied to the stick?

kpine commented 3 years ago

That would be a question for Home Assistant (the answer is yes, it will be added).

ozwdaemon is working correctly, you've now got the key properly added and so you just need to turn on the secure flag when you add it. For now, either use the service call in HA, use MQTT, or use the ozw-admin application.

jmgiaever commented 3 years ago

Just to clearify:

  1. I've added the OZW_NETWORK_KEY correctly
  2. ozwdaemon confirms that the key seems to be valid
  3. ozwdaemon says the «Encrypted flag is 0» for the stick/Node 1 (and also for Node 255, for whatever that is?) I don't see that the issue is with Home Assistant.
kpine commented 3 years ago

You never added the node securely, so what are you expecting to happen?

jmgiaever commented 3 years ago

The USB-stick? How do I add it securely, except providing the network key for the command?

jmgiaever commented 3 years ago

USB-stick = Aeotec Z-Stick Gen 5 = Controller

kpine commented 3 years ago

Like you said, HA doesn't have a secure add button.

you just need to turn on the secure flag when you add it. For now, either use the service call in HA, use MQTT, or use the ozw-admin application.

Those are the 3 options.

  1. https://www.home-assistant.io/integrations/ozw/#service-ozwadd_node
  2. https://github.com/OpenZWave/qt-openzwave/blob/master/docs/MQTT.md#addnode
  3. https://github.com/OpenZWave/ozw-admin
jmgiaever commented 3 years ago

Again, thanks for your reply, but this new «integration» is somewhat lacking documentation to make it easy for users to move over to the new solutions. I appreciate that you take you time to guide me through this.

I though that the «add secure node» maybe was missing because the network-key "was missing". The configuration tab also said the key was =0 and the log said the stick had «Encrypted flag is 0».

Screenshot from 2020-11-07 23-05-10

I have succesfully added the node securely with

{
  "secure": true,
  "instance_id": 1
}

from Home Assistant.

jmgiaever commented 3 years ago

Can I kindly ask if you are using HA? Is it so that it should not be an «add secure node» button? For what I see in the OZW impl of HA, they try to determine if it secure or not. I'm just trying to find out where to file the bug that it doesn't show up in my installation.

kpine commented 3 years ago

Remember the OZW integration is in beta, and the UI especially is a work in progress. It is not complete at all. The missing secure option is known. Feel free to submit an issue/feature request with HA (not here) if you are concerned though. https://github.com/home-assistant/frontend/issues/new/choose

For what I see in the OZW impl of HA, they try to determine if it secure or not

I'm not sure what you mean by this. The code you linked is the service call. It's just assigning the secure flag based on the parameters you set.

jmgiaever commented 3 years ago

Yes, I do remember. But I also hope that feedback from users will help make it better.

Thanks for your help.