Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

java.lang.NumberFormatException configuring Association Group #797

Closed
dude0001 opened this issue Jan 8, 2018 · 13 comments
Closed

java.lang.NumberFormatException configuring Association Group #797

dude0001 opened this issue Jan 8, 2018 · 13 comments

Comments

@dude0001
Copy link

dude0001 commented Jan 8, 2018

I am on the latest release of OH and the ZWave binding. I redeployed the latest version yesterday to fix a NULL pointer error when updating a Thing similar to what is describe in this issue

I can trace through the code and see the exception

java.lang.NumberFormatException: For input string: "org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@3dd05f63"

is happening here. The code is seeing this is a "group" configuration and expecting the second argument in the configurationParameter to be a groupId and an integer. The code is trying to parse this long string as an Integer which of course fails. However, I am a OH and ZWave newb and I am not sure what the correct solution should be. I'm also not sure if this is a problem with the code linked in the handler, or if the UI (I am using Paper UI) is passing a bad parameter here.

I am a software developer (C#), so I should be able to help troubleshoot quickly. I'd love to contribute myself, but I'm not sure how to setup a development environment to play with the code yet. Please let me know if you need more information.

Here is the HTTP PUT from Paper UI

curl "http://megaman:8181/rest/things/zwave:device:e7d0219a:node7/config" -X PUT -H "Origin: http://megaman:8181" -H "Accept-Encoding: gzip, deflate" -H "Accept-Language: en-US,en;q=0.9" -H "User-Agent: Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.108 Mobile Safari/537.36" -H "Content-Type: application/json" -H "Accept: application/json, text/plain, */*" -H "Referer: http://megaman:8181/paperui/index.html" -H "Connection: keep-alive" --data-binary "^{^\^"config_11_1^\^":1,^\^"config_10_1^\^":3,^\^"group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup^@3dd05f63^\^":^[^],^\^"group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup^@55eec832^\^":^[^],^\^"group_1^\^":^[^\^"node_1_0^\^"^],^\^"group_3^\^":null,^\^"group_2^\^":^[^],^\^"switchall_mode^\^":255,^\^"action_reinit^\^":false,^\^"group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup^@2d79c02f^\^":^[^\^"node_1_0^\^"^],^\^"config_12_1^\^":3,^\^"group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup^@2fbe54b7^\^":^[^\^"node_1_0^\^"^],^\^"action_failed^\^":false,^\^"powerlevel_level^\^":0,^\^"action_remove^\^":false,^\^"binding_pollperiod^\^":1800,^\^"action_heal^\^":false,^\^"group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup^@66bfec4^\^":^[^],^\^"config_7_1^\^":1,^\^"config_8_1^\^":3,^\^"config_9_1^\^":1,^\^"group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup^@623f221^\^":^[^],^\^"powerlevel_timeout^\^":0,^\^"config_3_1^\^":0,^\^"config_4_1^\^":0,^\^"config_5_1^\^":0^}" --compressed &

Here is the ZWave trace log

08-Jan-2018 10:44:50.367 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Configuration update received
08-Jan-2018 10:44:50.367 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Configuration update config_11_1 to 1
08-Jan-2018 10:44:50.367 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Creating new message for application command CONFIGURATIONCMD_SET
08-Jan-2018 10:44:50.367 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 7: Creating empty message of class = SendData (0x13), type = Request (0x00)
08-Jan-2018 10:44:50.367 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Callback ID = 77
08-Jan-2018 10:44:50.367 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
08-Jan-2018 10:44:50.367 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Creating new message for application command CONFIGURATIONCMD_GET
08-Jan-2018 10:44:50.367 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
08-Jan-2018 10:44:50.367 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 7: Creating empty message of class = SendData (0x13), type = Request (0x00)
08-Jan-2018 10:44:50.368 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Callback ID = 78
08-Jan-2018 10:44:50.368 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xF5
08-Jan-2018 10:44:50.368 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
08-Jan-2018 10:44:50.368 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Configuration update config_10_1 to 3
08-Jan-2018 10:44:50.368 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 07 05 70 04 0B 01 01 25 4D F5 
08-Jan-2018 10:44:50.368 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Creating new message for application command CONFIGURATIONCMD_SET
08-Jan-2018 10:44:50.368 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 7: Creating empty message of class = SendData (0x13), type = Request (0x00)
08-Jan-2018 10:44:50.368 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 7: Sending REQUEST Message = 01 0C 00 13 07 05 70 04 0B 01 01 25 4D F5 
08-Jan-2018 10:44:50.368 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Callback ID = 79
08-Jan-2018 10:44:50.368 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
08-Jan-2018 10:44:50.368 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Creating new message for application command CONFIGURATIONCMD_GET
08-Jan-2018 10:44:50.368 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 7: Creating empty message of class = SendData (0x13), type = Request (0x00)
08-Jan-2018 10:44:50.368 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Callback ID = 80
08-Jan-2018 10:44:50.368 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message queued. Queue length = 3. Queue={}
08-Jan-2018 10:44:50.368 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Configuration update group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@3dd05f63 to []
08-Jan-2018 10:44:50.368 [TRACE] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
08-Jan-2018 10:44:50.369 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received ACK
08-Jan-2018 10:44:50.375 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.375 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.375 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.375 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.375 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.375 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 
08-Jan-2018 10:44:50.375 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.375 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.375 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.376 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.376 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.376 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.376 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08-Jan-2018 10:44:50.376 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
08-Jan-2018 10:44:50.376 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
08-Jan-2018 10:44:50.376 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: Sent Data successfully placed on stack.
08-Jan-2018 10:44:50.376 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Ack Pending cleared
08-Jan-2018 10:44:50.396 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.396 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4D 00 00 03 A5 
08-Jan-2018 10:44:50.396 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 4D 00 00 03 A5 
08-Jan-2018 10:44:50.396 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xA5
08-Jan-2018 10:44:50.396 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.396 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 4D 00 00 03 
08-Jan-2018 10:44:50.396 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.396 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.396 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.396 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xAB
08-Jan-2018 10:44:50.396 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4D 00 00 03 00 00 AB 
08-Jan-2018 10:44:50.397 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4D 00 00 03 00 00 AB 
08-Jan-2018 10:44:50.397 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4D 00 00 03 
08-Jan-2018 10:44:50.397 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
08-Jan-2018 10:44:50.397 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
08-Jan-2018 10:44:50.397 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: SendData Request. CallBack ID = 77, Status = Transmission complete and ACK received(0)
08-Jan-2018 10:44:50.397 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 7: Starting initialisation from DONE
08-Jan-2018 10:44:50.397 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@46dee6dd already registered
08-Jan-2018 10:44:50.397 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=7, callback=77, payload=07 05 70 04 0B 01 01 
08-Jan-2018 10:44:50.397 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4D 00 00 03 
08-Jan-2018 10:44:50.397 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=77, expected=SendData, cancelled=false        transaction complete!
08-Jan-2018 10:44:50.397 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.397 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.397 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 1
08-Jan-2018 10:44:50.397 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - NODE 7: Response processed after 29ms/1931ms.
08-Jan-2018 10:44:50.397 [TRACE] [.internal.protocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0
08-Jan-2018 10:44:50.397 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 2
08-Jan-2018 10:44:50.397 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xF7
08-Jan-2018 10:44:50.397 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 07 03 70 05 0B 25 4E F7 
08-Jan-2018 10:44:50.397 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 7: Sending REQUEST Message = 01 0A 00 13 07 03 70 05 0B 25 4E F7 
08-Jan-2018 10:44:50.397 [TRACE] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
08-Jan-2018 10:44:50.398 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received ACK
08-Jan-2018 10:44:50.404 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.404 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.404 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.404 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.404 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.404 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 
08-Jan-2018 10:44:50.404 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.405 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.405 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.405 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.405 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.405 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.405 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08-Jan-2018 10:44:50.405 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
08-Jan-2018 10:44:50.405 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
08-Jan-2018 10:44:50.405 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: Sent Data successfully placed on stack.
08-Jan-2018 10:44:50.405 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Ack Pending cleared
08-Jan-2018 10:44:50.425 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.425 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4E 00 00 02 A7 
08-Jan-2018 10:44:50.425 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 4E 00 00 02 A7 
08-Jan-2018 10:44:50.425 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xA7
08-Jan-2018 10:44:50.425 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.425 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 4E 00 00 02 
08-Jan-2018 10:44:50.425 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.426 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.426 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.426 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xA9
08-Jan-2018 10:44:50.426 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4E 00 00 02 00 00 A9 
08-Jan-2018 10:44:50.426 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4E 00 00 02 00 00 A9 
08-Jan-2018 10:44:50.426 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4E 00 00 02 
08-Jan-2018 10:44:50.426 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
08-Jan-2018 10:44:50.426 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
08-Jan-2018 10:44:50.426 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: SendData Request. CallBack ID = 78, Status = Transmission complete and ACK received(0)
08-Jan-2018 10:44:50.426 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 7: Starting initialisation from DONE
08-Jan-2018 10:44:50.426 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@46dee6dd already registered
08-Jan-2018 10:44:50.426 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=7, callback=78, payload=07 03 70 05 0B 
08-Jan-2018 10:44:50.426 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4E 00 00 02 
08-Jan-2018 10:44:50.426 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=78, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
08-Jan-2018 10:44:50.439 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.439 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 07 05 70 06 0B 01 01 8F 
08-Jan-2018 10:44:50.439 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 0B 00 04 00 07 05 70 06 0B 01 01 8F 
08-Jan-2018 10:44:50.439 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0x8F
08-Jan-2018 10:44:50.440 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.440 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 00 07 05 70 06 0B 01 01 
08-Jan-2018 10:44:50.440 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.440 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.440 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.440 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0x8F
08-Jan-2018 10:44:50.440 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 07 05 70 06 0B 01 01 8F 
08-Jan-2018 10:44:50.440 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 07 05 70 06 0B 01 01 8F 
08-Jan-2018 10:44:50.440 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 07 05 70 06 0B 01 01 
08-Jan-2018 10:44:50.440 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
08-Jan-2018 10:44:50.440 [TRACE] [tocol.serialmessage.ApplicationCommandMessageClass] - Handle Message Application Command Request
08-Jan-2018 10:44:50.440 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 7: Application Command Request (ALIVE:DONE)
08-Jan-2018 10:44:50.440 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 7: Starting initialisation from DONE
08-Jan-2018 10:44:50.440 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@46dee6dd already registered
08-Jan-2018 10:44:50.440 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 7: Incoming command class CONFIGURATION
08-Jan-2018 10:44:50.440 [TRACE] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 7: Found Command Class CONFIGURATION, passing to handleApplicationCommandRequest
08-Jan-2018 10:44:50.440 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Received Configuration Request
08-Jan-2018 10:44:50.440 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Node configuration report, parameter = 11, value = 1, size = 1
08-Jan-2018 10:44:50.440 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveConfigurationParameterEvent
08-Jan-2018 10:44:50.440 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveConfigurationParameterEvent
08-Jan-2018 10:44:50.440 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got a value event from Z-Wave network, endpoint = 0, command class = CONFIGURATION, value = org.openhab.binding.zwave.internal.protocol.ZWaveConfigurationParameter@4d756e81
08-Jan-2018 10:44:50.440 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Update CONFIGURATION 11/1 to 1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Config about to update 26 parameters...
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1 - id = '11'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1 - size = '1'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Sub-parameter config_11_1 is 00000001
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Pre-processing  00000001>>FFFFFFFF
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Post-processing 00000001>>FFFFFFFF
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Sub-parameter setting config_11_1 is 00000001 [1]
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1 - id = '10'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@3dd05f63
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@55eec832
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_2
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing switchall_mode
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_reinit
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@2d79c02f
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_12_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_12_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_12_1 - id = '12'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@2fbe54b7
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_failed
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing powerlevel_level
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_remove
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing binding_pollperiod
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_heal
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@66bfec4
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_7_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_7_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_7_1 - id = '7'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_8_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_8_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_8_1 - id = '8'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_9_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_9_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_9_1 - id = '9'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@623f221
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing powerlevel_timeout
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_3_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_3_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_3_1 - id = '3'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_4_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_4_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_4_1 - id = '4'
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_5_1
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_5_1 len=3
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_5_1 - id = '5'
08-Jan-2018 10:44:50.441 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=7, callback=78, payload=07 03 70 05 0B 
08-Jan-2018 10:44:50.441 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 07 05 70 06 0B 01 01 
08-Jan-2018 10:44:50.441 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=78, expected=ApplicationCommandHandler, cancelled=false        transaction complete!
08-Jan-2018 10:44:50.441 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.441 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.441 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 1
08-Jan-2018 10:44:50.441 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - NODE 7: Response processed after 44ms/1931ms.
08-Jan-2018 10:44:50.441 [TRACE] [.internal.protocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0
08-Jan-2018 10:44:50.441 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
08-Jan-2018 10:44:50.441 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xF5
08-Jan-2018 10:44:50.441 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 07 06 70 04 0A 02 00 03 25 4F F5 
08-Jan-2018 10:44:50.441 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 7: Sending REQUEST Message = 01 0D 00 13 07 06 70 04 0A 02 00 03 25 4F F5 
08-Jan-2018 10:44:50.442 [TRACE] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
08-Jan-2018 10:44:50.443 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received ACK
08-Jan-2018 10:44:50.450 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.450 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.450 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.450 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.450 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.450 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 
08-Jan-2018 10:44:50.450 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.450 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.450 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.450 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.450 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.450 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.450 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08-Jan-2018 10:44:50.450 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
08-Jan-2018 10:44:50.450 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
08-Jan-2018 10:44:50.450 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: Sent Data successfully placed on stack.
08-Jan-2018 10:44:50.450 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Ack Pending cleared
08-Jan-2018 10:44:50.471 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.472 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4F 00 00 03 A7 
08-Jan-2018 10:44:50.472 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 4F 00 00 03 A7 
08-Jan-2018 10:44:50.472 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xA7
08-Jan-2018 10:44:50.472 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.472 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 4F 00 00 03 
08-Jan-2018 10:44:50.472 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.472 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.472 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.472 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xA9
08-Jan-2018 10:44:50.472 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4F 00 00 03 00 00 A9 
08-Jan-2018 10:44:50.473 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4F 00 00 03 00 00 A9 
08-Jan-2018 10:44:50.473 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4F 00 00 03 
08-Jan-2018 10:44:50.473 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
08-Jan-2018 10:44:50.473 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
08-Jan-2018 10:44:50.473 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: SendData Request. CallBack ID = 79, Status = Transmission complete and ACK received(0)
08-Jan-2018 10:44:50.473 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 7: Starting initialisation from DONE
08-Jan-2018 10:44:50.473 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@46dee6dd already registered
08-Jan-2018 10:44:50.473 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=7, callback=79, payload=07 06 70 04 0A 02 00 03 
08-Jan-2018 10:44:50.473 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4F 00 00 03 
08-Jan-2018 10:44:50.473 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=79, expected=SendData, cancelled=false        transaction complete!
08-Jan-2018 10:44:50.473 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.473 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.473 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 1
08-Jan-2018 10:44:50.473 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - NODE 7: Response processed after 31ms/1931ms.
08-Jan-2018 10:44:50.473 [TRACE] [.internal.protocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0
08-Jan-2018 10:44:50.473 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
08-Jan-2018 10:44:50.473 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.473 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 07 03 70 05 0A 25 50 E8 
08-Jan-2018 10:44:50.473 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 7: Sending REQUEST Message = 01 0A 00 13 07 03 70 05 0A 25 50 E8 
08-Jan-2018 10:44:50.473 [TRACE] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
08-Jan-2018 10:44:50.474 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received ACK
08-Jan-2018 10:44:50.480 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.480 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.480 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.480 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.480 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.481 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 
08-Jan-2018 10:44:50.481 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.481 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.481 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.481 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
08-Jan-2018 10:44:50.481 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.481 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08-Jan-2018 10:44:50.481 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08-Jan-2018 10:44:50.481 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
08-Jan-2018 10:44:50.481 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
08-Jan-2018 10:44:50.481 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: Sent Data successfully placed on stack.
08-Jan-2018 10:44:50.481 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Ack Pending cleared
08-Jan-2018 10:44:50.501 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.502 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 50 00 00 02 B9 
08-Jan-2018 10:44:50.502 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 50 00 00 02 B9 
08-Jan-2018 10:44:50.502 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xB9
08-Jan-2018 10:44:50.502 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.502 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 50 00 00 02 
08-Jan-2018 10:44:50.502 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.502 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.502 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.502 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0xB7
08-Jan-2018 10:44:50.502 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 50 00 00 02 00 00 B7 
08-Jan-2018 10:44:50.502 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 50 00 00 02 00 00 B7 
08-Jan-2018 10:44:50.502 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=50 00 00 02 
08-Jan-2018 10:44:50.502 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
08-Jan-2018 10:44:50.503 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
08-Jan-2018 10:44:50.503 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 7: SendData Request. CallBack ID = 80, Status = Transmission complete and ACK received(0)
08-Jan-2018 10:44:50.503 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 7: Starting initialisation from DONE
08-Jan-2018 10:44:50.503 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@46dee6dd already registered
08-Jan-2018 10:44:50.503 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=7, callback=80, payload=07 03 70 05 0A 
08-Jan-2018 10:44:50.503 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=50 00 00 02 
08-Jan-2018 10:44:50.503 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=80, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
08-Jan-2018 10:44:50.516 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF
08-Jan-2018 10:44:50.516 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 07 06 70 06 0A 02 00 03 8B 
08-Jan-2018 10:44:50.516 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 0C 00 04 00 07 06 70 06 0A 02 00 03 8B 
08-Jan-2018 10:44:50.516 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0x8B
08-Jan-2018 10:44:50.516 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
08-Jan-2018 10:44:50.516 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 00 07 06 70 06 0A 02 00 03 
08-Jan-2018 10:44:50.516 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
08-Jan-2018 10:44:50.517 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT
08-Jan-2018 10:44:50.517 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08-Jan-2018 10:44:50.517 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 0x8B
08-Jan-2018 10:44:50.517 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 04 00 07 06 70 06 0A 02 00 03 8B 
08-Jan-2018 10:44:50.517 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 0C 00 04 00 07 06 70 06 0A 02 00 03 8B 
08-Jan-2018 10:44:50.517 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 07 06 70 06 0A 02 00 03 
08-Jan-2018 10:44:50.517 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
08-Jan-2018 10:44:50.517 [TRACE] [tocol.serialmessage.ApplicationCommandMessageClass] - Handle Message Application Command Request
08-Jan-2018 10:44:50.517 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 7: Application Command Request (ALIVE:DONE)
08-Jan-2018 10:44:50.517 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 7: Starting initialisation from DONE
08-Jan-2018 10:44:50.517 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@46dee6dd already registered
08-Jan-2018 10:44:50.517 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 7: Incoming command class CONFIGURATION
08-Jan-2018 10:44:50.517 [TRACE] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 7: Found Command Class CONFIGURATION, passing to handleApplicationCommandRequest
08-Jan-2018 10:44:50.517 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Received Configuration Request
08-Jan-2018 10:44:50.517 [DEBUG] [otocol.commandclass.ZWaveConfigurationCommandClass] - NODE 7: Node configuration report, parameter = 10, value = 3, size = 2
08-Jan-2018 10:44:50.517 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveConfigurationParameterEvent
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveConfigurationParameterEvent
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got a value event from Z-Wave network, endpoint = 0, command class = CONFIGURATION, value = org.openhab.binding.zwave.internal.protocol.ZWaveConfigurationParameter@7007ea51
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Update CONFIGURATION 10/2 to 3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Config about to update 26 parameters...
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_11_1 - id = '11'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1 - id = '10'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_10_1 - size = '1'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Size error 1<>2 from config_10_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@3dd05f63
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@55eec832
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_2
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing switchall_mode
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_reinit
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@2d79c02f
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_12_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_12_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_12_1 - id = '12'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@2fbe54b7
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_failed
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing powerlevel_level
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_remove
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing binding_pollperiod
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing action_heal
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@66bfec4
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_7_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_7_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_7_1 - id = '7'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_8_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_8_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_8_1 - id = '8'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_9_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_9_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_9_1 - id = '9'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@623f221
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing powerlevel_timeout
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_3_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_3_1 len=3
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_3_1 - id = '3'
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_4_1
08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_4_1 len=3
08-Jan-2018 10:44:50.518 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_4_1 - id = '4'
08-Jan-2018 10:44:50.518 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_5_1
08-Jan-2018 10:44:50.518 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_5_1 len=3
08-Jan-2018 10:44:50.518 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing config_5_1 - id = '5'
08-Jan-2018 10:44:50.518 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=7, callback=80, payload=07 03 70 05 0A 
08-Jan-2018 10:44:50.518 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 07 06 70 06 0A 02 00 03 
08-Jan-2018 10:44:50.518 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=80, expected=ApplicationCommandHandler, cancelled=false        transaction complete!
08-Jan-2018 10:44:50.518 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.518 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
08-Jan-2018 10:44:50.518 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 1
08-Jan-2018 10:44:50.518 [DEBUG] [.internal.protocol.ZWaveController$ZWaveSendThread] - NODE 7: Response processed after 45ms/1931ms.
08-Jan-2018 10:44:50.518 [TRACE] [.internal.protocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0

Here is the exception and stack trace (this is not from the same call, but it is the same exception and stack)

INFO | jvm 1    | 2018/01/08 09:51:59 | 09:51:58.940 [qtp528873612-88] ERROR org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource - Exception during HTTP PUT request for update config at 'things/zwave:device:e7d0219a:node7/config'
INFO   | jvm 1    | 2018/01/08 09:51:59 | java.lang.NumberFormatException: For input string: "org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@3dd05f63"
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65) ~[?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at java.lang.Integer.parseInt(Integer.java:580) [?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at java.lang.Integer.valueOf(Integer.java:766) [?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.openhab.binding.zwave.handler.ZWaveThingHandler.handleConfigurationUpdate(ZWaveThingHandler.java:610) [200:org.openhab.binding.zwave:2.2.0]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:94) [116:org.eclipse.smarthome.core.thing:0.10.0.b1]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:413) [126:org.eclipse.smarthome.io.rest.core:0.10.0.b1]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [177:org.glassfish.jersey.core.jersey-common:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [177:org.glassfish.jersey.core.jersey-common:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [177:org.glassfish.jersey.core.jersey-common:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [177:org.glassfish.jersey.core.jersey-common:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [177:org.glassfish.jersey.core.jersey-common:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [177:org.glassfish.jersey.core.jersey-common:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [178:org.glassfish.jersey.core.jersey-server:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [175:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [175:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [175:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [175:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [175:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [15:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848) [88:org.eclipse.jetty.servlet:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:584) [88:org.eclipse.jetty.servlet:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [191:org.ops4j.pax.web.pax-web-jetty:6.0.7]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [85:org.eclipse.jetty.security:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:284) [191:org.ops4j.pax.web.pax-web-jetty:6.0.7]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [88:org.eclipse.jetty.servlet:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [191:org.ops4j.pax.web.pax-web-jetty:6.0.7]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.Server.handle(Server.java:534) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [87:org.eclipse.jetty.server:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [79:org.eclipse.jetty.io:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108) [79:org.eclipse.jetty.io:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [79:org.eclipse.jetty.io:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [90:org.eclipse.jetty.util:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [90:org.eclipse.jetty.util:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [90:org.eclipse.jetty.util:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [90:org.eclipse.jetty.util:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [90:org.eclipse.jetty.util:9.3.22.v20171030]
INFO   | jvm 1    | 2018/01/08 09:51:59 | 	at java.lang.Thread.run(Thread.java:748) [?:?]
@cdjackson
Copy link
Collaborator

cdjackson commented Jan 8, 2018 via email

@dude0001
Copy link
Author

dude0001 commented Jan 8, 2018

@cdjackson
The comment I made on Issue #796 was regarding a NullPointerException I believe was already found in Issue #755 and addressed with Pull Request #758.

The issue above is a NumberFormatException and I believe a different issue. I haven't see it discussed elsewhere. Which link are you referring to exactly? Are you saying you believe this NumberFormatException may already be fixed in the development branch as well?

@cdjackson
Copy link
Collaborator

cdjackson commented Jan 8, 2018 via email

@dude0001
Copy link
Author

dude0001 commented Jan 8, 2018

Just browsing the develop branch, the code that is causing the NumberFormatException with a "group" configurationParameter looks almost identical. I don't see anything added that would not cause the NumberFormatException with the congigurationParameter

group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@623f221

The code seems to split the congigurationParameter on underscore characters, switch on value on index 0 which is "group" here, and then the case for "group" takes the value at index 1 "org.openhab....." here and tries to parse it as an integer.

I'm willing to give it a try though. I've very new to the community. Just to clarify;

I would need to deploy just the ZWave Binding from the development branch build, and I can use the current OH 2.2.0 release I got from here this morning?

Are there any instructions for this?

@cdjackson
Copy link
Collaborator

cdjackson commented Jan 8, 2018 via email

@cdjackson
Copy link
Collaborator

I don't see anything wrong with the code you linked -:

                    if (cfg.length < 2) {
                        logger.debug("NODE{}: Association invalid {}", nodeId, configurationParameter.getKey());
                        continue;
                    }

                    Integer groupIndex = Integer.valueOf(cfg[1]);

It does make an assumption that cfg[1] is an Integer, but there should be no way that this can not be an integer unless the UI is somehow sending an ill formed command.

@dude0001
Copy link
Author

dude0001 commented Jan 8, 2018

That is what it is sending if you look at the logs above. I also admitted above I'm a complete newb to OH and it very well could be an issue with my setup or that Paper UI is sending a bad or unexpected parameter here.

I'm using GE ZWave Dimmers that have ZWave Plus. I've read some other things I don't fully understand that there have been some issues with Group Associations with GE's implementation of ZWave Plus. No idea if they are related either. My gut says it is something related to this though.

After reading through your thread some more, on a whim I deleted the Thing and added them back from the Inbox, but still have the same issue. I'm going to work on deploying the development branch build.

Any other information you think could help here? It looks like in your thread people are using a different UI than Paper UI. I could give that one a try if you point me to it as well.

@cdjackson
Copy link
Collaborator

What devices are you using this with? It won't be anything to do with GEs implementation though as the data doesn't come from the device.

It's difficult to view your data - please use code fences in future to improve the formatting.

@dude0001
Copy link
Author

dude0001 commented Jan 8, 2018

I updated my OP so the logs are in code fences instead of quotes, sorry about that.

Here is a screen shot of one of the GE ZWave dimmers I'm having the issue with. You can see the 500 error as I had just tried to save the Thing to add a location and turn the night light option off (parameter 3). The location saved but the night light configuration does not change.. I have some dimmers and on/off switches that all have the problem.

image

image

@cdjackson
Copy link
Collaborator

So the problem is this line -:

08-Jan-2018 10:44:50.517 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 7: Processing group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@623f221

Not sure why PaperUI is sending this. Possibly something was saved in an invalid way earlier, and now its in the config.

I can of course protect against this, but I don't like adding loads of checks that aren't needed as it just slows things down and makes the code less readable. At the end of the day, this is an invalid configuration.

Using HABmin will also solve this problem by the way.

@dude0001
Copy link
Author

dude0001 commented Jan 8, 2018

I agree that seems to be the line in the debug log I'm tracing the code with and where the exception comes from. I don't know more about this all right now to know how to troubleshoot more, but I agree it could be from the UI side.

With that said, I think you agree the develop branch code doesn't do anything to address this. So I'm going to wait to deploy it for now. I'm trying to learn and throwing an unstable binding in to the mix might not be beneficial for me unless you want the feedback.

Is Paper UI not preferred? I haven't tried HABmin yet but seen it referenced. I could give that a try.

When you say something was saved in an invalid way earlier: how would you suggest I "resave" it to make sure it is saved in the correct format? I did try deleting the Thing and readding it through Inbox. Are you suggesting to disassociate the devices and completely readd them etc?

@cdjackson
Copy link
Collaborator

cdjackson commented Jan 8, 2018 via email

@dude0001
Copy link
Author

dude0001 commented Jan 8, 2018

I was reading too much in to your response. uninstalled the ZWave binding, and manually deployed the development branch snapshot build. You are correct, the error is gone now. I can set the night light and other parameters now.

I'll mark this as closed. I agree with you, I wouldn't make an additional code change. Thank you for the help. I look forward to contributing in the future.

BTW, I also looked at HABmin as well. I didn't realize you were the owner of that project too. It definitely looks nice and fun to play with. I'll probably give it a try after I finish some other projects.

@dude0001 dude0001 closed this as completed Jan 8, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants