openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.87k stars 3.58k forks source link

Z-Wave: Exception during ZWave thread: Input 2 #815

Closed maggu2810 closed 8 years ago

maggu2810 commented 8 years ago

Hi, I added a Fibaro Motion Sensor (the eye). The device has a wakeup button. Every time I press this button I see "Exception during ZWave thread: Input 2" and I do not get any value displayed.

I set the log level of the Z-Wave binding to debug. I call "log:tail" and press the button, after a few seconds, I break that log and repeat the procedure. So every lines after log:tail will show one button press (and perhaps some timing related stuff).

2016-04-21 08:54:52,828 | INFO  | ESH-safeCall-54  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 632
2016-04-21 08:54:52,830 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:54:52,835 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:54:52,839 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:54:52,842 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:54:52,847 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C 
2016-04-21 08:54:52,851 | DEBUG | ZWaveInputThread | ApplicationUpdateMessageClass    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application update request. Node information received.
2016-04-21 08:54:52,863 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Is awake with 0 messages in the wake-up queue.
2016-04-21 08:54:52,865 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveWakeUpEvent
2016-04-21 08:54:52,867 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveWakeUpEvent
2016-04-21 08:54:52,869 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=121, payload=02 02 84 08 
2016-04-21 08:54:52,873 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C 
2016-04-21 08:54:52,875 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: class=ApplicationUpdate, callback id=121, expected=SendData, cancelled=false      MISMATCH
2016-04-21 08:54:52,901 | INFO  | ESH-safeCall-55  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 631 to 632
2016-04-21 08:54:53,869 | DEBUG | Timer-7          | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: No more messages, go back to sleep
2016-04-21 08:54:53,871 | DEBUG | Timer-7          | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2016-04-21 08:54:53,873 | DEBUG | ZWaveSendThread  | ZWaveController$ZWaveSendThread  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Took message from queue for sending. Queue length = 0
2016-04-21 08:54:53,873 | DEBUG | Timer-7          | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message queued. Queue length = 1. Queue={}
2016-04-21 08:54:53,876 | DEBUG | ZWaveSendThread  | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 09 00 13 02 02 84 08 25 7A 36 
2016-04-21 08:54:53,878 | DEBUG | ZWaveSendThread  | ZWaveSerialHandler               | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 08 25 7A 36 
2016-04-21 08:54:53,888 | INFO  | ESH-safeCall-55  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_ack updated to 203
2016-04-21 08:54:53,891 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 04 01 13 01 E8 
2016-04-21 08:54:53,899 | INFO  | ESH-safeCall-51  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 633
2016-04-21 08:54:53,901 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:54:53,903 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 04 01 13 01 E8 
2016-04-21 08:54:53,910 | INFO  | ESH-safeCall-52  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 634
2016-04-21 08:54:53,919 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 04 01 13 01 E8 
2016-04-21 08:54:53,909 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 07 00 13 7A 00 00 02 93 
2016-04-21 08:54:53,929 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2016-04-21 08:54:53,931 | DEBUG | ZWaveInputThread | SendDataMessageClass             | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sent Data successfully placed on stack.
2016-04-21 08:54:53,947 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:54:53,950 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 09 00 13 7A 00 00 02 00 00 9D 
2016-04-21 08:54:53,953 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 09 00 13 7A 00 00 02 00 00 9D 
2016-04-21 08:54:53,955 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=7A 00 00 02 
2016-04-21 08:54:53,959 | DEBUG | ZWaveInputThread | SendDataMessageClass             | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: SendData Request. CallBack ID = 122, Status = Transmission complete and ACK received(0)
2016-04-21 08:54:53,978 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=122, payload=02 02 84 08 
2016-04-21 08:54:53,981 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=7A 00 00 02 
2016-04-21 08:54:53,983 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: class=SendData, callback id=122, expected=SendData, cancelled=false        transaction complete!
2016-04-21 08:54:53,985 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveTransactionCompletedEvent
2016-04-21 08:54:53,986 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Went to sleep
2016-04-21 08:54:53,988 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Is sleeping
2016-04-21 08:54:53,990 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2016-04-21 08:54:53,994 | DEBUG | ZWaveSendThread  | ZWaveController$ZWaveSendThread  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Response processed after 114ms/4273ms.
2016-04-21 08:54:54,013 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_ack changed from 202 to 203
2016-04-21 08:54:54,035 | INFO  | ESH-safeCall-53  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 633 to 634
2016-04-21 08:54:54,036 | INFO  | ESH-safeCall-55  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 632 to 633
2016-04-21 08:54:54,840 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 03 0A 00 94 5A 
2016-04-21 08:54:54,841 | INFO  | ESH-safeCall-55  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 635
2016-04-21 08:54:54,844 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:54:54,849 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 03 0A 00 94 5A 
2016-04-21 08:54:54,856 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 03 0A 00 94 5A 
2016-04-21 08:54:54,863 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 03 0A 00 94 
2016-04-21 08:54:54,876 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:54:54,880 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:54:54,884 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:54:54,887 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:54:54,889 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Luminance(3), Scale = 1
2016-04-21 08:54:54,892 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 148
2016-04-21 08:54:54,902 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:54:54,904 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:54:54,906 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 148
2016-04-21 08:54:54,909 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
2016-04-21 08:54:54,913 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 634 to 635
2016-04-21 08:54:55,005 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 01 22 01 11 F4 
2016-04-21 08:54:55,005 | INFO  | ESH-safeCall-54  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 636
2016-04-21 08:54:55,008 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:54:55,011 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 01 22 01 11 F4 
2016-04-21 08:54:55,016 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 01 22 01 11 F4 
2016-04-21 08:54:55,020 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 01 22 01 11 
2016-04-21 08:54:55,022 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:54:55,025 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:54:55,039 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:54:55,042 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:54:55,044 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Temperature(1), Scale = 0
2016-04-21 08:54:55,048 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 27.3
2016-04-21 08:54:55,050 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:54:55,053 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:54:55,067 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 27.3
2016-04-21 08:54:55,070 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
2016-04-21 08:54:55,074 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 635 to 636
2016-04-21 08:55:00,987 | INFO  | ESH-safeCall-54  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 637
2016-04-21 08:55:00,989 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:55:01,001 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:01,005 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:55:01,010 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:55:01,013 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C 
2016-04-21 08:55:01,024 | DEBUG | ZWaveInputThread | ApplicationUpdateMessageClass    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application update request. Node information received.
2016-04-21 08:55:01,026 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Is awake with 0 messages in the wake-up queue.
2016-04-21 08:55:01,027 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveWakeUpEvent
2016-04-21 08:55:01,029 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveWakeUpEvent
2016-04-21 08:55:01,033 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=122, payload=02 02 84 08 
2016-04-21 08:55:01,036 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C 
2016-04-21 08:55:01,048 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: class=ApplicationUpdate, callback id=122, expected=SendData, cancelled=false      MISMATCH
2016-04-21 08:55:01,053 | INFO  | ESH-safeCall-53  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 636 to 637
2016-04-21 08:55:02,032 | DEBUG | Timer-7          | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: No more messages, go back to sleep
2016-04-21 08:55:02,034 | DEBUG | Timer-7          | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2016-04-21 08:55:02,036 | DEBUG | Timer-7          | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message queued. Queue length = 1. Queue={}
2016-04-21 08:55:02,036 | DEBUG | ZWaveSendThread  | ZWaveController$ZWaveSendThread  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Took message from queue for sending. Queue length = 0
2016-04-21 08:55:02,039 | DEBUG | ZWaveSendThread  | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 09 00 13 02 02 84 08 25 7B 37 
2016-04-21 08:55:02,043 | DEBUG | ZWaveSendThread  | ZWaveSerialHandler               | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 08 25 7B 37 
2016-04-21 08:55:02,052 | INFO  | ESH-safeCall-53  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_ack updated to 204
2016-04-21 08:55:02,059 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 04 01 13 01 E8 
2016-04-21 08:55:02,060 | INFO  | ESH-safeCall-54  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 638
2016-04-21 08:55:02,063 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:02,066 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 04 01 13 01 E8 
2016-04-21 08:55:02,068 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 04 01 13 01 E8 
2016-04-21 08:55:02,073 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2016-04-21 08:55:02,081 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 07 00 13 7B 00 00 02 92 
2016-04-21 08:55:02,087 | INFO  | ESH-safeCall-53  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 639
2016-04-21 08:55:02,085 | DEBUG | ZWaveInputThread | SendDataMessageClass             | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sent Data successfully placed on stack.
2016-04-21 08:55:02,097 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:02,104 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 09 00 13 7B 00 00 02 00 00 9C 
2016-04-21 08:55:02,107 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 09 00 13 7B 00 00 02 00 00 9C 
2016-04-21 08:55:02,109 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=7B 00 00 02 
2016-04-21 08:55:02,112 | DEBUG | ZWaveInputThread | SendDataMessageClass             | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: SendData Request. CallBack ID = 123, Status = Transmission complete and ACK received(0)
2016-04-21 08:55:02,115 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=123, payload=02 02 84 08 
2016-04-21 08:55:02,118 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=7B 00 00 02 
2016-04-21 08:55:02,120 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: class=SendData, callback id=123, expected=SendData, cancelled=false        transaction complete!
2016-04-21 08:55:02,122 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveTransactionCompletedEvent
2016-04-21 08:55:02,124 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Went to sleep
2016-04-21 08:55:02,128 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Is sleeping
2016-04-21 08:55:02,130 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2016-04-21 08:55:02,134 | DEBUG | ZWaveSendThread  | ZWaveController$ZWaveSendThread  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Response processed after 88ms/4273ms.
2016-04-21 08:55:03,015 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 03 0A 00 3A F4 
2016-04-21 08:55:03,021 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:03,022 | INFO  | ESH-safeCall-53  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 640
2016-04-21 08:55:03,024 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 03 0A 00 3A F4 
2016-04-21 08:55:03,027 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 03 0A 00 3A F4 
2016-04-21 08:55:03,030 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 03 0A 00 3A 
2016-04-21 08:55:03,036 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:55:03,040 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:55:03,043 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:55:03,045 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:55:03,047 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Luminance(3), Scale = 1
2016-04-21 08:55:03,051 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 58
2016-04-21 08:55:03,052 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:03,054 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:03,056 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 58
2016-04-21 08:55:03,060 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
2016-04-21 08:55:03,176 | INFO  | ESH-safeCall-53  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 641
2016-04-21 08:55:03,177 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 01 22 01 12 F7 
2016-04-21 08:55:03,182 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:03,185 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 01 22 01 12 F7 
2016-04-21 08:55:03,188 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 01 22 01 12 F7 
2016-04-21 08:55:03,191 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 01 22 01 12 
2016-04-21 08:55:03,193 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:55:03,195 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:55:03,197 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:55:03,198 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:55:03,200 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Temperature(1), Scale = 0
2016-04-21 08:55:03,202 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 27.4
2016-04-21 08:55:03,204 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:03,206 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:03,208 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 27.4
2016-04-21 08:55:03,211 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
2016-04-21 08:55:03,329 | INFO  | ESH-safeCall-55  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 637 to 638
2016-04-21 08:55:04,779 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_ack changed from 203 to 204
2016-04-21 08:55:04,838 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 638 to 639
2016-04-21 08:55:04,899 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 639 to 640
2016-04-21 08:55:04,957 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 640 to 641
2016-04-21 08:55:11,738 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:55:11,742 | INFO  | ESH-safeCall-54  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 642
2016-04-21 08:55:11,747 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:11,751 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:55:11,756 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 19 00 49 84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C A2 
2016-04-21 08:55:11,774 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C 
2016-04-21 08:55:11,776 | DEBUG | ZWaveInputThread | ApplicationUpdateMessageClass    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application update request. Node information received.
2016-04-21 08:55:11,782 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Is awake with 0 messages in the wake-up queue.
2016-04-21 08:55:11,784 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveWakeUpEvent
2016-04-21 08:55:11,786 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveWakeUpEvent
2016-04-21 08:55:11,789 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=123, payload=02 02 84 08 
2016-04-21 08:55:11,808 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 13 04 20 01 30 84 85 80 8F 56 72 86 70 8E 31 9C EF 30 31 9C 
2016-04-21 08:55:11,813 | INFO  | ESH-safeCall-55  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 641 to 642
2016-04-21 08:55:11,814 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: class=ApplicationUpdate, callback id=123, expected=SendData, cancelled=false      MISMATCH
2016-04-21 08:55:12,788 | DEBUG | Timer-7          | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: No more messages, go back to sleep
2016-04-21 08:55:12,790 | DEBUG | Timer-7          | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2016-04-21 08:55:12,793 | DEBUG | Timer-7          | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message queued. Queue length = 1. Queue={}
2016-04-21 08:55:12,793 | DEBUG | ZWaveSendThread  | ZWaveController$ZWaveSendThread  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Took message from queue for sending. Queue length = 0
2016-04-21 08:55:12,795 | DEBUG | ZWaveSendThread  | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 09 00 13 02 02 84 08 25 7C 30 
2016-04-21 08:55:12,797 | DEBUG | ZWaveSendThread  | ZWaveSerialHandler               | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 08 25 7C 30 
2016-04-21 08:55:12,806 | INFO  | ESH-safeCall-55  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_ack updated to 205
2016-04-21 08:55:12,810 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 04 01 13 01 E8 
2016-04-21 08:55:12,813 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:12,816 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 04 01 13 01 E8 
2016-04-21 08:55:12,818 | INFO  | ESH-safeCall-53  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 643
2016-04-21 08:55:12,821 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 04 01 13 01 E8 
2016-04-21 08:55:12,833 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2016-04-21 08:55:12,835 | DEBUG | ZWaveInputThread | SendDataMessageClass             | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sent Data successfully placed on stack.
2016-04-21 08:55:12,842 | INFO  | ESH-safeCall-53  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 644
2016-04-21 08:55:12,840 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 07 00 13 7C 00 00 02 95 
2016-04-21 08:55:12,858 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:12,864 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 09 00 13 7C 00 00 02 00 00 9B 
2016-04-21 08:55:12,868 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 09 00 13 7C 00 00 02 00 00 9B 
2016-04-21 08:55:12,886 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=7C 00 00 02 
2016-04-21 08:55:12,889 | DEBUG | ZWaveInputThread | SendDataMessageClass             | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: SendData Request. CallBack ID = 124, Status = Transmission complete and ACK received(0)
2016-04-21 08:55:12,894 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=124, payload=02 02 84 08 
2016-04-21 08:55:12,897 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=7C 00 00 02 
2016-04-21 08:55:12,904 | DEBUG | ZWaveInputThread | ZWaveCommandProcessor            | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Checking transaction complete: class=SendData, callback id=124, expected=SendData, cancelled=false        transaction complete!
2016-04-21 08:55:12,907 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveTransactionCompletedEvent
2016-04-21 08:55:12,910 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Went to sleep
2016-04-21 08:55:12,913 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 642 to 643
2016-04-21 08:55:12,914 | DEBUG | ZWaveInputThread | ZWaveWakeUpCommandClass          | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Is sleeping
2016-04-21 08:55:12,917 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2016-04-21 08:55:12,919 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_ack changed from 204 to 205
2016-04-21 08:55:12,920 | DEBUG | ZWaveSendThread  | ZWaveController$ZWaveSendThread  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Response processed after 121ms/4273ms.
2016-04-21 08:55:12,956 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 643 to 644
2016-04-21 08:55:13,766 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 03 0A 00 67 A9 
2016-04-21 08:55:13,770 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:13,771 | INFO  | ESH-safeCall-54  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 645
2016-04-21 08:55:13,774 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 03 0A 00 67 A9 
2016-04-21 08:55:13,781 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 03 0A 00 67 A9 
2016-04-21 08:55:13,785 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 03 0A 00 67 
2016-04-21 08:55:13,793 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:55:13,795 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:55:13,796 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:55:13,798 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:55:13,800 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Luminance(3), Scale = 1
2016-04-21 08:55:13,802 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 103
2016-04-21 08:55:13,805 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:13,808 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:13,810 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 103
2016-04-21 08:55:13,813 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
2016-04-21 08:55:13,818 | INFO  | ESH-safeCall-55  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 644 to 645
2016-04-21 08:55:13,930 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 01 22 01 12 F7 
2016-04-21 08:55:13,930 | INFO  | ESH-safeCall-55  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 646
2016-04-21 08:55:13,934 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:13,937 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 01 22 01 12 F7 
2016-04-21 08:55:13,940 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 01 22 01 12 F7 
2016-04-21 08:55:13,943 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 01 22 01 12 
2016-04-21 08:55:13,947 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:55:13,951 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:55:13,956 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:55:13,958 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:55:13,960 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Temperature(1), Scale = 0
2016-04-21 08:55:13,963 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 27.4
2016-04-21 08:55:13,965 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:13,967 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:13,974 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 27.4
2016-04-21 08:55:13,979 | INFO  | ESH-safeCall-55  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 645 to 646
2016-04-21 08:55:13,979 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
2016-04-21 08:55:18,485 | DEBUG | aveReceiveThread | SerialHandler$ZWaveReceiveThread | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive Message = 01 0C 00 04 00 02 06 31 05 03 0A 02 06 CA 
2016-04-21 08:55:18,486 | INFO  | ESH-safeCall-55  | ItemStateEvent                   | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof updated to 647
2016-04-21 08:55:18,490 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Receive queue TAKE: Length=0
2016-04-21 08:55:18,493 | DEBUG | ZWaveInputThread | SerialMessage                    | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Assembled message buffer = 01 0C 00 04 00 02 06 31 05 03 0A 02 06 CA 
2016-04-21 08:55:18,496 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Process Message = 01 0C 00 04 00 02 06 31 05 03 0A 02 06 CA 
2016-04-21 08:55:18,498 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 06 31 05 03 0A 02 06 
2016-04-21 08:55:18,506 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Application Command Request (ALIVE:DONE)
2016-04-21 08:55:18,510 | DEBUG | ZWaveInputThread | ApplicationCommandMessageClass   | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Incoming command class SENSOR_MULTILEVEL
2016-04-21 08:55:18,512 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Received Sensor Multi Level Request
2016-04-21 08:55:18,515 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Multi Level REPORT received
2016-04-21 08:55:18,517 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Type = Luminance(3), Scale = 1
2016-04-21 08:55:18,523 | DEBUG | ZWaveInputThread | WaveMultiLevelSensorCommandClass | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Sensor Value = 518
2016-04-21 08:55:18,525 | DEBUG | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:18,527 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-04-21 08:55:18,529 | INFO  | ESH-safeCall-54  | ItemStateChangedEvent            | 179 - org.eclipse.smarthome.io.monitor - 0.8.0.a12 | zwave_serial_zstick_fc47e4bd_serial_sof changed from 646 to 647
2016-04-21 08:55:18,529 | DEBUG | ZWaveInputThread | ZWaveThingHandler                | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 518
2016-04-21 08:55:18,534 | ERROR | ZWaveInputThread | ZWaveController                  | 222 - org.openhab.binding.zwave - 2.0.0.201604201505 | Exception during ZWave thread: Input 2.
maggu2810 commented 8 years ago

