openhabforum.de

Hallo,

Ich bin neu hier, und habe
Openhab, Neu, mit Aoetch gen5 mit Fibaro doubleswitch
Ich habe ein unerklärbares issue.

Ich habe mein SD karte mit win 32diskimager koppert.
Z-Wave war nicht da, und nach löschen des Schalters und Neuaufnahme hat alles scheinbar funktioniert.
Allerdings hatte ich immer nach ca 10-25 Stunden den Fehler

2019-09-24 20:13:43.388 [hingStatusInfoChangedEvent] - 'zwave:device:1accf42b:node2' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2019-09-24 20:13:43.567 [hingStatusInfoChangedEvent] - 'zwave:device:1accf42b:node2' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE
2019-09-24 20:14:47.093 [hingStatusInfoChangedEvent] - 'zwave:device:1accf42b:node2' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2019-09-24 20:29:06.668 [hingStatusInfoChangedEvent] - 'zwave:device:1accf42b:node2' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

Jetzt habe ich die Alte SD karte wieder rein und es geht.
Bis ich das raus gefunden habe war ich kurz vor dem Umstellen auf homematic.

Kann Mir jemand sagen an was das liegen kann,

Grüße Frank

Franky hat geschrieben: ↑30. Sep 2019 20:08 Kann Mir jemand sagen an was das liegen kann,

Mit den spärlichen Angaben die du gemacht hast ist das fast unmöglich.
Die Fehlermeldung deutet auf ein Reichweitenproblem hin.

Genaueres könnte man erst sagen wenn du mehr Angaben machst:
- welche openHAB Version, welche Installationsmethode
- welche Zwave Binding Version
- wieviele Zwave Geräte sind im Netzwerk, aufgeteilt nach batteriebetriebenen Geräten und Geräten die mit Netzspannung versorgt werden (nur Geräte die mit Netzspannung bzw. Netzteil versorgt werden bilden ein Mesh Netzwerk und erhöhen die Reichweite)
- ein DEBUG Log anstatt eines INFO log.
- Welche Nachbarn hat welches Zwave Gerät (schön grafisch zu sehen in HABmin)

Hallo,
Sorry für die Verwirrung, die Frage war mehr Architektonisch.
Wie kann das sein, welche Komponente, kann folgenden Fehler produzieren.
Und da der Fehler mit tausch der kopierten, SD Karte wandert, muss es ja Software sein.
Ich kann nicht begreifen, dass ein höchst Sporradischer , Fehler, an Software liegen kann.
z-wave 2.4
Openhab vor 5 Tagen installiert.
Nur das eine Fibaro gerät dran.

Gruß Frank

Franky hat geschrieben: ↑1. Okt 2019 11:23 z-wave 2.4

Ich habe leider keine Kristallkugel, bitte ein DEBUG Log erzeugen und posten.

https://www.openhab.org/addons/bindings ... as-planned

