2.4 snapshot, zwavereceiveThread exiting

New to openhab, I’m trying to get started with openhab on Macos 10.13.6, Z-Stick Gen5, and a single GE plugin smart switch 28169.

Openhab stable 2.3.0 could see the controller and plug but could not control it. I gave up and went to the latest Mac Openhab 2.4 snapshot, build #1431, and zwave binding version 2.4.0.201811181037. It was able to bind and control the smart plug in a brief test.

I got interrupted, came back to it a few hours later, and though openhab thinks the plug and controller are online, and it acts as if it is controlling the plug, the plug itself never changes state (never turns on/off). The logs show that the ZwaveReceiveThread exited at 16:11:03.907, though the transmit side (seems to be ZWaveSerialHandler?) is still going and not complaining and the GUI thinks all is well (“online”). The serial port (/dev/cu.usbmodem1411) exists, and is still in the configuration. It is possible the computer went to sleep while I was away from it. The ZStick is blinking its happy signal.

I’m surprised the GUI shows no errors after the receive thread exited.

The error message doesn’t make much sense. The configuration shows the correct serial port. I wonder if it was a transient problem and would have cleared up if the receivethread were restarted.

16:10:47.162 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 600 seconds - start in 293400 milliseconds.
16:10:47.164 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
16:10:47.172 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 25 02 25 02 E5 
16:10:47.172 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
16:10:47.173 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
16:10:47.180 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
16:10:47.196 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 02 00 00 02 EB 
16:10:47.207 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 25 03 FF 2A 
16:10:47.211 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
16:10:47.211 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_BINARY, value = 255
16:10:47.212 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:27ed8cd7:node2:switch_binary to ON [OnOffType]
16:10:47.216 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
16:10:47.227 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 73 02 25 03 B2 
16:10:47.227 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
16:10:47.228 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
16:10:47.235 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
16:10:47.251 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 03 00 00 02 EA 
16:10:47.262 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 02 04 73 03 00 00 87 
16:10:47.266 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWavePowerLevelCommandClassChangeEvent
16:10:47.267 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_POWERLEVEL, value = 0
16:10:47.268 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
16:10:47.271 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
16:10:47.281 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
16:11:03.905 [ERROR] [ZWaveSerialHandler$ZWaveReceiveThread] - Got I/O exception Device not configured in readByte during receiving. exiting thread.
16:11:03.907 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive
16:11:58.820 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:27ed8cd7:node2:switch_binary --> OFF [OnOffType]
16:11:58.823 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 25 01 00 25 04 E2 
16:11:58.823 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
16:11:58.824 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 600 seconds - start in 1500 milliseconds.
16:12:00.329 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
16:12:00.330 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:27ed8cd7:node2:switch_binary
16:12:00.332 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling skipped for zwave:device:27ed8cd7:node2:switch_binary on COMMAND_CLASS_BASIC
16:12:00.333 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:27ed8cd7:node2:scene_number
16:12:00.832 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA