Cannot include any Z-Wave device after hard reset

sloth0815 · July 20, 2017, 6:46pm

I had an issue with a Fibaro FSG-222 relay switch and finally did a hard reset on the UZB stick and removed all Z-Wave devices in the hope that re-inclusion would solve the problem. I have successfully added the controller and when I set it to inclusion mode via PaperUI the stick starts blinking like it should. However, it does not add any device to the inbox. I have installed the latest version of the test binding.
This is the log:

20:39:35.509 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
20:39:35.510 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
20:39:35.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue
20:39:35.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 1
20:39:35.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
20:39:35.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
20:39:35.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
20:39:35.520 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 04 B1
20:39:35.523 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 04 B1
20:39:35.525 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
20:39:35.526 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction Start type AddNodeToNetwork
20:39:35.528 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
20:39:35.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_REQUEST] requiresResponse=true callback: 4
20:39:35.529 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
20:39:35.530 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
20:39:35.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:39:35.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
20:39:35.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:39:40 CEST 2017 - 5000ms
20:39:35.534 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:39:35.535 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 12: [WAIT_REQUEST] requiresResponse=true callback: 4
20:39:35.536 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:39:35.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:39:35.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] requiresResponse=true callback: 4
20:39:35.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
20:39:35.546 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
20:39:35.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
20:39:35.538 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:39:40 CEST 2017 - 4996ms
20:39:35.551 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller end inclusion
20:39:35.552 [DEBUG] [ve.internal.protocol.ZWaveController] - Ending inclusion mode.
20:39:35.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
20:39:35.553 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
20:39:35.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:39:35.554 [DEBUG] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
20:39:35.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:39:40 CEST 2017 - 4979ms
20:39:35.677 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 04 06 00 00 B0
20:39:35.680 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
20:39:35.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=4, payload=04 06 00 00
20:39:35.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=4, payload=04 06 00 00
20:39:35.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=4, payload=04 06 00 00
20:39:35.686 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] requiresResponse=true callback: 4
20:39:35.686 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
20:39:35.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] requiresResponse=true callback: 4
20:39:35.688 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 4)
20:39:35.689 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
20:39:35.689 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 4
20:39:35.691 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=4, payload=04 06 00 00
20:39:35.692 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
20:39:35.692 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
20:39:35.693 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: TransactionAdvance ST: WAIT_REQUEST
20:39:35.694 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: TransactionAdvance WT: null {}
20:39:35.695 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: TransactionAdvance RX: Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=4, payload=04 06 00 00
20:39:35.696 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: TransactionAdvance RQ: RREQ=true, RCLS=null
20:39:35.697 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: TransactionAdvance TO: DONE
20:39:35.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12: Advanced to DONE
20:39:35.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 173ms
20:39:35.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 12: Transaction completed
20:39:35.700 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:12 DONE
20:39:35.701 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:39:35.705 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
20:39:35.705 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
20:39:35.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
20:39:35.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
20:39:35.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:40:04.192 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
20:40:04.193 [DEBUG] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
20:40:04.194 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Starting ZWave inclusion scan for zwave:serial_zstick:15d5c8767fa
20:40:04.196 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
20:40:04.197 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
20:40:04.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue
20:40:04.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 1
20:40:04.201 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
20:40:04.202 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
20:40:04.203 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
20:40:04.206 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 05 74
20:40:04.209 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 05 74
20:40:04.210 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
20:40:04.211 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: Transaction Start type AddNodeToNetwork
20:40:04.213 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 13: [WAIT_REQUEST] requiresResponse=true callback: 5
20:40:04.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
20:40:04.214 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
20:40:04.215 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
20:40:04.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
20:40:04.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:40:04.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:40:09 CEST 2017 - 4999ms
20:40:04.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:40:04.219 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 13: [WAIT_REQUEST] requiresResponse=true callback: 5
20:40:04.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:40:04.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:40:04.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_REQUEST] requiresResponse=true callback: 5
20:40:04.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:40:09 CEST 2017 - 4995ms
20:40:04.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
20:40:04.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
20:40:04.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
20:40:04.223 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 05 01 00 00 B6
20:40:04.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
20:40:04.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:40:04.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:40:09 CEST 2017 - 4989ms
20:40:04.234 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
20:40:04.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=1, callback=5, payload=05 01 00 00
20:40:04.245 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=1, callback=5, payload=05 01 00 00
20:40:04.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=1, callback=5, payload=05 01 00 00
20:40:04.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_REQUEST] requiresResponse=true callback: 5
20:40:04.252 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
20:40:04.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 13: [WAIT_REQUEST] requiresResponse=true callback: 5
20:40:04.254 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 13: (Callback 5)
20:40:04.255 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
20:40:04.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 13: callback 5
20:40:04.258 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=1, callback=5, payload=05 01 00 00
20:40:04.259 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
20:40:04.259 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
20:40:04.261 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: Transaction COMPLETED
20:40:04.262 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: TransactionAdvance ST: DONE
20:40:04.262 [INFO ] [smarthome.event.BindingEvent        ] - org.openhab.binding.zwave.event.BindingEvent@f0f5f0
20:40:04.262 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: TransactionAdvance WT: null {}
20:40:04.264 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: TransactionAdvance RX: Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=1, callback=5, payload=05 01 00 00
20:40:04.265 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: TransactionAdvance TO: DONE
20:40:04.265 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 54ms
20:40:04.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 13: Transaction completed
20:40:04.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:13 DONE
20:40:04.269 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:40:04.273 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
20:40:04.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
20:40:04.275 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
20:40:04.277 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
20:40:04.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:40:34.194 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
20:40:34.196 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
20:40:34.197 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue
20:40:34.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 1
20:40:34.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
20:40:34.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
20:40:34.201 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
20:40:34.206 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 06 B3
20:40:34.209 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 06 B3
20:40:34.211 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
20:40:34.212 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: Transaction Start type AddNodeToNetwork
20:40:34.213 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 14: [WAIT_REQUEST] requiresResponse=true callback: 6
20:40:34.215 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
20:40:34.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
20:40:34.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
20:40:34.221 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
20:40:34.222 [DEBUG] [ve.internal.protocol.ZWaveController] - Ending inclusion mode.
20:40:34.223 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:40:39 CEST 2017 - 4996ms
20:40:34.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:40:34.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 14: [WAIT_REQUEST] requiresResponse=true callback: 6
20:40:34.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:40:34.227 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:40:34.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
20:40:34.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 14: [WAIT_REQUEST] requiresResponse=true callback: 6
20:40:34.230 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:40:39 CEST 2017 - 4990ms
20:40:34.230 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
20:40:34.230 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller end inclusion
20:40:34.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
20:40:34.232 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
20:40:34.232 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
20:40:34.235 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
20:40:34.242 [DEBUG] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
20:40:34.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
20:40:34.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jul 20 20:40:39 CEST 2017 - 4971ms
20:40:34.373 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 06 06 00 00 B2
20:40:34.376 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
20:40:34.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=6, payload=06 06 00 00
20:40:34.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=6, payload=06 06 00 00
20:40:34.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=6, payload=06 06 00 00
20:40:34.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 14: [WAIT_REQUEST] requiresResponse=true callback: 6
20:40:34.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
20:40:34.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 14: [WAIT_REQUEST] requiresResponse=true callback: 6
20:40:34.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 14: (Callback 6)
20:40:34.398 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
20:40:34.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 14: callback 6
20:40:34.405 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=6, payload=06 06 00 00
20:40:34.407 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
20:40:34.410 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
20:40:34.413 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: TransactionAdvance ST: WAIT_REQUEST
20:40:34.415 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: TransactionAdvance WT: null {}
20:40:34.419 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: TransactionAdvance RX: Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], dest=6, callback=6, payload=06 06 00 00
20:40:34.422 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: TransactionAdvance RQ: RREQ=true, RCLS=null
20:40:34.424 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: TransactionAdvance TO: DONE
20:40:34.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 14: Advanced to DONE
20:40:34.430 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 217ms
20:40:34.432 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 14: Transaction completed
20:40:34.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:14 DONE
20:40:34.438 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:40:34.445 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
20:40:34.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
20:40:34.450 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
20:40:34.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
20:40:34.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

