Item state change always from NULL to actual value

[speed (Dima)]

I have one Item (Z-Wave) which is always changing from NULL to the actual value and with every next update it is again changing from NULL to the actual value. Here is the log:

2020-11-04 11:46:13.179 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_binary changed from NULL to ON
2020-11-04 11:46:13.181 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_temperature changed from NULL to 71.25 °C
2020-11-04 11:46:13.183 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_door changed from NULL to OPEN
2020-11-04 11:46:13.185 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_battery_level changed from NULL to 100.0
2020-11-04 11:46:13.186 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_alarm_general changed from NULL to ON
2020-11-04 11:46:13.187 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:ddd3b615:node22' has been updated.
2020-11-04 11:48:09.609 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_binary changed from NULL to ON
2020-11-04 11:48:09.611 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_temperature changed from NULL to 71.25 °C
2020-11-04 11:48:09.612 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_door changed from NULL to OPEN
2020-11-04 11:48:09.615 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_battery_level changed from NULL to 100.0
2020-11-04 11:48:09.616 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_alarm_general changed from NULL to ON
2020-11-04 11:48:09.617 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:ddd3b615:node22' has been updated.

PaperUI is showing the actual values and not the NULL values. This Item is also the only item I have this issue - all others are updating / changing as expected.

Why is that happening and how can this be fixed so I have the real value changes instead of from NULL to real value?

[Bruce_Osborne]

@speed

Why is that happening and how can this be fixed

Only your system knows that and you did noe enable debug logging as instructed in the binding documentation. With unfiltered debug logs perhaps the log viewer would be helpful.

Z-Wave Log Viewer

[rossko57]

@speed

Thing ‘zwave:device:ddd3b615:node22’ has been updated.

This event causes the linked Items to be (silently) reinitialized, becoming NULL state.

This event is about the properties of the Thing, and an update can be caused if the real device properties don’t match the recorded Thing configuration.

That might happen if the device has been reconfigured or updated.
It might happen if the binding has been updated, with some change in this particular Thing type. Old existing Things do not get automatically updated.

A common cure is to delete the Thing, allow it to be rediscovered, and if you create a new Thing with the same UID it will re-attach to your old Items etc.

[speed (Dima)]

Thanks Bruce. Here is the Debug Log:

2020-11-05 13:43:57.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 09 71 05 00 00 00 FF 06 16 00 
2020-11-05 13:43:57.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 09 71 05 00 00 00 FF 06 16 00 
2020-11-05 13:43:57.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 88
2020-11-05 13:43:57.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Application Command Request (ALIVE:DONE)
2020-11-05 13:43:57.631 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: resetResendCount initComplete=true isDead=false
2020-11-05 13:43:57.631 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2020-11-05 13:43:57.631 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: SECURITY NOT required on COMMAND_CLASS_ALARM
2020-11-05 13:43:57.631 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 22: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT
2020-11-05 13:43:57.631 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 22: NOTIFICATION report - 0 = 0, event=22, status=255, plen=0
2020-11-05 13:43:57.631 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 22: Alarm Type = ACCESS_CONTROL (0)
2020-11-05 13:43:57.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2020-11-05 13:43:57.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
2020-11-05 13:43:57.631 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 22: Alarm converter processing NOTIFICATION
2020-11-05 13:43:57.631 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 22: Alarm converter NOTIFICATION event is 22, type OpenClosedType
2020-11-05 13:43:57.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Updating channel state zwave:device:ddd3b615:node22:sensor_door to OPEN [OpenClosedType]
2020-11-05 13:43:57.632 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 22: Alarm converter processing NOTIFICATION
2020-11-05 13:43:57.632 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 22: Alarm converter NOTIFICATION event is 22, type OnOffType
2020-11-05 13:43:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Commands processed 1.
2020-11-05 13:43:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2fb8ec4a.
2020-11-05 13:43:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:57.739 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 16 03 80 03 64 00 
2020-11-05 13:43:57.739 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 03 80 03 64 
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 03 80 03 64 
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 88
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Application Command Request (ALIVE:DONE)
2020-11-05 13:43:57.740 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: resetResendCount initComplete=true isDead=false
2020-11-05 13:43:57.740 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: Incoming command class COMMAND_CLASS_BATTERY, endpoint 0
2020-11-05 13:43:57.740 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: SECURITY NOT required on COMMAND_CLASS_BATTERY
2020-11-05 13:43:57.740 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 22: Received COMMAND_CLASS_BATTERY V1 BATTERY_REPORT
2020-11-05 13:43:57.740 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 22: Battery report value = 100
2020-11-05 13:43:57.740 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2020-11-05 13:43:57.740 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BATTERY, value=100
2020-11-05 13:43:57.740 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Updating channel state zwave:device:ddd3b615:node22:battery-level to 100 [DecimalType]
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Commands processed 1.
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@389d9202.
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:57.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:57.804 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 58 01 00 28 9A 
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=88, payload=58 01 00 28 
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=88, payload=58 01 00 28 
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 88
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 88
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2579: (Callback 88)
2020-11-05 13:43:57.804 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-11-05 13:43:57.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 2579: callback 88
2020-11-05 13:43:57.804 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=88, payload=58 01 00 28 
2020-11-05 13:43:57.804 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 88, Status = Transmission complete, no ACK received(1)
2020-11-05 13:43:57.804 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2579: Transaction CANCELLED
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: CANCEL while sending message. Requeueing - 1 attempts left!
2020-11-05 13:43:57.805 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2579: Transaction RESET with 1 retries remaining.
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 2579 to queue - size 9
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-11-05 13:43:57.805 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 04 01 00 25 59 9D 
2020-11-05 13:43:57.805 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 08 00 13 04 01 00 25 59 9D 
2020-11-05 13:43:57.805 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2579: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2579: Transaction not completed
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:57.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:57.806 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-11-05 13:43:57.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-11-05 13:43:57.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-11-05 13:43:57.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:57.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-11-05 13:43:57.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:57.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:57.815 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-11-05 13:43:57.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-11-05 13:43:57.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-11-05 13:43:57.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:57.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-11-05 13:43:57.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2579: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:57.816 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-11-05 13:43:57.816 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: sentData successfully placed on stack.
2020-11-05 13:43:57.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2579: Advanced to WAIT_REQUEST
2020-11-05 13:43:57.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2579: Transaction not completed
2020-11-05 13:43:57.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:57.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:57.900 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 16 02 84 07 64 
2020-11-05 13:43:57.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 02 84 07 
2020-11-05 13:43:57.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 02 84 07 
2020-11-05 13:43:57.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:57.901 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Application Command Request (ALIVE:DONE)
2020-11-05 13:43:57.901 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: resetResendCount initComplete=true isDead=false
2020-11-05 13:43:57.901 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: Is awake with 0 messages in the queue
2020-11-05 13:43:57.901 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: Start sleep timer at 1000ms
2020-11-05 13:43:57.901 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2020-11-05 13:43:57.901 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:scene_number unlinked - polling stopped.
2020-11-05 13:43:57.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:sensor_binary unlinked - polling stopped.
2020-11-05 13:43:57.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:sensor_temperature unlinked - polling stopped.
2020-11-05 13:43:57.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:sensor_door unlinked - polling stopped.
2020-11-05 13:43:57.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:alarm_tamper unlinked - polling stopped.
2020-11-05 13:43:57.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:battery-level unlinked - polling stopped.
2020-11-05 13:43:57.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:alarm_general unlinked - polling stopped.
2020-11-05 13:43:57.904 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:scene_number linked - polling started.
2020-11-05 13:43:57.905 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:sensor_binary linked - polling started.
2020-11-05 13:43:57.909 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:sensor_temperature linked - polling started.
2020-11-05 13:43:57.909 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:sensor_door linked - polling started.
2020-11-05 13:43:57.911 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:alarm_tamper linked - polling started.
2020-11-05 13:43:57.912 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:battery-level linked - polling started.
2020-11-05 13:43:57.914 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Channel zwave:device:ddd3b615:node22:alarm_general linked - polling started.
2020-11-05 13:43:57.915 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 22: Node Status event - Node is AWAKE
2020-11-05 13:43:57.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Commands processed 1.
2020-11-05 13:43:57.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@37296a9.
2020-11-05 13:43:57.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:57.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:57.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:57.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:58.162 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 59 01 00 24 97 
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=89, payload=59 01 00 24 
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=89, payload=59 01 00 24 
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2579: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2579: (Callback 89)
2020-11-05 13:43:58.162 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-11-05 13:43:58.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 2579: callback 89
2020-11-05 13:43:58.162 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=89, payload=59 01 00 24 
2020-11-05 13:43:58.162 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 89, Status = Transmission complete, no ACK received(1)
2020-11-05 13:43:58.163 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2579: Transaction CANCELLED
2020-11-05 13:43:58.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Retry count exceeded. Discarding message: TID 2579: [CANCELLED] priority=Poll, requiresResponse=true, callback: 89
2020-11-05 13:43:58.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2579: Transaction completed
2020-11-05 13:43:58.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:2579 CANCELLED
2020-11-05 13:43:58.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:58.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-11-05 13:43:58.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2579: Transaction event listener: DONE: CANCELLED -> 
2020-11-05 13:43:58.163 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@32152588
2020-11-05 13:43:58.401 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: WakeupTimerTask 0 Messages waiting, state DONE
2020-11-05 13:43:58.901 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: WakeupTimerTask 0 Messages waiting, state DONE
2020-11-05 13:43:58.901 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: No more messages, go back to sleep
2020-11-05 13:43:58.902 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 22: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2020-11-05 13:43:58.902 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2020-11-05 13:43:58.902 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2020-11-05 13:43:58.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1b39336c
2020-11-05 13:43:58.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Bump transaction 2580 priority from Immediate to Immediate
2020-11-05 13:43:58.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Adding to device queue
2020-11-05 13:43:58.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Added 2580 to queue - size 9
2020-11-05 13:43:58.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-11-05 13:43:58.902 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 16 02 84 08 25 5A 02 
2020-11-05 13:43:58.902 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 22: Sending REQUEST Message = 01 09 00 13 16 02 84 08 25 5A 02 
2020-11-05 13:43:58.902 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-11-05 13:43:58.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2580: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 90
2020-11-05 13:43:58.903 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-11-05 13:43:58.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-11-05 13:43:58.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-11-05 13:43:58.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2580: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 90
2020-11-05 13:43:58.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-11-05 13:43:58.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:58.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:58.910 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2580: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 90
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2580: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 90
2020-11-05 13:43:58.910 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-11-05 13:43:58.910 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 22: sentData successfully placed on stack.
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2580: Advanced to WAIT_REQUEST
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: TID 2580: Transaction not completed
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:58.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-11-05 13:43:58.922 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 16 06 31 05 01 42 1B 2C A7 
2020-11-05 13:43:58.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 06 31 05 01 42 1B 2C 
2020-11-05 13:43:58.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=22, callback=0, payload=00 16 06 31 05 01 42 1B 2C 
2020-11-05 13:43:58.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2580: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 90
2020-11-05 13:43:58.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Application Command Request (ALIVE:DONE)
2020-11-05 13:43:58.923 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: resetResendCount initComplete=true isDead=false
2020-11-05 13:43:58.923 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2020-11-05 13:43:58.923 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 22: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-11-05 13:43:58.923 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 22: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2020-11-05 13:43:58.923 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 22: Sensor Type = Temperature(1), Scale = 0
2020-11-05 13:43:58.923 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 22: Sensor Value = 69.56
2020-11-05 13:43:58.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2020-11-05 13:43:58.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=69.56
2020-11-05 13:43:58.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Updating channel state zwave:device:ddd3b615:node22:sensor_temperature to 69.56 °C [QuantityType]
2020-11-05 13:43:58.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Commands processed 1.
2020-11-05 13:43:58.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 22: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@72275ffd.
2020-11-05 13:43:58.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:58.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-11-05 13:43:58.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-11-05 13:43:58.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