Hallo, ich hatte gehofft es war ein einmaliger Fehler
Aber heute habe ich sie SANDIK extream karte wieder rein,
Komplett Neu Installiert mit openhabian Image
Den AEOTCH gen 5 resttet
und einen neuen Fibaro doppelswitch, (am Alten war der schlater defeket.
Und nun habe ich das problem wieder, desmal aber mit debug.
am Anfang ist der fehler,
dann hab ich auf debug geschaltet und den switch1 betätigt in openhab

Code: Alles auswählen

2019-10-02 21:08:29.131 [ome.event.ItemCommandEvent] - Item 'Teich_Switch1' received command OFF
2019-10-02 21:08:29.141 [nt.ItemStatePredictedEvent] - Teich_Switch1 predicted to become OFF
2019-10-02 21:08:29.152 [vent.ItemStateChangedEvent] - Teich_Switch1 changed from ON to OFF
2019-10-02 21:08:29.610 [vent.ItemStateChangedEvent] - Teich_ElectricMeterWatts1 changed from 7.8 to 0
2019-10-02 21:38:43.032 [hingStatusInfoChangedEvent] - 'zwave:device:b7a721e3:node3' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2019-10-02 21:52:20.631 [hingStatusInfoChangedEvent] - 'zwave:device:b7a721e3:node3' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE
2019-10-02 22:06:26.920 [ome.event.ItemCommandEvent] - Item 'Teich_Switch1' received command ON
2019-10-02 22:06:26.931 [nt.ItemStatePredictedEvent] - Teich_Switch1 predicted to become ON
2019-10-02 22:06:26.939 [vent.ItemStateChangedEvent] - Teich_Switch1 changed from OFF to ON
2019-10-02 22:06:39.382 [hingStatusInfoChangedEvent] - 'zwave:device:b7a721e3:node3' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2019-10-02 22:08:28.875 [hingStatusInfoChangedEvent] - 'zwave:device:b7a721e3:node3' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE
2019-10-02 22:09:40.231 [ome.event.ItemCommandEvent] - Item 'Teich_Switch1' received command OFF
2019-10-02 22:09:40.242 [nt.ItemStatePredictedEvent] - Teich_Switch1 predicted to become OFF
2019-10-02 22:09:40.259 [vent.ItemStateChangedEvent] - Teich_Switch1 changed from ON to OFF
2019-10-02 22:09:47.649 [ome.event.ItemCommandEvent] - Item 'Teich_Switch1' received command ON
2019-10-02 22:09:47.662 [nt.ItemStatePredictedEvent] - Teich_Switch1 predicted to become ON
2019-10-02 22:09:47.674 [vent.ItemStateChangedEvent] - Teich_Switch1 changed from OFF to ON
2019-10-02 22:09:52.626 [hingStatusInfoChangedEvent] - 'zwave:device:b7a721e3:node3' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2019-10-02 22:11:43.816 [ome.event.ItemCommandEvent] - Item 'Teich_Switch1' received command OFF
==> /var/log/openhab2/openhab.log <==
2019-10-02 22:11:43.893 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Command received zwave:device:b7a721e3:node3:switch_binary1 --> OFF [OnOffType]
==> /var/log/openhab2/events.log <==
2019-10-02 22:11:43.900 [nt.ItemStatePredictedEvent] - Teich_Switch1 predicted to become ON
==> /var/log/openhab2/openhab.log <==
2019-10-02 22:11:43.908 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 3: Creating new message for application command SWITCH_BINARY_SET
2019-10-02 22:11:43.912 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 1
2019-10-02 22:11:43.915 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2019-10-02 22:11:43.917 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-10-02 22:11:43.920 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-10-02 22:11:43.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:43.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 346 to queue - size 1
2019-10-02 22:11:43.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:11:43.930 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 25 01 00 25 81 0B 
2019-10-02 22:11:43.933 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 25 01 00 25 81 0B 
2019-10-02 22:11:43.935 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:11:43.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2019-10-02 22:11:43.939 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:11:43.941 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling intialised at 1800 seconds - start in 1500 milliseconds.
2019-10-02 22:11:43.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:43.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:43.948 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:11:43.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2019-10-02 22:11:43.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:11:43.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:43.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:43.956 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:43.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:43.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2019-10-02 22:11:43.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:43.966 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2019-10-02 22:11:43.968 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:43.970 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:11:43.972 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 346: Advanced to WAIT_REQUEST
2019-10-02 22:11:43.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 346: Transaction not completed
2019-10-02 22:11:43.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:43.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:45.441 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...
2019-10-02 22:11:45.446 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling zwave:device:b7a721e3:node3:switch_binary1
2019-10-02 22:11:45.450 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 3: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1
2019-10-02 22:11:45.453 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 3: Creating new message for application command SWITCH_BINARY_GET
2019-10-02 22:11:45.457 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 1
2019-10-02 22:11:45.460 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2019-10-02 22:11:45.464 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-10-02 22:11:45.468 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-10-02 22:11:45.472 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling skipped for zwave:device:b7a721e3:node3:switch_binary1 on COMMAND_CLASS_BASIC
2019-10-02 22:11:45.476 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling zwave:device:b7a721e3:node3:meter_watts1
2019-10-02 22:11:45.479 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 3: Generating poll message for COMMAND_CLASS_METER, endpoint 1
2019-10-02 22:11:45.482 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 3: Generating poll message for COMMAND_CLASS_METER, endpoint 1
2019-10-02 22:11:45.485 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 3: Creating new message for application command METER_GET
2019-10-02 22:11:45.489 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 1
2019-10-02 22:11:45.492 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2019-10-02 22:11:45.496 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-10-02 22:11:45.499 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-10-02 22:11:45.502 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling zwave:device:b7a721e3:node3:switch_binary2
2019-10-02 22:11:45.505 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 3: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 2
2019-10-02 22:11:45.509 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 3: Creating new message for application command SWITCH_BINARY_GET
2019-10-02 22:11:45.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 2
2019-10-02 22:11:45.515 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 2
2019-10-02 22:11:45.519 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-10-02 22:11:45.522 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-10-02 22:11:45.525 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling skipped for zwave:device:b7a721e3:node3:switch_binary2 on COMMAND_CLASS_BASIC
2019-10-02 22:11:45.529 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling zwave:device:b7a721e3:node3:meter_watts2
2019-10-02 22:11:45.532 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 3: Generating poll message for COMMAND_CLASS_METER, endpoint 2
2019-10-02 22:11:45.535 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 3: Generating poll message for COMMAND_CLASS_METER, endpoint 2
2019-10-02 22:11:45.538 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 3: Creating new message for application command METER_GET
2019-10-02 22:11:45.541 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 2
2019-10-02 22:11:45.544 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 2
2019-10-02 22:11:45.548 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-10-02 22:11:45.551 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-10-02 22:11:45.555 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:45.559 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 347 to queue - size 1
2019-10-02 22:11:45.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:45.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:45.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 348 to queue - size 2
2019-10-02 22:11:45.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:45.576 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:45.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 349 to queue - size 3
2019-10-02 22:11:45.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:45.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:45.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 350 to queue - size 4
2019-10-02 22:11:45.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:48.034 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 81 01 01 99 F3 
2019-10-02 22:11:48.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=129, payload=81 01 01 99 
2019-10-02 22:11:48.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=129, payload=81 01 01 99 
2019-10-02 22:11:48.045 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 129
2019-10-02 22:11:48.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:48.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 346: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 129
2019-10-02 22:11:48.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 346: (Callback 129)
2019-10-02 22:11:48.057 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:11:48.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 346: callback 129
2019-10-02 22:11:48.064 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=129, payload=81 01 01 99 
2019-10-02 22:11:48.067 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 129, Status = Transmission complete, no ACK received(1)
2019-10-02 22:11:48.070 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 346: Transaction CANCELLED
2019-10-02 22:11:48.073 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:11:48.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left!
2019-10-02 22:11:48.079 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 346: Transaction RESET with 2 retries remaining.
2019-10-02 22:11:48.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:48.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 346 to queue - size 5
2019-10-02 22:11:48.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:11:48.093 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 25 01 00 25 82 08 
2019-10-02 22:11:48.097 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 25 01 00 25 82 08 
2019-10-02 22:11:48.105 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:11:48.107 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:11:48.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2019-10-02 22:11:48.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:48.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 346: Transaction not completed
2019-10-02 22:11:48.116 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:48.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2019-10-02 22:11:48.118 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:11:48.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:48.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:11:48.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:48.130 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2019-10-02 22:11:48.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:48.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2019-10-02 22:11:48.140 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:48.143 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:11:48.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 346: Advanced to WAIT_REQUEST
2019-10-02 22:11:48.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 346: Transaction not completed
2019-10-02 22:11:48.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:48.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:52.248 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 82 01 01 9E F7 
2019-10-02 22:11:52.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=130, payload=82 01 01 9E 
2019-10-02 22:11:52.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=130, payload=82 01 01 9E 
2019-10-02 22:11:52.262 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 130
2019-10-02 22:11:52.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:52.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 346: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 130
2019-10-02 22:11:52.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 346: (Callback 130)
2019-10-02 22:11:52.279 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:11:52.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 346: callback 130
2019-10-02 22:11:52.287 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=130, payload=82 01 01 9E 
2019-10-02 22:11:52.290 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 130, Status = Transmission complete, no ACK received(1)
2019-10-02 22:11:52.294 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 346: Transaction CANCELLED
2019-10-02 22:11:52.297 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:11:52.302 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 1 attempts left!
2019-10-02 22:11:52.304 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 346: Transaction RESET with 1 retries remaining.
2019-10-02 22:11:52.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:11:52.312 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 346 to queue - size 5
2019-10-02 22:11:52.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:11:52.320 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 25 01 00 25 83 09 
2019-10-02 22:11:52.325 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 25 01 00 25 83 09 
2019-10-02 22:11:52.329 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:11:52.331 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:11:52.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:52.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 346: Transaction not completed
2019-10-02 22:11:52.339 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:52.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:52.343 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:52.344 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:11:52.347 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:52.349 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:52.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:52.355 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:11:52.357 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:52.360 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:52.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:52.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 346: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:52.366 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:52.369 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:11:52.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 346: Advanced to WAIT_REQUEST
2019-10-02 22:11:52.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 346: Transaction not completed
2019-10-02 22:11:52.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:52.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:56.486 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 83 01 01 A0 C8 
2019-10-02 22:11:56.490 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=131, payload=83 01 01 A0 
2019-10-02 22:11:56.494 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=131, payload=83 01 01 A0 
2019-10-02 22:11:56.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 346: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:56.501 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:56.504 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 346: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:56.508 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 346: (Callback 131)
2019-10-02 22:11:56.511 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:11:56.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 346: callback 131
2019-10-02 22:11:56.519 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=131, payload=83 01 01 A0 
2019-10-02 22:11:56.522 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 131, Status = Transmission complete, no ACK received(1)
2019-10-02 22:11:56.527 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 346: Transaction CANCELLED
2019-10-02 22:11:56.530 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:11:56.534 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Retry count exceeded. Discarding message: TID 346: [CANCELLED] priority=Set, requiresResponse=true, callback: 131
2019-10-02 22:11:56.537 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 346: Transaction completed
2019-10-02 22:11:56.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:346 CANCELLED
2019-10-02 22:11:56.545 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:11:56.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:56.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:11:56.557 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 84 0F 
2019-10-02 22:11:56.561 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 84 0F 
2019-10-02 22:11:56.565 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:11:56.568 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:11:56.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 132
2019-10-02 22:11:56.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:56.576 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:11:56.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 132
2019-10-02 22:11:56.579 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:11:56.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:11:56.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:56.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:56.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:11:56.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:56.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 132
2019-10-02 22:11:56.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:11:56.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 132
2019-10-02 22:11:56.605 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:11:56.607 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:11:56.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 347: Advanced to WAIT_REQUEST
2019-10-02 22:11:56.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 347: Transaction not completed
2019-10-02 22:11:56.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:11:56.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:00.694 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 84 01 01 9C F3 
2019-10-02 22:12:00.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=132, payload=84 01 01 9C 
2019-10-02 22:12:00.702 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=132, payload=84 01 01 9C 
2019-10-02 22:12:00.705 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 132
2019-10-02 22:12:00.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:00.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 347: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 132
2019-10-02 22:12:00.715 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 347: (Callback 132)
2019-10-02 22:12:00.718 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:12:00.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 347: callback 132
2019-10-02 22:12:00.726 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=132, payload=84 01 01 9C 
2019-10-02 22:12:00.730 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 132, Status = Transmission complete, no ACK received(1)
2019-10-02 22:12:00.732 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 347: Transaction CANCELLED
2019-10-02 22:12:00.736 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:12:00.739 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left!
2019-10-02 22:12:00.742 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 347: Transaction RESET with 2 retries remaining.
2019-10-02 22:12:00.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:12:00.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 347 to queue - size 4
2019-10-02 22:12:00.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:12:00.755 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 85 0E 
2019-10-02 22:12:00.759 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 85 0E 
2019-10-02 22:12:00.763 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:12:00.766 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:12:00.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2019-10-02 22:12:00.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:00.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 347: Transaction not completed
2019-10-02 22:12:00.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:00.777 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:12:00.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2019-10-02 22:12:00.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:12:00.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:00.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:00.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:00.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:00.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2019-10-02 22:12:00.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:00.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2019-10-02 22:12:00.802 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:00.807 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:12:00.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 347: Advanced to WAIT_REQUEST
2019-10-02 22:12:00.813 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 347: Transaction not completed
2019-10-02 22:12:00.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:00.819 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:04.876 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 85 01 01 9B F5 
2019-10-02 22:12:04.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=133, payload=85 01 01 9B 
2019-10-02 22:12:04.884 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=133, payload=85 01 01 9B 
2019-10-02 22:12:04.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 133
2019-10-02 22:12:04.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:04.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 347: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 133
2019-10-02 22:12:04.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 347: (Callback 133)
2019-10-02 22:12:04.899 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:12:04.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 347: callback 133
2019-10-02 22:12:04.905 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=133, payload=85 01 01 9B 
2019-10-02 22:12:04.909 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 133, Status = Transmission complete, no ACK received(1)
2019-10-02 22:12:04.912 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 347: Transaction CANCELLED
2019-10-02 22:12:04.915 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:12:04.918 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 1 attempts left!
2019-10-02 22:12:04.920 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 347: Transaction RESET with 1 retries remaining.
2019-10-02 22:12:04.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:12:04.931 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 347 to queue - size 4
2019-10-02 22:12:04.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:12:04.938 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 86 0D 
2019-10-02 22:12:04.942 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 86 0D 
2019-10-02 22:12:04.945 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:12:04.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:04.948 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:12:04.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 347: Transaction not completed
2019-10-02 22:12:04.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:04.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:04.957 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:04.958 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:12:04.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:04.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:04.967 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:12:04.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:04.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:04.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:04.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:04.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:04.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:04.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 347: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:04.995 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:04.998 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:12:05.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 347: Advanced to WAIT_REQUEST
2019-10-02 22:12:05.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 347: Transaction not completed
2019-10-02 22:12:05.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:05.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:09.058 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 86 01 01 9B F6 
2019-10-02 22:12:09.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=134, payload=86 01 01 9B 
2019-10-02 22:12:09.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=134, payload=86 01 01 9B 
2019-10-02 22:12:09.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 347: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:09.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:09.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 347: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:09.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 347: (Callback 134)
2019-10-02 22:12:09.086 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:12:09.088 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 347: callback 134
2019-10-02 22:12:09.092 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=134, payload=86 01 01 9B 
2019-10-02 22:12:09.095 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 134, Status = Transmission complete, no ACK received(1)
2019-10-02 22:12:09.098 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 347: Transaction CANCELLED
2019-10-02 22:12:09.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:12:09.104 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Retry count exceeded. Discarding message: TID 347: [CANCELLED] priority=Get, requiresResponse=true, callback: 134
2019-10-02 22:12:09.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 347: Transaction completed
2019-10-02 22:12:09.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:347 CANCELLED
2019-10-02 22:12:09.114 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:12:09.116 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:09.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:12:09.123 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 32 01 10 25 87 0A 
2019-10-02 22:12:09.127 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 32 01 10 25 87 0A 
2019-10-02 22:12:09.130 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:12:09.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 135
2019-10-02 22:12:09.134 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:12:09.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:09.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:09.145 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 135
2019-10-02 22:12:09.145 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:12:09.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:12:09.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:09.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:09.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:09.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:09.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 135
2019-10-02 22:12:09.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:09.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 135
2019-10-02 22:12:09.176 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:09.180 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:12:09.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 348: Advanced to WAIT_REQUEST
2019-10-02 22:12:09.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 348: Transaction not completed
2019-10-02 22:12:09.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:09.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:13.244 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 87 01 01 9A F6 
2019-10-02 22:12:13.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=135, payload=87 01 01 9A 
2019-10-02 22:12:13.254 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=135, payload=87 01 01 9A 
2019-10-02 22:12:13.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 348: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 135
2019-10-02 22:12:13.261 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:13.264 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 348: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 135
2019-10-02 22:12:13.268 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 348: (Callback 135)
2019-10-02 22:12:13.272 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:12:13.277 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 348: callback 135
2019-10-02 22:12:13.280 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=135, payload=87 01 01 9A 
2019-10-02 22:12:13.284 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 135, Status = Transmission complete, no ACK received(1)
2019-10-02 22:12:13.287 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 348: Transaction CANCELLED
2019-10-02 22:12:13.291 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:12:13.294 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left!
2019-10-02 22:12:13.306 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 348: Transaction RESET with 2 retries remaining.
2019-10-02 22:12:13.312 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:12:13.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 348 to queue - size 3
2019-10-02 22:12:13.319 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:12:13.323 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 32 01 10 25 88 05 
2019-10-02 22:12:13.327 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 32 01 10 25 88 05 
2019-10-02 22:12:13.331 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:12:13.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 136
2019-10-02 22:12:13.334 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:12:13.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 348: Transaction not completed
2019-10-02 22:12:13.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:13.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:13.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:13.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:13.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 136
2019-10-02 22:12:13.352 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-10-02 22:12:13.354 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-10-02 22:12:13.357 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:13.360 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:13.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:13.367 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:13.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 136
2019-10-02 22:12:13.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:13.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 136
2019-10-02 22:12:13.382 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-10-02 22:12:13.387 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-10-02 22:12:13.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 348: Advanced to WAIT_REQUEST
2019-10-02 22:12:13.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 348: Transaction not completed
2019-10-02 22:12:13.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-10-02 22:12:13.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-10-02 22:12:17.473 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 88 01 01 9D FE 
2019-10-02 22:12:17.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=136, payload=88 01 01 9D 
2019-10-02 22:12:17.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=136, payload=88 01 01 9D 
2019-10-02 22:12:17.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 348: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 136
2019-10-02 22:12:17.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-10-02 22:12:17.494 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 348: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 136
2019-10-02 22:12:17.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 348: (Callback 136)
2019-10-02 22:12:17.500 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-10-02 22:12:17.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 348: callback 136
2019-10-02 22:12:17.508 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=136, payload=88 01 01 9D 
2019-10-02 22:12:17.511 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 136, Status = Transmission complete, no ACK received(1)
2019-10-02 22:12:17.515 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 348: Transaction CANCELLED
2019-10-02 22:12:17.519 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-10-02 22:12:17.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 1 attempts left!
2019-10-02 22:12:17.525 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 348: Transaction RESET with 1 retries remaining.
2019-10-02 22:12:17.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-10-02 22:12:17.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 348 to queue - size 3
2019-10-02 22:12:17.534 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-10-02 22:12:17.538 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 32 01 10 25 89 04 
2019-10-02 22:12:17.542 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 32 01 10 25 89 04 
2019-10-02 22:12:17.545 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-10-02 22:12:17.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 348: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 137
2019-10-02 22:12:17.548 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-10-02 22:12:17.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 348: Transaction not completed
2019-10-02 22:12:17.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-10-02 22:12:17.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
02 25 8B 03

Das sind die Daten vom Empfänger switch,
dbReference 416
defaultAssociations 1
manufacturerId 010F
manufacturerRef 0203:1000,0203:2000,0203:3000,0203:4000
modelId FGS223
vendor Fibargroup
zwave_beaming true
zwave_class_basic BASIC_TYPE_ROUTING_SLAVE
zwave_class_generic GENERIC_TYPE_SWITCH_BINARY
zwave_class_specific SPECIFIC_TYPE_POWER_SWITCH_BINARY
zwave_deviceid 4096
zwave_devicetype 515
zwave_frequent false
zwave_listening true
zwave_manufacturer 271
zwave_neighbours
zwave_nodeid 3
zwave_plus_devicetype NODE_TYPE_ZWAVEPLUS_NODE
zwave_plus_roletype ROLE_TYPE_SLAVE_ALWAYS_ON
zwave_routing true
zwave_secure false
zwave_version 3.2

Und das sind die 2 Z-Wave devices

Teich OFFLINE - COMMUNICATION_ERROR
FGS223 Double Switch 2
zwave:device:b7a721e3:node3

Z-Wave Serial Controller ONLINE
Z-Wave Serial Controller
zwave:serial_zstick:b7a721e3

Franky hat geschrieben: ↑2. Okt 2019 22:20 dann hab ich auf debug geschaltet und den switch1 betätigt in openhab

Wenn du das DEBUG Log über den Zwave Log Viewer https://www.cd-jackson.com/index.php/op ... log-viewer laufen lässt siehst du das du massive Aussetzer in der Kommunikation hast:

timeout.JPG

Wahrscheinlich ist der FGS223 zu weit vom Controller entfernt. Setze ihn mal in etwa 1-3 Meter Entfernung zum Controller und versuche es nach einem nächtlichen Netzwerk Heal (findet grundsätzlich nachts um 02:00 Uhr statt falls du es nicht geändert hast) noch einmal.

Danke Sihui, für die Mühe.
Und jetzt erklär mir mal wie das an einer sd karte liegen kann.
Ich hab die gegenprobe t mal gemacht.
Zum schluss sogar neu installiert.
Ich werde das z-wave zeug zurück schicken. Und mir homatic kaufen.
Solche Geisterfehler, kann ich im produktivem einsatz nicht gebrauchen,
Danke nochmal

Ich kann sihui nur zustimmen. Scheint ein Reichweitenproblem zu sein, da er immer wieder Offline geht.
Oder beim Klonen der SD-Karte ist was schief gelaufen. HAbe es mehrmals gemacht ohne Probleme.
Hier ist das nochmal genau und gut beschrieben:
[https://www.randombrick.de/raspberry-pi ... erstellen/][/code]

Vielleicht probierst du es nochmal.
GRuß
Oliver

openhabforum.de

Z-Wave Fehler nach SD card copy

Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy

Re: Z-Wave Fehler nach SD card copy