Some more details. In the first session, I added my controller (so, with configuration). Then I added the device and I configured the device. After that I does not see any values in the Paper UI. So I looked at the log.

After I have done a restart I see no exception anymore, but still no values in the UI. Log: https://gist.github.com/maggu2810/a8c0f86a2c54ce52d1cb6020b78f417a

I will test to configure the device...

maggu2810 commented 8 years ago

Configuration for that device using the Paper UI is not working. Will have a look at...

General Request URL:http://10.10.10.166:8080/rest/things/zwave:device:fc47e4bd:node2/config Request Method:PUT Status Code:400 Bad Request Remote Address:10.10.10.166:8080

Response Headers view source Content-Length:128 Content-Type:application/json Date:Thu, 21 Apr 2016 09:15:06 GMT Server:Jetty(9.2.14.v20151106)

Request Headers view source Accept:application/json, text/plain, / Accept-Encoding:gzip, deflate, sdch Accept-Language:de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4 Connection:keep-alive Content-Length:898 Content-Type:application/json DNT:1 Host:10.10.10.166:8080 Origin:http://10.10.10.166:8080 Referer:http://10.10.10.166:8080/ui/index.html User-Agent:Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/47.0.2526.73 Safari/537.36

Request Payload view source {zwave_class_basic: "ROUTING_SLAVE", zwave_class_generic: "BINARY_SENSOR", zwave_version: "2.6",…} config_1_1: 10 config_2_1: 15 config_3_1: 1 config_4_1: 2 config_6_2: 30 config_8_1: null config_9_2: 200 config_12_1: null config_14_1: null config_16_1: null config_20_1: 15 config_22_2: 30 config_24_1: null config_26_1: null config_40_2: 200 config_42_2: null config_60_1: 10 config_62_2: 900 config_64_2: null config_66_2: null config_80_1: 10 config_81_1: 50 config_82_2: 100 config_83_2: 1000 config_86_1: 18 config_87_1: 28 config_89_1: 1 group_1: [] group_2: [] group_3: ["node_1_0"] wakeup_interval: 7200 wakeup_node: 1 zwave_beaming: "true" zwave_class_basic: "ROUTING_SLAVE" zwave_class_generic: "BINARY_SENSOR" zwave_class_specific: "ROUTING_SENSOR_BINARY" zwave_deviceid: "4097" zwave_devicetype: "2048" zwave_frequent: "false" zwave_listening: "false" zwave_manufacturer: "271" zwave_nodeid: "2" zwave_routing: "true" zwave_version: "2.6"