For time reference here is the corresponding event.log

2020-11-05 13:43:57.905 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_binary changed from NULL to ON
2020-11-05 13:43:57.907 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_temperature changed from NULL to 69.75 °C
2020-11-05 13:43:57.909 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_door changed from NULL to OPEN
2020-11-05 13:43:57.912 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_battery_level changed from NULL to 100.0
2020-11-05 13:43:57.917 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_alarm_general changed from NULL to ON
2020-11-05 13:43:57.917 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:ddd3b615:node22' has been updated.
2020-11-05 13:43:58.924 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_temperature changed from 69.75 °C to 69.56 °C

I dont see what could have been the trigger for “2020-11-05 13:43:57.917 [me.event.ThingUpdatedEvent]” which I understand from Rossko57 below post, could be the issue.

Do you see anything unusual for Node 22? Thanks.

[speed (Dima)]

Thanks Rossko57. I have deleted the Thing in PaperUI and did a z-wave binding discovery which as expected re-discovered the Node22 and I have added it again. Behavior of being updated after each report is still the same and I keep getting the “changed from NULL to …” messages.

Any other idea what I could try? If you have a moment, have a look at the debug.log in my other post - I wasn’t able to identify the trigger.

Thanks!

[rossko57]

@speed

I have deleted the Thing in PaperUI and did a z-wave binding discovery which as expected re-discovered the Node22 and I have added it again. Behavior of being updated after each report is still the same and I keep getting the “changed from NULL

