Trying to setup my z-wave network on latest openhab 2 beta, and strugging to get any commands to be acknowledged by the devices. Running a win10 VM dedicated to HA, with a aeon labs z-stick gen 5. The logs seems to suggest it’s working, save for these errors:
Error 0x79 at src/windows/termios.c(1323): The semaphore timeout period has expWrite action failed! Input/output error
(Repeats periodically in the console)
[ERROR] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
(shown in log:display zwave)
Thoughts? Suggestions? Is this even related to why I can’t get my door lock to respond to commands?
zwave log when sending a door lock request:
[details=Summary]20:30:45.866 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Command received zwave:device:b3f7119e:node5:lock_door --> ON
20:30:45.870 [DEBUG] [mmandclass.ZWaveDoorLockCommandClass] - NODE 5: Creating new message for application command DOORLOCK_SET
20:30:45.873 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:30:45.873 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 62 01 FF 25 2F 76
20:30:45.873 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 62 01 FF 25 2F 76
20:30:45.873 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
20:30:46.064 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
20:30:46.067 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:30:46.067 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
20:30:46.067 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
20:30:46.067 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
20:30:46.067 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
20:30:47.342 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2F 00 00 81 45
20:30:47.346 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:30:47.347 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 2F 00 00 81 00 00 4B
20:30:47.347 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 2F 00 00 81 00 00 4B
20:30:47.347 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=2F 00 00 81
20:30:47.347 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 47, Status = Transmission complete and ACK received(0)
20:30:47.347 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Node is ALIVE. Init stage is VERSION.
20:30:47.347 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
20:30:47.347 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveNodeStatusEvent
20:30:47.347 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Setting ONLINE
20:30:47.348 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node Status event during initialisation - Node is ALIVE
20:30:47.348 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - VERSION: queue length(0), free to send(true)
20:30:47.348 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Initialisation retry timer started 320000
20:30:47.348 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: loop - VERSION try 1: stageAdvanced(false)
20:30:47.349 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking USER_CODE, version is 0
20:30:47.349 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued USER_CODE
20:30:47.349 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 5: Creating new message for application command VERSION_COMMAND_CLASS_GET command class USER_CODE
20:30:47.349 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - queued packet. Queue length is 1
20:30:47.349 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:30:47.349 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking MANUFACTURER_SPECIFIC, version is 0
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued MANUFACTURER_SPECIFIC
20:30:47.350 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 5: Creating new message for application command VERSION_COMMAND_CLASS_GET command class MANUFACTURER_SPECIFIC
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking LOCK, version is 0
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued LOCK
20:30:47.350 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 5: Creating new message for application command VERSION_COMMAND_CLASS_GET command class LOCK
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking BASIC, version is 0
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued BASIC
20:30:47.350 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 5: Creating new message for application command VERSION_COMMAND_CLASS_GET command class BASIC
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking VERSION, version is 0
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued VERSION
20:30:47.350 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 5: Creating new message for application command VERSION_COMMAND_CLASS_GET command class VERSION
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking NO_OPERATION, version is 1
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - checking DOOR_LOCK, version is 0
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued DOOR_LOCK
20:30:47.350 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 5: Creating new message for application command VERSION_COMMAND_CLASS_GET command class DOOR_LOCK
20:30:47.350 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: VERSION - queued 6 frames
20:30:47.351 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 5: Node Status event - Node is ALIVE
20:30:47.351 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=5, callback=47, payload=05 03 62 01 FF
20:30:47.351 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=2F 00 00 81
20:30:47.351 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=47, expected=SendData, cancelled=false transaction complete!
20:30:47.351 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:30:47.351 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
20:30:47.351 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - VERSION: Transaction complete (SendData:Request) success(true)
20:30:47.351 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - checking initialisation queue. Queue size 6.
20:30:47.351 [DEBUG] [curityCommandClassWithInitialization] - NODE 5: updating lastSentMessageTimestamp
20:30:47.351 [DEBUG] [curityCommandClassWithInitialization] - NODE 5: updating lastSentMessageTimestamp
20:30:47.351 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Response processed after 1294ms/1308ms.
20:30:47.351 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:30:47.351 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 86 13 63 25 30 03
20:30:47.351 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 86 13 63 25 30 03
20:30:47.363 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
20:30:47.366 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:30:47.366 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
20:30:47.366 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
20:30:47.366 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
20:30:47.366 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
20:30:47.380 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 30 00 00 03 D8
20:30:47.385 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:30:47.385 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 30 00 00 03 00 00 D6
20:30:47.385 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 30 00 00 03 00 00 D6
20:30:47.385 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=30 00 00 03
20:30:47.385 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 48, Status = Transmission complete and ACK received(0)
20:30:47.385 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=5, callback=48, payload=05 03 86 13 63
20:30:47.385 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=30 00 00 03
20:30:47.385 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=48, expected=ApplicationCommandHandler, cancelled=false MISMATCH
20:30:52.356 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 2 attempts left!
20:30:52.356 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
20:30:52.356 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:30:52.356 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:30:52.356 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 86 13 63 25 31 02
20:30:52.356 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 86 13 63 25 31 02
Error 0x79 at src/windows/termios.c(1323): The semaphore timeout period has expWrite action failed! Input/output error20:30:52.659 [ERROR] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
20:30:57.661 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA
20:30:57.661 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Sending ABORT Message = 01 03 00 16 EA
20:30:57.661 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA
20:30:57.661 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA
20:30:57.744 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 1 attempts left!
20:30:57.744 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
20:30:57.744 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:30:57.744 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:30:57.744 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 86 13 63 25 32 01
20:30:57.744 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 86 13 63 25 32 01
20:30:57.759 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
20:30:57.765 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:30:57.765 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
20:30:57.765 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
20:30:57.765 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
20:30:57.765 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
20:30:59.018 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 32 00 00 7E A7
20:30:59.023 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:30:59.023 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 32 00 00 7E 00 00 A9
20:30:59.023 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 32 00 00 7E 00 00 A9
20:30:59.023 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=32 00 00 7E
20:30:59.023 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 50, Status = Transmission complete and ACK received(0)
20:30:59.023 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=5, callback=50, payload=05 03 86 13 63
20:30:59.023 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=32 00 00 7E
20:30:59.023 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=50, expected=ApplicationCommandHandler, cancelled=false MISMATCH
20:31:02.750 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 0 attempts left!
20:31:02.750 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
20:31:02.750 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:31:02.750 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:31:02.750 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 86 13 63 25 33 00
20:31:02.750 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 86 13 63 25 33 00
Error 0x79 at src/windows/termios.c(1323): The semaphore timeout period has expWrite action failed! Input/output error20:31:03.383 [ERROR] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
20:31:08.385 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA
Error 0x79 at src/windows/termios.c(1323): The semaphore timeout period has exp20:31:08.385 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Sending ABORT Message = 01 03 00 16 EA
20:31:08.385 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA
20:31:08.385 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA
Write action failed! Input/output error20:31:13.447 [ERROR] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
20:31:13.447 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=5, callback=51, payload=05 03 86 13 63[/details]