Upgraded Raspberry Pi 2 with UZB1 stick to v2.0.1-24 about an hour ago. Got two Can not start Z-Wave binding notifications telling me that the Z-Wave binding had failed (08.56). See the log below.
I had to leave the machine alone, but after returning home I found everything was fine.
Code: Select all
[2015-03-27 08:51:06.134] [D] [zway] Job 0x13: deleted from queue
[2015-03-27 08:55:36.675] [I] [core] Executing script: exit()
[2015-03-27 08:55:37.144] [D] [zway] Worker thread exit point
[2015-03-27 08:55:37.145] [D] [zway] Worker thread successfully finished
[2015-03-27 08:55:37.145] [I] [zway] Saving configuration data to config/zddx/ccf7795e-DevicesData.xml
[2015-03-27 08:55:55.263] [I] [core] Executing script: /*** Z-Way Home Automation Engine main executable ***************************** ...
[2015-03-27 08:55:55.294] [I] [core] Executing script: // This script transforms old formats to new ...
[2015-03-27 08:55:55.373] [I] [core] Executing script: /*! ...
[2015-03-27 08:55:55.428] [I] [core] Executing script: // Underscore.js 1.7.0 ...
[2015-03-27 08:55:55.471] [I] [core] Executing script: /* System Start */ ...
[2015-03-27 08:55:55.475] [I] [core] Executing script: /* Start Core */ ...
[2015-03-27 08:55:55.485] [I] [core] Executing script: /* Start Core/Helpers */ ...
[2015-03-27 08:55:55.488] [I] [core] Executing script: /* Start Core/Namespace */ ...
[2015-03-27 08:55:55.489] [I] [core] Executing script: /* Start Core/Storage */ ...
[2015-03-27 08:55:55.494] [I] [core] Executing script: /* Start Core/Base */ ...
[2015-03-27 08:55:55.500] [I] [core] Executing script: /* Start Core/Model */ ...
[2015-03-27 08:55:55.530] [I] [core] Executing script: /* Start Core/Base */ ...
[2015-03-27 08:55:55.539] [I] [core] Executing script: /* Start Core/Collection */ ...
[2015-03-27 08:55:55.551] [I] [core] System: Loading Config
[2015-03-27 08:55:55.553] [I] [core] System: Loading Boot Scripts
[2015-03-27 08:55:55.562] [I] [core] System: Boot folder is empty
[2015-03-27 08:55:55.565] [I] [core] System: Registering Models
[2015-03-27 08:55:55.571] [I] [core] Executing script: /* System: User Model */ ...
[2015-03-27 08:55:55.577] [I] [core] Executing script: /* System: Users Collections */ ...
[2015-03-27 08:55:55.584] [I] [core] {"dataSource":"memory","public":false}
[2015-03-27 08:55:55.586] [I] [core] Executing script: /* System: User Model */ ...
[2015-03-27 08:55:55.589] [I] [core] Executing script: /* System: Users Collections */ ...
[2015-03-27 08:55:55.600] [I] [core] {"dataSource":"filesystem","file":"users","public":true}
[2015-03-27 08:55:55.601] [I] [core] System: Registering Handlers
[2015-03-27 08:55:55.603] [I] [core] Executing script: /* System: Loaded Cors Handler */ ...
[2015-03-27 08:55:55.604] [I] [core] Executing script: /* System: Loaded Cors Handler */ ...
[2015-03-27 08:55:55.606] [I] [core] Executing script: /* System: Loaded Rest Handler */ ...
[2015-03-27 08:55:55.608] [I] [core] Executing script: /* System: Loaded Cors Handler */ ...
[2015-03-27 08:55:55.610] [I] [core] Executing script: /* System: Loaded Cors Handler */ ...
[2015-03-27 08:55:55.614] [I] [core] Executing script: /*** Z-Way HA Virtual Device base class *************************************** ...
[2015-03-27 08:55:55.620] [I] [core] Executing script: /*** Z-Way DevicesCollection class ************************************ ...
[2015-03-27 08:55:55.637] [I] [core] Executing script: /*** Z-Way HA Controller class module ***************************************** ...
[2015-03-27 08:55:55.641] [I] [core] Executing script: /*** Z-Way HA Controller class module ***************************************** ...
[2015-03-27 08:55:55.644] [I] [core] Executing script: /*** Z-Way HA Automation module base class ************************************ ...
[2015-03-27 08:55:55.649] [I] [core] Executing script: /*** Main Automation storage module ***************************************** ...
[2015-03-27 08:55:55.659] [I] [core] Executing script: /*** Main Automation webserver module ***************************************** ...
[2015-03-27 08:55:55.661] [I] [core] Executing script: // Make this testable by pulling in underscore from the parent module ...
[2015-03-27 08:55:55.666] [I] [core] Executing script: /*** Main Automation storage module ***************************************** ...
[2015-03-27 08:55:55.685] [I] [core] --- Loading ZAutomation classes
[2015-03-27 08:55:55.771] [I] [core] Starting ZWay Automation webserver
[2015-03-27 08:55:55.778] [I] [core] Loading modules...
[2015-03-27 08:55:55.787] [I] [core] Loading module RoundRobinScenes from modules/RoundRobinScenes
[2015-03-27 08:55:55.789] [I] [core] Executing script: /*** RoundRobinScenes Z-Way HA module ******************************************* ...
[2015-03-27 08:55:55.794] [I] [core] Loading module CodeDevice from modules/CodeDevice
[2015-03-27 08:55:55.796] [I] [core] Executing script: /*** CodeDevice Z-Way HA module ******************************************* ...
[2015-03-27 08:55:55.809] [I] [core] Instantiating module 9 from class CodeDevice
[2015-03-27 08:55:55.812] [I] [core] --- Starting module Code device
[2015-03-27 08:56:11.781] [I] [core] Creating device sensorMultilevel Code_Device_sensorMultilevel_9
[2015-03-27 08:56:11.839] [I] [core] Instantiating module 10 from class CodeDevice
[2015-03-27 08:56:11.840] [I] [core] --- Starting module Code device
[2015-03-27 08:56:12.198] [I] [core] Creating device sensorMultilevel Code_Device_sensorMultilevel_10
[2015-03-27 08:56:12.211] [I] [core] Instantiating module 12 from class CodeDevice
[2015-03-27 08:56:23.564] [I] [core] --- Starting module Code device
[2015-03-27 08:56:23.573] [I] [core] Creating device sensorMultilevel Code_Device_sensorMultilevel_12
[2015-03-27 08:56:23.582] [I] [core] Instantiating module 20 from class CodeDevice
[2015-03-27 08:56:23.583] [I] [core] --- Starting module Code device
[2015-03-27 08:56:24.019] [I] [core] Creating device toggleButton Code_Device_toggleButton_20
[2015-03-27 08:56:24.030] [I] [core] Instantiating module 21 from class CodeDevice
[2015-03-27 08:56:24.030] [I] [core] --- Starting module Code device
[2015-03-27 08:56:24.486] [I] [core] Creating device toggleButton Code_Device_toggleButton_21
[2015-03-27 08:56:24.493] [I] [core] Loading module GroupDevices from modules/GroupDevices
[2015-03-27 08:56:24.495] [I] [core] Executing script: /*** GroupDevices Z-Way HA module ******************************************* ...
[2015-03-27 08:56:24.497] [I] [core] Loading module FosCam9828 from modules/FosCam9828
[2015-03-27 08:56:24.500] [I] [core] Executing script: /*** FosCam9828 Z-Way HA module ******************************************* ...
[2015-03-27 08:56:24.508] [I] [core] Loading module HTTPDevice from modules/HTTPDevice
[2015-03-27 08:56:24.511] [I] [core] Executing script: /*** HTTPDevice Z-Way HA module ******************************************* ...
[2015-03-27 08:56:24.512] [I] [core] Loading module DummyDevice from modules/DummyDevice
[2015-03-27 08:56:24.514] [I] [core] Executing script: /*** DummyDevice Z-Way HA module ******************************************* ...
[2015-03-27 08:56:24.515] [I] [core] Loading module CustomUserCodeLoader from modules/CustomUserCodeLoader
[2015-03-27 08:56:24.517] [I] [core] Executing script: /*** CustomUserCodeLoader ZAutomation module **************************************** ...
[2015-03-27 08:56:24.519] [I] [core] Loading module YandexProbki from modules/YandexProbki
[2015-03-27 08:56:24.521] [I] [core] Executing script: /*** YandexProbki Z-Way HA module ******************************************* ...
[2015-03-27 08:56:24.523] [I] [core] Loading module Cron from modules/Cron
[2015-03-27 08:56:24.536] [I] [core] Executing script: /*** Cron ZAutomation module ************************************************** ...
[2015-03-27 08:56:24.542] [I] [core] Instantiating module 1 from class Cron
[2015-03-27 08:56:24.545] [I] [core] --- Starting module Cron scheduler
[2015-03-27 08:56:27.371] [I] [core] Loading module BatteryPolling from modules/BatteryPolling
[2015-03-27 08:56:27.373] [I] [core] Executing script: /*** BatteryPolling Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.375] [I] [core] Loading module PVLogger from userModules/PVLogger
[2015-03-27 08:56:27.377] [I] [core] Executing script: /*** PVLogger Z-Way HA module *******************************************
...
[2015-03-27 08:56:27.385] [I] [core] Instantiating module 24 from class PVLogger
[2015-03-27 08:56:27.387] [I] [core] --- Starting module __title__
[2015-03-27 08:56:27.395] [I] [core] Creating device sensorMultilevel PVLogger_24-1
[2015-03-27 08:56:27.404] [I] [core] Creating device sensorMultilevel PVLogger_24-2
[2015-03-27 08:56:27.447] [I] [core] Instantiating module 25 from class PVLogger
[2015-03-27 08:56:27.448] [I] [core] --- Starting module __title__
[2015-03-27 08:56:27.454] [I] [core] Creating device sensorMultilevel PVLogger_25-1
[2015-03-27 08:56:27.464] [I] [core] Creating device sensorMultilevel PVLogger_25-2
[2015-03-27 08:56:27.516] [I] [core] Loading module FosCam9826 from modules/FosCam9826
[2015-03-27 08:56:27.519] [I] [core] Executing script: /*** FosCam9826 Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.523] [I] [core] Loading module VistaCam from modules/VistaCam
[2015-03-27 08:56:27.525] [I] [core] Executing script: /*** VistaCam Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.528] [I] [core] Loading module Daylight from userModules/Daylight
[2015-03-27 08:56:27.532] [I] [core] Executing script: /*** Daylight Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.537] [I] [core] Instantiating module 7 from class Daylight
[2015-03-27 08:56:27.540] [I] [core] --- Starting module Daylight
[2015-03-27 08:56:27.548] [I] [core] Creating device sensorBinary Daylight7
[2015-03-27 08:56:27.589] [I] [core] Daylight: Status update executed
[2015-03-27 08:56:27.594] [I] [core] Daylight: current local time: Fri Mar 27 2015 08:56:27 GMT+0100 (CET)
[2015-03-27 08:56:27.596] [I] [core] Daylight: current UTC time : Fri, 27 Mar 2015 07:56:27 GMT
[2015-03-27 08:56:27.597] [I] [core] Daylight: Sunrise in local time: Fri Mar 27 2015 05:48:45 GMT+0100 (CET)
[2015-03-27 08:56:27.598] [I] [core] Daylight: Sunrise in UTC time : Fri, 27 Mar 2015 04:48:45 GMT
[2015-03-27 08:56:27.598] [I] [core] Daylight: Sunset in local time: Fri Mar 27 2015 19:33:16 GMT+0100 (CET)
[2015-03-27 08:56:27.598] [I] [core] Daylight: Sunset in UTC time : Fri, 27 Mar 2015 18:33:16 GMT
[2015-03-27 08:56:27.599] [I] [core] Daylight: Conclusion is that sensor should be on
[2015-03-27 08:56:27.599] [I] [core] Daylight: Sensor already on, nothing changed
[2015-03-27 08:56:27.602] [I] [core] Daylight: Schedule update executed
[2015-03-27 08:56:27.602] [I] [core] Daylight: Sunrise in local time: Fri Mar 27 2015 05:48:45 GMT+0100 (CET)
[2015-03-27 08:56:27.603] [I] [core] Daylight: Sunrise in UTC time : Fri, 27 Mar 2015 04:48:45 GMT
[2015-03-27 08:56:27.605] [I] [core] Daylight: Sunrise event scheduled for 5:49
[2015-03-27 08:56:27.606] [I] [core] Daylight: Sunset in local time: Fri Mar 27 2015 19:33:16 GMT+0100 (CET)
[2015-03-27 08:56:27.606] [I] [core] Daylight: Sunset in UTC time : Fri, 27 Mar 2015 18:33:16 GMT
[2015-03-27 08:56:27.607] [I] [core] Daylight: Sunset event scheduled for 19:34
[2015-03-27 08:56:27.608] [I] [core] Loading module HomeKitGate from modules/HomeKitGate
[2015-03-27 08:56:27.610] [I] [core] Executing script: /* ...
[2015-03-27 08:56:27.612] [I] [core] Loading module AutoOff from modules/AutoOff
[2015-03-27 08:56:27.613] [I] [core] Executing script: /*** AutoOff Z-Way Home Automation module ************************************* ...
[2015-03-27 08:56:27.615] [I] [core] Loading module NotificationSMSru from modules/NotificationSMSru
[2015-03-27 08:56:27.616] [I] [core] Executing script: /*** NotificationSMSru Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.618] [I] [core] Loading module LightScene from modules/LightScene
[2015-03-27 08:56:27.619] [I] [core] Executing script: /*** LightScene Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.621] [I] [core] Loading module Mathematica from userModules/Mathematica
[2015-03-27 08:56:27.623] [I] [core] Executing script: /*** Mathematica Z-Way HA module *******************************************
...
[2015-03-27 08:56:27.625] [I] [core] Loading module SwitchPolling from modules/SwitchPolling
[2015-03-27 08:56:27.626] [I] [core] Executing script: /*** SwitchPolling Z-Way HA module ******************************************* ...
[2015-03-27 08:56:27.628] [I] [core] Loading module ZWave from modules/ZWave
[2015-03-27 08:56:27.646] [I] [core] Executing script: /*** Z-Wave Binding module ******************************************************** ...
[2015-03-27 08:56:27.653] [I] [core] Instantiating module 18 from class ZWave
[2015-03-27 08:56:27.655] [I] [core] --- Starting module Z-Wave binding
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data = Empty
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data.nodeId = Empty
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data.homeId = Empty
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data.SUCNodeId = Empty
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data.isPrimary = Empty
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data.isInOthersNetwork = Empty
[2015-03-27 08:56:28.042] [D] [zway] SETDATA controller.data.isRealPrimary = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.isSUC = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.SISPresent = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.libType = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.SDK = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.ZWlibMajor = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.ZWlibMinor = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.ZWLib = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.ZWVersion = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.ZWaveChip = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.APIVersion = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.manufacturerId = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.vendor = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.manufacturerProductType = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.manufacturerProductId = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.capabilities = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.controllerState = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.nonManagmentJobs = Empty
[2015-03-27 08:56:28.043] [D] [zway] SETDATA controller.data.lastIncludedDevice = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.lastExcludedDevice = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.secureInclusion = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.oldSerialAPIAckTimeout10ms = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.oldSerialAPIByteTimeout10ms = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.curSerialAPIAckTimeout10ms = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.curSerialAPIByteTimeout10ms = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.countJobs = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.memoryGetAddress = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.memoryGetData = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.functionClasses = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.functionClassesNames = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.softwareRevisionVersion = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.softwareRevisionId = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.softwareRevisionDate = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.uuid = Empty
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.nodeId = 0 (0x00000000)
[2015-03-27 08:56:28.044] [D] [zway] SETDATA controller.data.homeId = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.SUCNodeId = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.isPrimary = False
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.isInOthersNetwork = False
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.isRealPrimary = False
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.isSUC = False
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.SISPresent = False
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.ZWLib = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.ZWlibMajor = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.ZWlibMinor = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.ZWVersion = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.manufacturerId = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.manufacturerProductType = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.manufacturerProductId = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.controllerState = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.nonManagmentJobs = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.secureInclusion = True
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.oldSerialAPIAckTimeout10ms = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.oldSerialAPIByteTimeout10ms = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.curSerialAPIAckTimeout10ms = 0 (0x00000000)
[2015-03-27 08:56:28.045] [D] [zway] SETDATA controller.data.curSerialAPIByteTimeout10ms = 0 (0x00000000)
[2015-03-27 08:56:28.046] [D] [zway] SETDATA controller.data.countJobs = False
[2015-03-27 08:56:28.046] [D] [zway] SETDATA controller.data.softwareRevisionVersion = "v2.0.1-rc24"
[2015-03-27 08:56:28.046] [D] [zway] SETDATA controller.data.softwareRevisionId = "ee8c3a37fdc7f82204edc4e07946b01570078031"
[2015-03-27 08:56:28.046] [D] [zway] SETDATA controller.data.softwareRevisionDate = "2015-03-27 01:59:16 +0300"
[2015-03-27 08:56:28.046] [D] [zway] SETDATA controller.data.functionClasses = int[55]
[2015-03-27 08:56:28.046] [D] [zway] [00] 2
[2015-03-27 08:56:28.046] [D] [zway] [01] 3
[2015-03-27 08:56:28.046] [D] [zway] [02] 4
[2015-03-27 08:56:28.046] [D] [zway] [03] 5
[2015-03-27 08:56:28.046] [D] [zway] [04] 6
[2015-03-27 08:56:28.046] [D] [zway] [05] 7
[2015-03-27 08:56:28.046] [D] [zway] [06] 8
[2015-03-27 08:56:28.046] [D] [zway] [07] 18
[2015-03-27 08:56:28.047] [D] [zway] [08] 19
[2015-03-27 08:56:28.047] [D] [zway] [09] 21
[2015-03-27 08:56:28.047] [D] [zway] [10] 22
[2015-03-27 08:56:28.047] [D] [zway] [11] 23
[2015-03-27 08:56:28.047] [D] [zway] [12] 32
[2015-03-27 08:56:28.047] [D] [zway] [13] 33
[2015-03-27 08:56:28.047] [D] [zway] [14] 34
[2015-03-27 08:56:28.047] [D] [zway] [15] 35
[2015-03-27 08:56:28.047] [D] [zway] [16] 36
[2015-03-27 08:56:28.047] [D] [zway] [17] 39
[2015-03-27 08:56:28.047] [D] [zway] [18] 41
[2015-03-27 08:56:28.047] [D] [zway] [19] 42
[2015-03-27 08:56:28.047] [D] [zway] [20] 43
[2015-03-27 08:56:28.047] [D] [zway] [21] 44
[2015-03-27 08:56:28.047] [D] [zway] [22] 45
[2015-03-27 08:56:28.047] [D] [zway] [23] 65
[2015-03-27 08:56:28.047] [D] [zway] [24] 66
[2015-03-27 08:56:28.047] [D] [zway] [25] 68
[2015-03-27 08:56:28.047] [D] [zway] [26] 70
[2015-03-27 08:56:28.047] [D] [zway] [27] 71
[2015-03-27 08:56:28.047] [D] [zway] [28] 72
[2015-03-27 08:56:28.047] [D] [zway] [29] 73
[2015-03-27 08:56:28.047] [D] [zway] [30] 74
[2015-03-27 08:56:28.048] [D] [zway] [31] 75
[2015-03-27 08:56:28.048] [D] [zway] [32] 76
[2015-03-27 08:56:28.048] [D] [zway] [33] 77
[2015-03-27 08:56:28.048] [D] [zway] [34] 80
[2015-03-27 08:56:28.048] [D] [zway] [35] 81
[2015-03-27 08:56:28.048] [D] [zway] [36] 82
[2015-03-27 08:56:28.048] [D] [zway] [37] 83
[2015-03-27 08:56:28.048] [D] [zway] [38] 84
[2015-03-27 08:56:28.048] [D] [zway] [39] 85
[2015-03-27 08:56:28.048] [D] [zway] [40] 86
[2015-03-27 08:56:28.048] [D] [zway] [41] 87
[2015-03-27 08:56:28.048] [D] [zway] [42] 96
[2015-03-27 08:56:28.048] [D] [zway] [43] 97
[2015-03-27 08:56:28.048] [D] [zway] [44] 98
[2015-03-27 08:56:28.048] [D] [zway] [45] 99
[2015-03-27 08:56:28.048] [D] [zway] [46] 128
[2015-03-27 08:56:28.048] [D] [zway] [47] 186
[2015-03-27 08:56:28.048] [D] [zway] [48] 190
[2015-03-27 08:56:28.048] [D] [zway] [49] 210
[2015-03-27 08:56:28.048] [D] [zway] [50] 211
[2015-03-27 08:56:28.048] [D] [zway] [51] 242
[2015-03-27 08:56:28.048] [D] [zway] [52] 243
[2015-03-27 08:56:28.048] [D] [zway] [53] 244
[2015-03-27 08:56:28.049] [D] [zway] [54] 245
[2015-03-27 08:56:28.049] [D] [zway] SETDATA controller.data.functionClassesNames = string[55]
[2015-03-27 08:56:28.049] [D] [zway] [00] "SerialAPIGetInitData"
[2015-03-27 08:56:28.049] [D] [zway] [01] "SerialAPIApplicationNodeInformation"
[2015-03-27 08:56:28.049] [D] [zway] [02] "ApplicationCommandHandler"
[2015-03-27 08:56:28.049] [D] [zway] [03] "GetControllerCapabilities"
[2015-03-27 08:56:28.049] [D] [zway] [04] "SerialAPISetTimeouts"
[2015-03-27 08:56:28.049] [D] [zway] [05] "GetSerialAPICapabilities"
[2015-03-27 08:56:28.049] [D] [zway] [06] "SerialAPISoftReset"
[2015-03-27 08:56:28.049] [D] [zway] [07] "SendNodeInformation"
[2015-03-27 08:56:28.049] [D] [zway] [08] "SendData"
[2015-03-27 08:56:28.049] [D] [zway] [09] "GetVersion"
[2015-03-27 08:56:28.049] [D] [zway] [10] "SendDataAbort"
[2015-03-27 08:56:28.049] [D] [zway] [11] "RFPowerLevelSet"
[2015-03-27 08:56:28.049] [D] [zway] [12] "GetHomeId"
[2015-03-27 08:56:28.049] [D] [zway] [13] "MemoryGetByte"
[2015-03-27 08:56:28.049] [D] [zway] [14] "MemoryPutByte"
[2015-03-27 08:56:28.049] [D] [zway] [15] "MemoryGetBuffer"
[2015-03-27 08:56:28.049] [D] [zway] [16] "MemoryPutBuffer"
[2015-03-27 08:56:28.050] [D] [zway] [17] "FlashAutoProgSet"
[2015-03-27 08:56:28.050] [D] [zway] [18] "NVMGetId"
[2015-03-27 08:56:28.050] [D] [zway] [19] "NVMExtReadLongBuffer"
[2015-03-27 08:56:28.050] [D] [zway] [20] "NVMExtWriteLongBuffer"
[2015-03-27 08:56:28.050] [D] [zway] [21] "NVMExtReadLongByte"
[2015-03-27 08:56:28.050] [D] [zway] [22] "NVMExtWriteLongByte"
[2015-03-27 08:56:28.050] [D] [zway] [23] "GetNodeProtocolInformation"
[2015-03-27 08:56:28.050] [D] [zway] [24] "SetDefault"
[2015-03-27 08:56:28.050] [D] [zway] [25] "ReplicationReceiveComplete"
[2015-03-27 08:56:28.050] [D] [zway] [26] "AssignReturnRoute"
[2015-03-27 08:56:28.050] [D] [zway] [27] "DeleteReturnRoute"
[2015-03-27 08:56:28.050] [D] [zway] [28] "RequestNodeNeighbourUpdate"
[2015-03-27 08:56:28.050] [D] [zway] [29] "ApplicationNodeUpdate"
[2015-03-27 08:56:28.050] [D] [zway] [30] "AddNodeToNetwork"
[2015-03-27 08:56:28.050] [D] [zway] [31] "RemoveNodeFromNetwork"
[2015-03-27 08:56:28.050] [D] [zway] [32] "CreateNewPrimary"
[2015-03-27 08:56:28.050] [D] [zway] [33] "ControllerChange"
[2015-03-27 08:56:28.050] [D] [zway] [34] "SetLearnMode"
[2015-03-27 08:56:28.050] [D] [zway] [35] "AssignSUCReturnRoute"
[2015-03-27 08:56:28.050] [D] [zway] [36] "EnableSUC"
[2015-03-27 08:56:28.050] [D] [zway] [37] "RequestNetworkUpdate"
[2015-03-27 08:56:28.050] [D] [zway] [38] "SetSUCNodeId"
[2015-03-27 08:56:28.050] [D] [zway] [39] "DeleteSUCReturnRoute"
[2015-03-27 08:56:28.050] [D] [zway] [40] "GetSUCNodeId"
[2015-03-27 08:56:28.051] [D] [zway] [41] "SendSUCNodeId"
[2015-03-27 08:56:28.051] [D] [zway] [42] "RequestNodeInformation"
[2015-03-27 08:56:28.051] [D] [zway] [43] "RemoveFailedNode"
[2015-03-27 08:56:28.051] [D] [zway] [44] "IsFailedNode"
[2015-03-27 08:56:28.051] [D] [zway] [45] "ReplaceFailedNode"
[2015-03-27 08:56:28.051] [D] [zway] [46] "GetRoutingTableLine"
[2015-03-27 08:56:28.051] [D] [zway] [47] "RFPowerLevelGet"
[2015-03-27 08:56:28.051] [D] [zway] [48] "SendTestFrame"
[2015-03-27 08:56:28.051] [D] [zway] [49] "WatchDogStart"
[2015-03-27 08:56:28.051] [D] [zway] [50] "WatchDogStop"
[2015-03-27 08:56:28.051] [D] [zway] [51] "ZMEFreqChange"
[2015-03-27 08:56:28.051] [D] [zway] [52] "ZMERestore"
[2015-03-27 08:56:28.051] [D] [zway] [53] "ZMEBootloaderFlash"
[2015-03-27 08:56:28.051] [D] [zway] [54] "ZMECapabilities"
[2015-03-27 08:56:28.052] [D] [zway] Opened device: /dev/ttyACM0
[2015-03-27 08:56:28.052] [D] [zway] Worker thread successfully created
[2015-03-27 08:56:28.052] [D] [zway] Worker thread entry point
[2015-03-27 08:56:28.056] [I] [zway] Adding job: Get controller info and supported function classes
[2015-03-27 08:56:28.084] [D] [zway] SENDING: ( 01 03 00 07 FB )
[2015-03-27 08:56:28.294] [I] [zway] Job 0x07 (Get controller info and supported function classes): No ACK received before timeout
[2015-03-27 08:56:28.294] [D] [zway] SENDING: ( 01 03 00 07 FB )
[2015-03-27 08:56:28.353] [W] [zway] Received SOF, while awaiting ACK
[2015-03-27 08:56:28.353] [D] [zway] RECEIVED: ( 01 22 00 04 00 04 1C 8F 01 06 03 80 03 4C 06 43 03 01 42 07 D0 04 46 08 00 7F 02 81 05 02 46 04 02 84 07 25 )
[2015-03-27 08:56:28.353] [D] [zway] SENT ACK
[2015-03-27 08:56:28.353] [I] [zway] Unhandled request for function class 0x04
[2015-03-27 08:56:28.353] [W] [zway] Received SOF, while awaiting ACK
[2015-03-27 08:56:28.714] [I] [zway] Job 0x07 (Get controller info and supported function classes): No ACK received before timeout
[2015-03-27 08:56:28.714] [D] [zway] SENDING: ( 01 03 00 07 FB )
[2015-03-27 08:56:28.734] [D] [zway] RECEIVED: ( 01 22 00 04 00 04 1C 8F 01 06 03 80 03 4C 06 43 03 01 42 07 D0 04 46 08 00 7F 02 06 01 2B 01 07 05 02 01 15 )
[2015-03-27 08:56:28.734] [D] [zway] Wrong checksum
[2015-03-27 08:56:28.734] [D] [zway] SENT NAK
[2015-03-27 08:56:28.754] [E] [zway] RECEIVED UNKNOWN PACKET TYPE: 0x04
[2015-03-27 08:56:28.754] [E] [zway] RECEIVED UNKNOWN PACKET TYPE: 0x00
[2015-03-27 08:56:28.754] [E] [zway] RECEIVED UNKNOWN PACKET TYPE: 0x00
[2015-03-27 08:56:28.755] [W] [zway] Received SOF, while awaiting ACK
[2015-03-27 08:56:29.114] [I] [zway] Job 0x07 (Get controller info and supported function classes): No ACK received before timeout
[2015-03-27 08:56:29.114] [W] [zway] Job 0x07 (Get controller info and supported function classes) dropped: too many resends
[2015-03-27 08:56:29.114] [D] [zway] Job 0x07 (Get controller info and supported function classes): fail
[2015-03-27 08:56:29.114] [C] [zway] Get Serial API Capabilities returned zero.
[2015-03-27 08:56:29.114] [I] [zway] Removing job: Get controller info and supported function classes
[2015-03-27 08:56:29.134] [D] [zway] Worker thread exit point
[2015-03-27 08:56:29.134] [D] [zway] Worker thread successfully finished
[2015-03-27 08:56:29.266] [I] [core] Terminating Z-Wave binding
[2015-03-27 08:56:29.271] [E] [zway] SaveData will not save data since it wasn't loaded. This is to prevent data loss.
[2015-03-27 08:56:29.292] [I] [core] Notification: critical (z-wave): Can not start Z-Wave binding: Error: Bad data - communication failed
[2015-03-27 08:56:29.292] [I] [core] Loading module ThermostatDevice from modules/ThermostatDevice
[2015-03-27 08:56:29.294] [I] [core] Executing script: /*** ThermostatDevice Z-Way HA module ******************************************* ...
[2015-03-27 08:56:29.295] [I] [core] Loading module AutoLock from modules/AutoLock
[2015-03-27 08:56:29.297] [I] [core] Executing script: /*** AutoLock Z-Way Home Automation module ************************************* ...
[2015-03-27 08:56:29.298] [I] [core] Loading module RGB from modules/RGB
[2015-03-27 08:56:29.299] [I] [core] Executing script: /*** RGB Z-Way HA module ******************************************* ...
[2015-03-27 08:56:29.300] [I] [core] Loading module TagOnOff from modules/TagOnOff
[2015-03-27 08:56:29.301] [I] [core] Executing script: /*** TagOnOff Z-Way HA module ******************************************* ...
[2015-03-27 08:56:29.302] [I] [core] Loading module ImportRemoteHA from modules/ImportRemoteHA
[2015-03-27 08:56:29.305] [I] [core] Executing script: /*** ImportRemoteHA Z-Way HA module ******************************************* ...
[2015-03-27 08:56:29.307] [I] [core] Loading module OpenWeather from modules/OpenWeather