Do you still get the Thing updated messages?
Bearing in mind that the the Thing definition may indeed have changed between versions, take a close look at channels. Are you linking say (what is now) a number:temperature type channel to a plain Number Item, etc.?

[chris (Chris Jackson)]

I’m a little confused what’s being suggested here…

@rossko57

This event causes the linked Items to be (silently) reinitialized, becoming NULL state

Are you sure about this, or is this a guess?

If we update the properties of a thing (eg the node neighbours, or something like this that changes periodically) I would NOT expect this to impact items and I don’t believe it does.

@rossko57

Bearing in mind that the the Thing definition may indeed have changed between versions,

How does the thing definition feed in to this issue? I just don’t understand (probably just my lack of knowledge here).

[rossko57]

@chris

Are you sure about this, or is this a guess?

I am not 100% on it, and I think it varies by circumstance. The behaviour has changed through the life of 2.5 I am sure, as I understand in an attempt to respond ‘better’.to configuration edits.

If we do update the properties of a Thing (eg the channel names or types) I WOULD expect this to impact items.
There’s an underlying tension about how many chains to be yanking at in the case of Thing update. In some other binding say, an update to a polling period might require the binding to tear down a scheduled job and build a new one for example, a fairly drastic action.

What would be really useful right here is your insider’s view of what should happen in the zwave context.

In the original post, it appears there’s a “Thing update” every time that device reports - would you consider that normal?
What does the binding do, when notified of a Thing update?

2020-11-05 13:43:57.901 in that DEBUG log looks to me the part that will NULL Items by unlinking/linking channels. But yes, I am guessing at that part. Maybe this is the important change in framework behaviour - although it does seem reasonable to reinitialize (NULL state) a freshly linked Item.

More generally, for example - device database update between versions, changing a channel type say from number to number:temperature.
Would you expect this to trigger a ‘Thing updated’ event at all?
If so, will that be one-off?
Should everything still work without further intervention? (how?)
What should happen with an existing Item-channel link?

Dropping this in for my own reference really, knew I’d read it ages ago,

Bindings

[chris (Chris Jackson)]

@rossko57

in an attempt to respond ‘better’.to configuration edits.

Configuration edits are different though aren’t they. Changing properties, and changing configuration (in the text file I assume?) are completely different. The binding updates properties - a user updates the configuration, and I didn’t think they were treated the same.

@rossko57

In the original post, it appears there’s a “Thing update” every time that device reports - would you consider that normal?

Yes, possibly it is. But updating the thing properties for example is completely different to updating the configuration. I would be quite worried if updating the thing properties was causing all items to be cleared to null, and I’m reasonably sure that does not happen (but I’ve not tested this as I’m not near my system). We update properties all the time - it clearly (IMHO) shouldn’t cause the whole thing to be reset.

@rossko57

What does the binding do, when notified of a Thing update?

Firstly, what do you mean by “thing update”? Do you mean 1) the configuration changes, 2) the state changes from OFFLINE to ONLINE, 3) properties are updated…

If you mean that the user changes configuration, then the binding receives configuration update command and processes this accordingly. The binding will NEVER set a channel to null.

@rossko57

More generally, for example - device database update between versions, changing a channel type say from number to number:temperature.
Would you expect this to trigger a ‘Thing updated’ event at all?

No - the database is in no way related to this conversation and generally speaking, it will never change (in OH) unless the user deletes the thing and adds it back. Changes to the database will not otherwise have an impact.

@rossko57

Should everything still work without further intervention?

I don’t know what this question relates to? Do you mean “when the database updates, should everything still work without further intervention?”. If so, as I said above, the database is in no way linked to this discussion, and unless the USER deletes the thing and adds it back again, the thing will not update.

@rossko57

What should happen with an existing Item-channel link?

Nothing (at least not in the binding) - channel links are separate events - they have not updated the thing. The binding receives a notification (there is a method that is called in the handler) but I don’t think that’s in any way linked.

It does feel like we’re just guessing a bit here, and that feels just a little bit dangerous.

[rossko57]

Alright, that’s fair enough.

Re configuration vs. Online/offline, these appear as completely distinguishable events in events.log
A ‘Thing updated’ message is distinct from ‘Thing status update’, the framework handles them differently.

Let’s forget Things and work backwards - why is the binding unlinking all this devices channels?

[chris (Chris Jackson)]

@rossko57

Re configuration vs. Online/offline, these appear as completely distinguishable events in events.log
A ‘Thing updated’ message is distinct from ‘Thing status update’, the framework handles them differently.

Sure - I fully understand that. My question was relating to what you meant by a “thing update” as there are many different updates that can happen and it seemed to me that you were mixing up a number of them (you seem to talk about properties and configuration interchangeably for example).

@rossko57

why is the binding unlinking all this devices channels?

Because it’s told to do so by the system - the messages that are logged here are logged by the binding in response to the framework calling the “channelUnlinked” method. The binding has no control over the linking - something else is doing this.

The binding has absolutely no control over what is linked to what. The binding only sends updates to channels - it sends them to ALL channels if they are linked or not, and it doesn’t control in any way at all the linking or unlinking. Additionally, the binding doesn’t even provide the “changed from” part.

We see this in the logs above -:

2020-11-05 13:43:57.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Updating channel state zwave:device:ddd3b615:node22:sensor_door to OPEN [OpenClosedType]
2020-11-05 13:43:57.740 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Updating channel state zwave:device:ddd3b615:node22:battery-level to 100 [DecimalType]
2020-11-05 13:43:58.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 22: Updating channel state zwave:device:ddd3b615:node22:sensor_temperature to 69.56 °C [QuantityType]

This is all that the binding is doing - from the binding perspective, there is the following activity -:

What’s happening outside of the binding I can’t really say - maybe a broader debug log would help. I do tend to agree that it looks like the thing is being reset, but I don’t think it’s because the binding is updating the properties - if it is, then I’d suggest that’s a bug as it’s done a lot and relinking channels every time a property is updated would not be correct.

[rossko57]

Okay, I did not realise “channel unlinked” was just passing on a report and not binding originated.

This all seems to bring us back to Thing updated as the visible clue, and nobody knows why or who updates it.

[speed (Dima)]

Chris and rossko57, many thanks for your efforts to help!

If I get you right, what would be a good next step is to enable debugging logs for other components. Any suggestions what exactly?

[chris (Chris Jackson)]