Can anybody help out? I have no idea what to do now.

Many thanks,
Jonas

chris · July 20, 2017, 6:55pm

It looks like the controller is entering inclusion mode, but it’s not finding any devices. Have you reset/excluded the device you’re trying to include and then you’re putting it into inclusion mode?

sloth0815 · July 20, 2017, 7:05pm

I have deleted the devices in PaperUI and reset them by for example long pressing a button.

chris · July 20, 2017, 7:18pm

Stupid question, but the only other thing I can think of is that the devices aren’t being put into inclusion mode, or they are out of range of the controller.

sloth0815 · July 20, 2017, 7:20pm

Ok, it seems I did not press for long enough for the reset. Now I managed to include a few devices.
However, I am still not able to include the Fibaro FGS-222 switch. I am following the manual (3 s press to reset, short press to include) but nothing happens. Unfortunately there is no feedback on the switch to confirm a successful reset.

sihui · July 20, 2017, 7:48pm

You need to triple click the button or the switch connected to S1.
You can even include it without any clicking: just apply power and the fgs222 is in inclusion mode for a couple of seconds.

sloth0815 · July 20, 2017, 7:52pm

I have tried triple clicking the B button starting from position “off” and from position “on”. Both times with no success. Just applying power also did not help so I am thinking that maybe the device is not reset properly.

sihui · July 20, 2017, 7:55pm

The reset only works shortly after applying power, so don’t forget this step …

sloth0815 · July 20, 2017, 7:59pm

I removed power, connected power and then pressed the B button for 3 seconds. Waited a bit and tried the inclusion. Nothing.

sihui · July 20, 2017, 8:06pm

Last idea: remove power, press and hold the button, apply power, wait at least 3 seconds, release the button. When I remember correctly you will hear the relay clicking after a successful reset (not sure about that …)

Edit: an additional power break may be needed after the above procedure …

sloth0815 · July 20, 2017, 8:36pm

Wow, that is exactly what worked. Thanks so much. I wish Fibaro had written a proper manual.