I have a Fibaro Motion Sensor configured to run with my OH 3.2.0 instance via Z-Wave Serial Controller in Serial Port of my Raspi.
A while ago the Motion Sensor dropped out of the Z-Wave Network and I reincluded it. But it seems something went wrong. The thing for the Motion Sensor is shown as online. But it does not seem to be sending any commands or at least OH is not receiving them. Also any change in settings of the thing let’s them in ‘pending’ like forever after saving. The Network map shows the thing as Node14 being directly connected to the controller.
However in the logs the only event which is shown with regard to this thing is when I remove and include battery again:
2022-11-12 21:05:28.126 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zwave:device:de7704fb:node14' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2022-11-12 21:05:28.131 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zwave:device:de7704fb:node14' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
Other zwave device connected to the same controller are working fine.
Healing the device did not work.
Exclusion of the device (setting controller to exclusion mode and clicking the B Button 3 times close to the controller) seems not working either.
Is there any recommended procedure in this case which I am missing?
What does this mean? Did you exclude with it coming back as a new number or just delete the thing from the UI page?
The event log is not useful for diagnosing Zwave problems. For a start, you will need to set the binding to debug (this is explained in the zwave documentation in the last couple of paragraphs) and press the B button once to wake it up.
Sorry for being inaccurate. It was not working after I upgraded to OH3 from my original OH2 setup. After having ignored the one device not working, I tried to reinclude it. It is likely that I failed on the correct procedure and maybe did not properly exclude it first.
I
Done. I searched for ‘Node 14’ but besides the many different events shown now in logs for Zwave devices, Node 14 is mentioned in the following events:
2022-11-12 22:07:38.859 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller status changed to OFFLINE.
2022-11-12 22:07:38.870 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller is not online.
2022-11-12 22:07:43.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: sendTransaction exception
2022-11-12 22:07:43.909 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init response (0) null
2022-11-12 22:07:43.914 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init transaction completed with response null
2022-11-12 22:07:43.915 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Skipping initialization thread, process stopped by controller
2022-11-12 22:07:44.001 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller status changed to OFFLINE.
2022-11-12 22:07:44.006 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller is not online.
2022-11-12 22:07:52.540 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 14: Node found
2022-11-12 22:07:52.599 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 14: Init node thread start
2022-11-12 22:07:52.821 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 14: Serializing from file /var/lib/openhab/zwave/network_c8f79543__node_14.xml
2022-11-12 22:07:52.983 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 14: Restore from config: Ok.
2022-11-12 22:07:53.002 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_SENSOR_ALARM, endpoint 0 created
2022-11-12 22:07:53.021 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2022-11-12 22:07:53.022 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created
2022-11-12 22:07:53.023 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created
2022-11-12 22:07:53.024 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_APPLICATION_STATUS, endpoint 0 created
2022-11-12 22:07:53.025 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_ALARM, endpoint 0 created
2022-11-12 22:07:53.026 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0 created
2022-11-12 22:07:53.027 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created
2022-11-12 22:07:53.030 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created
2022-11-12 22:07:53.043 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_CRC_16_ENCAP, endpoint 0 created
2022-11-12 22:07:53.069 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 created
2022-11-12 22:07:53.070 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created
2022-11-12 22:07:53.071 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2022-11-12 22:07:53.075 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_BATTERY, endpoint 0 created
2022-11-12 22:07:53.078 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_SECURITY, endpoint 0 created
2022-11-12 22:07:53.099 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 14: Updated networkKey
2022-11-12 22:07:53.100 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 14: setupNetworkKey useSchemeZero=false
2022-11-12 22:07:53.116 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created
2022-11-12 22:07:53.123 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created
2022-11-12 22:07:53.151 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created
2022-11-12 22:07:53.152 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created
2022-11-12 22:07:53.156 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_VERSION, endpoint 0 created
2022-11-12 22:07:53.157 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created
2022-11-12 22:07:53.158 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery completed
2022-11-12 22:07:53.170 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002
2022-11-12 22:07:53.254 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Starting initialisation from EMPTYNODE
2022-11-12 22:07:53.276 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node advancer - advancing to IDENTIFY_NODE
2022-11-12 22:07:53.287 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 14: Init node thread finished
2022-11-12 22:07:53.291 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node advancer: Initialisation starting
2022-11-12 22:07:53.660 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller status changed to ONLINE.
2022-11-12 22:07:53.666 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller is ONLINE. Starting device initialisation.
2022-11-12 22:07:53.703 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Updating node properties.
2022-11-12 22:07:53.737 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Updating node properties. MAN=271
2022-11-12 22:07:53.738 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Updating node properties. MAN=271. SET. Was 271
2022-11-12 22:07:53.739 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Properties synchronised
2022-11-12 22:07:53.744 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_64_2
2022-11-12 22:07:53.746 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_1_2
2022-11-12 22:07:53.748 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_2_1
2022-11-12 22:07:53.753 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_66_2
2022-11-12 22:07:53.754 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_3_1
2022-11-12 22:07:53.756 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_4_1
2022-11-12 22:07:53.762 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_6_2
2022-11-12 22:07:53.764 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_8_1
2022-11-12 22:07:53.767 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_9_2
2022-11-12 22:07:53.770 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_12_1
2022-11-12 22:07:53.792 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_14_2
2022-11-12 22:07:53.806 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_16_2
2022-11-12 22:07:53.810 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_80_1
2022-11-12 22:07:53.816 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_81_1
2022-11-12 22:07:53.818 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_18_1
2022-11-12 22:07:53.820 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_82_2
2022-11-12 22:07:53.822 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_83_2
2022-11-12 22:07:53.824 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_20_1
2022-11-12 22:07:53.826 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_22_2
2022-11-12 22:07:53.828 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_86_2
2022-11-12 22:07:53.829 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_87_2
2022-11-12 22:07:53.831 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_24_1
2022-11-12 22:07:53.833 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_25_1
2022-11-12 22:07:53.834 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_89_1
2022-11-12 22:07:53.835 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_28_1
2022-11-12 22:07:53.836 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_29_1
2022-11-12 22:07:53.838 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_40_2
2022-11-12 22:07:53.839 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_42_2
2022-11-12 22:07:53.841 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_60_2
2022-11-12 22:07:53.844 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Configuration pending removed for config_62_2
2022-11-12 22:07:53.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1)
2022-11-12 22:07:53.856 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising Thing Node...
2022-11-12 22:07:53.858 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:sensor_binary for OnOffType
2022-11-12 22:07:53.859 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:sensor_binary for OnOffType
2022-11-12 22:07:53.860 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:sensor_binary for OnOffType
2022-11-12 22:07:53.862 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:sensor_temperature for QuantityType
2022-11-12 22:07:53.863 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:sensor_temperature for QuantityType
2022-11-12 22:07:53.865 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:sensor_seismicintensity for DecimalType
2022-11-12 22:07:53.884 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:sensor_seismicintensity for DecimalType
2022-11-12 22:07:53.886 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:sensor_luminance for DecimalType
2022-11-12 22:07:53.888 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:sensor_luminance for DecimalType
2022-11-12 22:07:53.890 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:alarm_motion for OnOffType
2022-11-12 22:07:53.891 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:alarm_motion for OnOffType
2022-11-12 22:07:53.892 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:alarm_tamper for OnOffType
2022-11-12 22:07:53.894 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:alarm_tamper for OnOffType
2022-11-12 22:07:53.895 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:battery-level for PercentType
2022-11-12 22:07:53.896 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:battery-level for PercentType
2022-11-12 22:07:53.898 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising cmd channel zwave:device:de7704fb:node14:alarm_general for OnOffType
2022-11-12 22:07:53.899 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Initialising state channel zwave:device:de7704fb:node14:alarm_general for OnOffType
2022-11-12 22:07:53.900 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Polling initialised at 3600 seconds - start in 3038400 milliseconds.
2022-11-12 22:07:53.901 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Device initialisation complete.
2022-11-12 22:07:54.490 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: ProtocolInfo
2022-11-12 22:07:54.491 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Listening = false
2022-11-12 22:07:54.492 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Routing = true
2022-11-12 22:07:54.493 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Beaming = true
2022-11-12 22:07:54.494 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Version = 4
2022-11-12 22:07:54.495 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: FLIRS = false
2022-11-12 22:07:54.497 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Security = false
2022-11-12 22:07:54.498 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Max Baud = 40000
2022-11-12 22:07:54.499 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Basic = BASIC_TYPE_ROUTING_SLAVE
2022-11-12 22:07:54.500 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Generic = GENERIC_TYPE_SENSOR_NOTIFICATION
2022-11-12 22:07:54.501 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 14: Specific = SPECIFIC_TYPE_NOTIFICATION_SENSOR
2022-11-12 22:07:54.502 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2022-11-12 22:07:54.503 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2022-11-12 22:07:54.504 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Version = 1, version set. Enabling extra functionality.
2022-11-12 22:07:54.506 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2022-11-12 22:07:54.506 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Creating new instance of command class COMMAND_CLASS_BASIC
2022-11-12 22:07:54.508 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2022-11-12 22:07:54.509 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2022-11-12 22:07:54.518 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@c930e9
2022-11-12 22:07:54.519 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init transaction completed with response COMPLETE
2022-11-12 22:07:54.519 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node advancer - advancing to REQUEST_NIF
2022-11-12 22:07:54.520 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2022-11-12 22:07:54.523 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1cbbb54
2022-11-12 22:07:54.525 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Bump transaction 417 priority from Controller to Immediate
2022-11-12 22:07:54.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Adding to device queue
2022-11-12 22:07:54.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Added 417 to queue - size 10
Additionally I find Node 15 and 16 (which seem to be also Nodes created from the same device as they appear in the inbox as Fibaro Sensors and I do only have this one device) in the logs with exactly the same events logged :
2022-11-12 22:07:43.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: sendTransaction exception
2022-11-12 22:07:43.906 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init response (0) null
2022-11-12 22:07:43.917 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init transaction completed with response null
2022-11-12 22:07:43.918 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Skipping initialization thread, process stopped by controller
2022-11-12 22:07:52.541 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 15: Node found
2022-11-12 22:07:52.602 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 15: Init node thread start
2022-11-12 22:07:52.738 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 15: Serializing from file /var/lib/openhab/zwave/network_c8f79543__node_15.xml
2022-11-12 22:07:52.983 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 15: Restore from config: Ok.
2022-11-12 22:07:53.033 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_SENSOR_ALARM, endpoint 0 created
2022-11-12 22:07:53.044 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2022-11-12 22:07:53.067 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created
2022-11-12 22:07:53.068 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created
2022-11-12 22:07:53.069 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_APPLICATION_STATUS, endpoint 0 created
2022-11-12 22:07:53.072 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ALARM, endpoint 0 created
2022-11-12 22:07:53.081 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0 created
2022-11-12 22:07:53.085 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created
2022-11-12 22:07:53.085 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created
2022-11-12 22:07:53.086 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_CRC_16_ENCAP, endpoint 0 created
2022-11-12 22:07:53.087 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 created
2022-11-12 22:07:53.088 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created
2022-11-12 22:07:53.089 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2022-11-12 22:07:53.090 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_BATTERY, endpoint 0 created
2022-11-12 22:07:53.107 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_SECURITY, endpoint 0 created
2022-11-12 22:07:53.117 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: Updated networkKey
2022-11-12 22:07:53.123 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: setupNetworkKey useSchemeZero=false
2022-11-12 22:07:53.147 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created
2022-11-12 22:07:53.148 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created
2022-11-12 22:07:53.150 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created
2022-11-12 22:07:53.153 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created
2022-11-12 22:07:53.155 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_VERSION, endpoint 0 created
2022-11-12 22:07:53.157 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created
2022-11-12 22:07:53.159 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery completed
2022-11-12 22:07:53.164 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002
2022-11-12 22:07:53.220 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Starting initialisation from EMPTYNODE
2022-11-12 22:07:53.221 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 15: Init node thread finished
2022-11-12 22:07:53.222 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer - advancing to IDENTIFY_NODE
2022-11-12 22:07:53.249 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer: Initialisation starting
2022-11-12 22:07:54.078 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: ProtocolInfo
2022-11-12 22:07:54.079 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Listening = false
2022-11-12 22:07:54.080 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Routing = true
2022-11-12 22:07:54.081 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Beaming = true
2022-11-12 22:07:54.082 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Version = 4
2022-11-12 22:07:54.083 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: FLIRS = false
2022-11-12 22:07:54.084 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Security = false
2022-11-12 22:07:54.085 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Max Baud = 40000
2022-11-12 22:07:54.086 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Basic = BASIC_TYPE_ROUTING_SLAVE
2022-11-12 22:07:54.087 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Generic = GENERIC_TYPE_SENSOR_NOTIFICATION
2022-11-12 22:07:54.088 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Specific = SPECIFIC_TYPE_NOTIFICATION_SENSOR
2022-11-12 22:07:54.089 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2022-11-12 22:07:54.090 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2022-11-12 22:07:54.091 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Version = 1, version set. Enabling extra functionality.
2022-11-12 22:07:54.092 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2022-11-12 22:07:54.093 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_BASIC
2022-11-12 22:07:54.095 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2022-11-12 22:07:54.096 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2022-11-12 22:07:54.105 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@dc1d6c
2022-11-12 22:07:54.106 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init transaction completed with response COMPLETE
2022-11-12 22:07:54.109 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer - advancing to REQUEST_NIF
2022-11-12 22:07:54.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1de8ad3
2022-11-12 22:07:54.113 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Bump transaction 413 priority from Controller to Immediate
2022-11-12 22:07:54.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Adding to device queue
2022-11-12 22:07:54.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added 413 to queue - size 6
I read here that the issue most probably is that I do have these three Nodes 14/15/16 in my controller for the same device. Unfortunately in the post the solution seems to go through habmin, which is not available in OH3. The last post suggests to add all things from inbox and then remove them from controller. I did this but the three Nodes keep reappearing in my inbox. Any other suggestions?
Interestingly immediatly after trying to ‘remove device from controller’ from Node 14 thing configuration page the Zwave logs are showing this:
2022-11-12 22:32:24.779 [ERROR] [st.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at 'things/zwave:device:de7704fb:node14/config'
java.lang.IllegalStateException: Thing with UID zwave:device:de7704fb:node14 has no handler attached.
Unfortunately I was not able to find anything related to this.
Don’t filter the logs. This is covered in the read.me. Not every message has the node, but still could be related
Don’t use the “remove failed” on the device UI page. The only way to exclude is on the controller UI page, “exclude devices” then press the action button on the device as the manual. Good exclusion deletes the node from the controller (will not appear on a scan) and removes the XML.
back to the original problem. Set the binding in debug and press the action button once. This will find out what the node is and where it is in the initialization. edit: the device is communicating, but not fully configured yet
As a side note OH 3.3 has better battery device initialization