Good question - I’m not sure I have a great answer though .

I would probably suggest to simply enable all debug logging. Since you can replicate this pretty easily, you can enable all logging at debug level, and disable it again 30 seconds later after triggering an event. That ensures that you should grab everything/anything that is available and gives us the best chance to see what is going on.

[speed (Dima)]

Didn’t manage to turn on debug logging. When I enable OPENHAB_STARTMODE=debug in /etc/default/openhab2 (because I use the debian package), it is running in a restart loop. Also running start_debug.sh didn’t create any debug logs at all.

However I was able to maybe move a step ahead. The change from NULL to value behavior is only there when either a wake-up is initiated or when the “interval for XYZ report” of the zwave device is triggered. If the device sends a report based on a “XYZ report threshold” then the behaviour is as expected.

Here is the sample:

When “interval for temperature report triggers” the behavior is:

2020-11-05 22:51:50.370 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_binary changed from NULL to ON
2020-11-05 22:51:50.371 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_temperature changed from NULL to 22.31 °C
2020-11-05 22:51:50.373 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_sensor_door changed from NULL to OPEN
2020-11-05 22:51:50.375 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_battery_level changed from NULL to 100.0
2020-11-05 22:51:50.376 [vent.ItemStateChangedEvent] - zwave_device_ddd3b615_node22_alarm_general changed from NULL to ON
2020-11-05 22:51:50.376 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:ddd3b615:node35' has been updated.

When “temperature report threshold” the behavior is:

zwave_device_ddd3b615_node22_sensor_temperature changed from 26.18 °C to 25.56 °C

Not sure what conclusion to draw from this, but wanted to share it.

[chris (Chris Jackson)]

@speed

running in a restart loop. Also running start_debug.sh didn’t create any debug logs at all.

This does not enable debug logging - hence why you got no debug logs. This enables debug access to the JVM only.

To enable debug logging, you need to enable it through the console with the log:set debug * (I think) command.

[speed (Dima)]

Thanks Chris. debug * didnt work but I did it manually for all modules… I also had to remove (grep -v -i http) lines, to shorten a bit the large log size. Hope this is not removing anything of relevance.

Here is the result for that one second in which the unlinking happens (2020-11-06 00:23:15.452):

Ubuntu Pastebin

Any hints you can provide?

[chris (Chris Jackson)]

I don’t really see anything that jumps out. The unlinking doesn’t happen on all updates - it would be good to be a longer log to try and establish a pattern. In this log, it only seems to happen on the wakeup report. However this log is very short with all received messages coming in within around 200ms. This could therefore be misleading if there was a small delay in processing elsewhere, or there was something that happened just before.

I looked at the wakeup event in the binding and can’t see that it is doing anything special - it does update the properties to set the last wakeup time, so it could well be that somewhere else in the system the items are all being reset (as suggested by @rossko57). IMHO if this is the case it’s not correct - updating properties about a Thing should not reset the Items to null (if this is what is happening).

[speed (Dima)]

Thanks Chris! Much appreciated.

Here is a 3 minute DEBUG log around the same event. Hope you can identify something:

Ubuntu Pastebin

[BGrosse (Burki)]

Hi there!

Is there any update on this topic? I also have a test install running continously for around a year now (started with OH 2.5.2 in autumn 2020 afair) and only have ONE - but big - problem left as of now: the sporadically upcoming zwave thing updates which in turn forces item values back to NULL. This results in rules which do not fire at all or at least do not perform as intended (of course - the rule only can work correct when fed correct with correct item values/states).

In my installation I’m still on OH 2.5 with around a dozend Fibaro FGMS-001 Sensors (Firmware 3.3). All of them behave the same: zwave thing updates are ocurring from time to time, leaving the sensors items/values NULL and the rules useless until the items/values are updated by time/event. For the zwave master I’m also using the AEOTEC Z-Stick Gen5+.

So if anyone ever found a solution to this or at least a workaround, please let me know! PLEASE!!!

If further information is needed, please let me also know of course. I will try my best to provide anything which will be of help!

Thank you!