maggu2810 commented 8 years ago

Open the URL (http://10.10.10.166:8080/rest/things/zwave:device:fc47e4bd:node2/config) in browser gives me:

{
  "error": {
    "message": "HTTP 405 Method Not Allowed",
    "http-code": 405,
    "exception": {
      "class": "javax.ws.rs.NotAllowedException",
      "message": "HTTP 405 Method Not Allowed",
      "localized-message": "HTTP 405 Method Not Allowed"
    }
  }
}
cdjackson commented 8 years ago

Thanks @maggu2810 I'll take a look at this tonight or tomorrow...

cdjackson commented 8 years ago

Markus - does this exception still happen with todays binding?

cdjackson commented 8 years ago

Configuration for that device using the Paper UI is not working.

This is possible linked to https://github.com/eclipse/smarthome/issues/1414 since I see properties in your configuration!

maggu2810 commented 8 years ago

I will give it a try this weekend. Will report back (or you) :wink:

cdjackson commented 8 years ago

thanks.

maggu2810 commented 8 years ago

I am using the Eclipse SmartHome Eclipse IDE setup now and added your openHAB Z-Wave binding and the serial transport to debug using the most recent versions. I started with a "clean" setup, and add the Z-Wave Serial Controller. I filled the serial port, enabled "master" and "suc" and accepted that settings to get the thing created.

Add this point I already see the input 2 excpetion.

https://gist.github.com/maggu2810/ebdaba8ea11c71b6ec6721201250b141#file-gistfile1-txt-L415

maggu2810 commented 8 years ago

The SerialMessage constructor SerialMessage(int nodeId, byte[] buffer) is used.

The line

this.messageClass = SerialMessageClass.getMessageClass(buffer[3] & 0xFF);

sets the messageClass member to null (in some cases).

Arrays.toString(buffer) returns this:

[1, 12, 0, 10, 5, 0, 1, 2, 1, 3, -1, -1, -1, 2]

and there is no message class with ID defined.

So, is the buffer wrong?

After a second start, I cannot reproduce this again.

I have to remove the USB device, add it again, restart the test and I see the exception again.

maggu2810 commented 8 years ago

Here (https://github.com/yepher/RaZBerry#zwave-functions) the function ID 0x00 is listed as "None". It is listed and not missed like 0x01, so it is valid?

maggu2810 commented 8 years ago

Sorry, wrong index. The unknown message class is 10, so 0x0A.

maggu2810 commented 8 years ago

@cdjackson See #818

cdjackson commented 8 years ago

Closed by #818

maggu2810 commented 8 years ago

Sorry, missed that