Zwave questions

shorty707 · July 31, 2016, 6:42am

Hi there,

I moved from an UZB Zwave Stick to a AeoTec Zstick and therefore basically started over.
Removed all Things … included all new on the new stick

some things are strange now

my Philio PAN11 power plugs don’t show the current voltage and watts anymore. However I can turn them on / off
they also show constantly up in the log (not debug level):

04:44:19.163 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 2 attempts left!
04:44:19.164 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
04:44:24.168 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 1 attempts left!
04:44:24.169 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
04:44:29.174 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 0 attempts left!
04:44:29.175 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
04:44:34.179 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=149, payload=06 03 71 04 00 
04:45:20.679 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 2 attempts left!
04:45:20.680 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
04:45:25.685 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 1 attempts left!
04:45:25.690 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
04:45:30.701 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 0 attempts left!
04:45:30.705 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
04:45:35.710 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=3, callback=153, payload=03 03 71 04 00 
04:54:04.480 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 2 attempts left!
04:54:04.481 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
04:54:09.483 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 1 attempts left!
04:54:09.485 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
04:54:14.489 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 0 attempts left!
04:54:14.491 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
04:54:19.494 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=4, callback=157, payload=04 03 71 04 00 
04:54:24.499 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 2 attempts left!
04:54:24.500 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
04:54:29.506 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 1 attempts left!
04:54:29.507 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
04:54:34.512 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 0 attempts left!
04:54:34.515 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
04:54:39.520 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=5, callback=161, payload=05 03 71 04 00 
04:55:35.873 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 20: Timeout while sending message. Requeueing - 2 attempts left!
04:55:35.874 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 20: Got an error while sending data. Resending message.
04:55:40.879 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 20: Timeout while sending message. Requeueing - 1 attempts left!
04:55:40.880 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 20: Got an error while sending data. Resending message.
04:55:45.883 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 20: Timeout while sending message. Requeueing - 0 attempts left!
04:55:45.884 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 20: Got an error while sending data. Resending message.
04:55:50.889 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 20: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=20, callback=165, payload=14 04 59 03 00 01 
04:56:17.070 [ERROR] [alization.ZWaveNodeInitStageAdvancer] - NODE 20: Node advancer: Retries exceeded at STATIC_VALUES
05:08:23.167 [WARN ] [home.core.internal.items.ItemUpdater] - InstantiationException on org.eclipse.smarthome.core.library.types.StringType
05:08:23.292 [WARN ] [home.core.internal.items.ItemUpdater] - InstantiationException on org.eclipse.smarthome.core.library.types.StringType
05:08:23.361 [ERROR] [WaveSerialHandler$ZWaveReceiveThread] - Protocol error (CAN), resending
05:08:23.478 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 2: Already processed another send data request for this callback Id, ignoring.
05:08:28.360 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
05:08:28.361 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
05:08:35.377 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
05:08:35.378 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
05:08:40.382 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
05:08:40.383 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
05:08:45.387 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
05:08:45.388 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
05:08:50.395 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=2, callback=196, payload=02 03 71 04 00 
05:14:19.163 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 2 attempts left!
05:14:19.165 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
05:14:24.169 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 1 attempts left!
05:14:24.170 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
05:14:29.173 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 0 attempts left!
05:14:29.175 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
05:14:34.182 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=219, payload=06 03 71 04 00 
05:15:20.679 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 2 attempts left!
05:15:20.681 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
05:15:25.687 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 1 attempts left!
05:15:25.688 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
05:15:30.691 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 0 attempts left!
05:15:30.692 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
05:15:35.697 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=3, callback=223, payload=03 03 71 04 00 
05:24:04.480 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 2 attempts left!
05:24:04.481 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
05:24:09.484 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 1 attempts left!
05:24:09.485 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
05:24:14.489 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 0 attempts left!
05:24:14.490 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
05:24:19.495 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=4, callback=227, payload=04 03 71 04 00 
05:24:24.498 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 2 attempts left!
05:24:24.499 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
05:24:29.507 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 1 attempts left!
05:24:29.508 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
05:24:34.512 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 0 attempts left!
05:24:34.513 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
05:24:39.518 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=5, callback=231, payload=05 03 71 04 00

When I add new Things it happens all the time that either not all or no chnannel gets created automatically. When I remove the Thing and readd it … it sometimes works.

thanks

shorty707 · July 31, 2016, 6:46am

here some debug lines from one of the pan11 switches:

08:44:14.160 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling...
08:44:14.161 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:switch_binary
08:44:14.161 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 6: Generating poll message for SWITCH_BINARY, endpoint 0
08:44:14.162 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 6: Node doesn't support get requests
08:44:14.162 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:meter_powerfactor
08:44:14.162 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:meter_current
08:44:14.163 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:meter_kwh
08:44:14.163 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:meter_voltage
08:44:14.163 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:meter_watts
08:44:14.163 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:15348538564:node6:alarm_general
08:44:14.164 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 6: Generating poll message for ALARM, endpoint 0, alarm null
08:44:14.164 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 6: Creating new message for application command ALARM_GET V1
08:44:14.167 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
08:44:14.167 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
08:44:14.169 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 71 04 00 25 6A D9 
08:44:14.169 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 71 04 00 25 6A D9 
08:44:14.186 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08:44:14.194 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:14.196 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08:44:14.197 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08:44:14.199 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08:44:14.202 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
08:44:14.204 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6A 00 00 02 83 
08:44:14.215 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:14.217 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6A 00 00 02 00 00 8D 
08:44:14.218 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6A 00 00 02 00 00 8D 
08:44:14.219 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6A 00 00 02 
08:44:14.220 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 106, Status = Transmission complete and ACK received(0)
08:44:14.221 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
08:44:14.222 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@1a7911e already registered
08:44:14.223 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=106, payload=06 03 71 04 00 
08:44:14.224 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6A 00 00 02 
08:44:14.225 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=106, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
08:44:19.170 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 2 attempts left!
08:44:19.172 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
08:44:19.173 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
08:44:19.173 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
08:44:19.175 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 71 04 00 25 6B D8 
08:44:19.176 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 71 04 00 25 6B D8 
08:44:19.189 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08:44:19.200 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:19.202 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08:44:19.204 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08:44:19.205 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6B 00 00 03 83 
08:44:19.206 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08:44:19.222 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
08:44:19.225 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:19.228 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6B 00 00 03 00 00 8D 
08:44:19.231 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6B 00 00 03 00 00 8D 
08:44:19.233 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6B 00 00 03 
08:44:19.235 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 107, Status = Transmission complete and ACK received(0)
08:44:19.236 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
08:44:19.238 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@1a7911e already registered
08:44:19.239 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=107, payload=06 03 71 04 00 
08:44:19.241 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6B 00 00 03 
08:44:19.242 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=107, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
08:44:24.178 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 1 attempts left!
08:44:24.179 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
08:44:24.180 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
08:44:24.181 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
08:44:24.182 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 71 04 00 25 6C DF 
08:44:24.183 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 71 04 00 25 6C DF 
08:44:24.195 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08:44:24.197 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:24.198 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08:44:24.199 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08:44:24.205 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08:44:24.207 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
08:44:24.214 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6C 00 00 02 85 
08:44:24.229 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:24.231 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6C 00 00 02 00 00 8B 
08:44:24.233 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6C 00 00 02 00 00 8B 
08:44:24.237 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6C 00 00 02 
08:44:24.242 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 108, Status = Transmission complete and ACK received(0)
08:44:24.245 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
08:44:24.246 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@1a7911e already registered
08:44:24.248 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=108, payload=06 03 71 04 00 
08:44:24.251 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6C 00 00 02 
08:44:24.253 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=108, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
08:44:29.185 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Timeout while sending message. Requeueing - 0 attempts left!
08:44:29.186 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
08:44:29.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
08:44:29.188 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
08:44:29.190 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 71 04 00 25 6D DE 
08:44:29.191 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 71 04 00 25 6D DE 
08:44:29.202 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
08:44:29.207 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:29.210 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
08:44:29.211 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
08:44:29.215 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
08:44:29.216 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
08:44:29.222 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6D 00 00 02 84 
08:44:29.235 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
08:44:29.237 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6D 00 00 02 00 00 8A 
08:44:29.239 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6D 00 00 02 00 00 8A 
08:44:29.240 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6D 00 00 02 
08:44:29.241 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 109, Status = Transmission complete and ACK received(0)
08:44:29.242 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
08:44:29.243 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@1a7911e already registered
08:44:29.244 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=109, payload=06 03 71 04 00 
08:44:29.245 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6D 00 00 02 
08:44:29.246 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=109, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
08:44:34.193 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=109, payload=06 03 71 04 00

chris · July 31, 2016, 8:33am

I think we need to disable polling for this device - I’ll update the database according…

shorty707 · July 31, 2016, 9:52am

sounds good

for the not working volts and watts ? thats something else I guess?

I have 4 of these:

for a rebranded devolo version of the same switch (also config parameters are the same) it does work:

cheers

chris · July 31, 2016, 10:25am

I don’t know - I’d need to see a log, but the first question is if the device is sending the meter data? These channels are configured, so I would check the device configuration to make sure it should be sent (eg any parameters that control this, and make sure the associations are set correctly).

shorty707 · July 31, 2016, 11:26am

well heres a log where I switch on and off
Node 5 --> doenst show watts / volts
Node 2–> works fully

seems like Node 5 is not sending any information about METER … however the channels are there:

13:18:28.689 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Command received zwave:device:15348538564:node5:switch_binary --> OFF
13:18:28.691 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 5: Creating new message for application command SWITCH_BINARY_SET
13:18:28.696 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
13:18:28.697 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
13:18:28.698 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 25 01 00 25 6B 8A 
13:18:28.700 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 25 01 00 25 6B 8A 
13:18:28.726 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
13:18:28.730 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:28.733 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
13:18:28.734 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
13:18:28.736 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
13:18:28.748 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
13:18:28.758 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6B 00 00 03 83 
13:18:28.763 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:28.767 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6B 00 00 03 00 00 8D 
13:18:28.769 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6B 00 00 03 00 00 8D 
13:18:28.774 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6B 00 00 03 
13:18:28.778 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 107, Status = Transmission complete and ACK received(0)
13:18:28.782 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from DONE
13:18:28.786 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@121771d already registered
13:18:28.790 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=5, callback=107, payload=05 03 25 01 00 
13:18:28.795 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6B 00 00 03 
13:18:28.798 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=107, expected=SendData, cancelled=false        transaction complete!
13:18:28.802 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
13:18:28.804 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:18:28.808 [DEBUG] [curityCommandClassWithInitialization] - NODE 5: updating lastSentMessageTimestamp
13:18:28.810 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Response processed after 104ms/4291ms.
13:18:30.330 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 25 03 00 D2 
13:18:30.333 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:30.334 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 05 03 25 03 00 D2 
13:18:30.335 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 05 03 25 03 00 D2 
13:18:30.337 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 03 25 03 00 
13:18:30.339 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Application Command Request (ALIVE:DONE)
13:18:30.343 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from DONE
13:18:30.344 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@121771d already registered
13:18:30.346 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Incoming command class SWITCH_BINARY
13:18:30.348 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 5
13:18:30.349 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 5: Switch Binary report, value = 0
13:18:30.353 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
13:18:30.353 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
13:18:30.354 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_BINARY, value = 0
13:18:30.355 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:15348538564:node5:switch_binary to OFF [OnOffType]
13:18:30.357 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=5, callback=107, payload=05 03 25 01 00 
13:18:30.361 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 03 25 03 00 
13:18:30.362 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=107, expected=SendData, cancelled=false      MISMATCH
13:18:31.626 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Command received zwave:device:15348538564:node5:switch_binary --> ON
13:18:31.627 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 5: Creating new message for application command SWITCH_BINARY_SET
13:18:31.628 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
13:18:31.628 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
13:18:31.629 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 05 03 25 01 FF 25 6C 72 
13:18:31.630 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 25 01 FF 25 6C 72 
13:18:31.642 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
13:18:31.653 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:31.655 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
13:18:31.657 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
13:18:31.657 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6C 00 00 03 84 
13:18:31.658 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
13:18:31.658 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
13:18:31.659 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:31.660 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6C 00 00 03 00 00 8A 
13:18:31.662 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6C 00 00 03 00 00 8A 
13:18:31.663 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6C 00 00 03 
13:18:31.663 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 108, Status = Transmission complete and ACK received(0)
13:18:31.664 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from DONE
13:18:31.664 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@121771d already registered
13:18:31.665 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=5, callback=108, payload=05 03 25 01 FF 
13:18:31.670 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6C 00 00 03 
13:18:31.672 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=108, expected=SendData, cancelled=false        transaction complete!
13:18:31.673 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
13:18:31.676 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:18:31.681 [DEBUG] [curityCommandClassWithInitialization] - NODE 5: updating lastSentMessageTimestamp
13:18:31.692 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Response processed after 54ms/4291ms.
13:18:33.263 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 25 03 FF 2D 
13:18:33.265 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:33.266 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 05 03 25 03 FF 2D 
13:18:33.268 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 05 03 25 03 FF 2D 
13:18:33.269 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 03 25 03 FF 
13:18:33.269 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Application Command Request (ALIVE:DONE)
13:18:33.270 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from DONE
13:18:33.274 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@121771d already registered
13:18:33.277 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Incoming command class SWITCH_BINARY
13:18:33.284 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 5
13:18:33.286 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 5: Switch Binary report, value = 255
13:18:33.287 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
13:18:33.289 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
13:18:33.290 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_BINARY, value = 255
13:18:33.291 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:15348538564:node5:switch_binary to ON [OnOffType]
13:18:33.299 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=5, callback=108, payload=05 03 25 01 FF 
13:18:33.302 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 03 25 03 FF 
13:18:33.303 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=108, expected=SendData, cancelled=false      MISMATCH
13:18:36.789 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:15348538564:node2:switch_binary --> ON
13:18:36.790 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Creating new message for application command SWITCH_BINARY_SET
13:18:36.791 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
13:18:36.791 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
13:18:36.793 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 25 01 FF 25 6D 74 
13:18:36.795 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 25 01 FF 25 6D 74 
13:18:36.812 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
13:18:36.821 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:36.835 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
13:18:36.838 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
13:18:36.839 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
13:18:36.840 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
13:18:37.121 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6D 00 00 20 A6 
13:18:37.123 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
13:18:37.124 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6D 00 00 20 00 00 A8 
13:18:37.125 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6D 00 00 20 00 00 A8

shorty707 · July 31, 2016, 11:26am

log part2

 13:18:37.127 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6D 00 00 20 
    13:18:37.128 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 109, Status = Transmission complete and ACK received(0)
    13:18:37.129 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
    13:18:37.130 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@87e6c7 already registered
    13:18:37.132 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=109, payload=02 03 25 01 FF 
    13:18:37.134 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6D 00 00 20 
    13:18:37.135 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=109, expected=SendData, cancelled=false        transaction complete!
    13:18:37.136 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
    13:18:37.137 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
    13:18:37.137 [DEBUG] [curityCommandClassWithInitialization] - NODE 2: updating lastSentMessageTimestamp
    13:18:37.138 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Response processed after 342ms/4291ms.
    13:18:38.781 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 C6 
    13:18:38.788 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
    13:18:38.790 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 14 00 04 00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 C6 
    13:18:38.792 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 14 00 04 00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 C6 
    13:18:38.797 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 
    13:18:38.799 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Application Command Request (ALIVE:DONE)
    13:18:38.801 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
    13:18:38.803 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@87e6c7 already registered
    13:18:38.803 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Incoming command class METER
    13:18:38.804 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Received METER command V3
    13:18:38.805 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
    13:18:38.806 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
    13:18:38.806 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent
    13:18:38.807 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = METER, value = 0E+1
    13:18:38.808 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:15348538564:node2:meter_watts to 0 [DecimalType]
    13:18:38.810 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_Power_Factor <> E_W
    13:18:38.811 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_KWh <> E_W
    13:18:38.812 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_A <> E_W
    13:18:38.812 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_V <> E_W
    13:18:38.813 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=109, payload=02 03 25 01 FF 
    13:18:38.815 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 
    13:18:38.815 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=109, expected=SendData, cancelled=false      MISMATCH
    13:18:38.820 [WARN ] [home.core.internal.items.ItemUpdater] - InstantiationException on org.eclipse.smarthome.core.library.types.StringType
    13:18:39.125 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 25 03 FF 2A 
    13:18:39.128 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
    13:18:39.130 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 02 03 25 03 FF 2A 
    13:18:39.131 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 02 03 25 03 FF 2A 
    13:18:39.133 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 03 25 03 FF 
    13:18:39.134 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Application Command Request (ALIVE:DONE)
    13:18:39.135 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
    13:18:39.143 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@87e6c7 already registered
    13:18:39.147 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Incoming command class SWITCH_BINARY
    13:18:39.147 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 2
    13:18:39.148 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Switch Binary report, value = 255
    13:18:39.148 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
    13:18:39.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
    13:18:39.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_BINARY, value = 255
    13:18:39.150 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:15348538564:node2:switch_binary to ON [OnOffType]
    13:18:39.153 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=109, payload=02 03 25 01 FF 
    13:18:39.154 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 03 25 03 FF 
    13:18:39.154 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=109, expected=SendData, cancelled=false      MISMATCH
    13:18:40.676 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:15348538564:node2:switch_binary --> OFF
    13:18:40.677 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Creating new message for application command SWITCH_BINARY_SET
    13:18:40.678 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
    13:18:40.679 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
    13:18:40.679 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 25 01 00 25 6E 88 
    13:18:40.680 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 25 01 00 25 6E 88 
    13:18:40.692 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
    13:18:40.699 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
    13:18:40.700 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
    13:18:40.702 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
    13:18:40.703 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
    13:18:40.704 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
    13:18:41.671 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6E 00 00 63 E6 
    13:18:41.673 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
    13:18:41.675 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6E 00 00 63 00 00 E8 
    13:18:41.676 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6E 00 00 63 00 00 E8 
    13:18:41.677 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6E 00 00 63 
    13:18:41.678 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 110, Status = Transmission complete and ACK received(0)
    13:18:41.678 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
    13:18:41.679 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@87e6c7 already registered
    13:18:41.680 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=110, payload=02 03 25 01 00 
    13:18:41.681 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6E 00 00 63 
    13:18:41.682 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=110, expected=SendData, cancelled=false        transaction complete!
    13:18:41.682 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
    13:18:41.683 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
    13:18:41.687 [DEBUG] [curityCommandClassWithInitialization] - NODE 2: updating lastSentMessageTimestamp
    13:18:41.688 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Response processed after 1004ms/4291ms.
    13:18:43.331 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 C6 
    13:18:43.334 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
    13:18:43.336 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 14 00 04 00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 C6 
    13:18:43.337 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 14 00 04 00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 C6 
    13:18:43.339 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 
    13:18:43.340 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Application Command Request (ALIVE:DONE)
    13:18:43.340 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
    13:18:43.341 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@87e6c7 already registered
    13:18:43.342 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Incoming command class METER
    13:18:43.342 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Received METER command V3
    13:18:43.345 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
    13:18:43.346 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
    13:18:43.358 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent
    13:18:43.360 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = METER, value = 0E+1
    13:18:43.362 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:15348538564:node2:meter_watts to 0 [DecimalType]
    13:18:43.368 [WARN ] [home.core.internal.items.ItemUpdater] - InstantiationException on org.eclipse.smarthome.core.library.types.StringType
    13:18:43.371 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_Power_Factor <> E_W
    13:18:43.372 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_KWh <> E_W
    13:18:43.375 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_A <> E_W
    13:18:43.376 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_V <> E_W
    13:18:43.378 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=110, payload=02 03 25 01 00 
    13:18:43.379 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 0E 32 02 21 34 00 00 00 00 00 00 00 00 00 00 
    13:18:43.380 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=110, expected=SendData, cancelled=false      MISMATCH
    13:18:43.675 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 25 03 00 D5 
    13:18:43.678 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
    13:18:43.680 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 02 03 25 03 00 D5 
    13:18:43.683 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 02 03 25 03 00 D5 
    13:18:43.690 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 03 25 03 00 
    13:18:43.691 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Application Command Request (ALIVE:DONE)
    13:18:43.692 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
    13:18:43.693 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@87e6c7 already registered
    13:18:43.694 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Incoming command class SWITCH_BINARY
    13:18:43.695 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 2
    13:18:43.696 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Switch Binary report, value = 0
    13:18:43.696 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
    13:18:43.697 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
    13:18:43.698 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_BINARY, value = 0
    13:18:43.699 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:15348538564:node2:switch_binary to OFF [OnOffType]
    13:18:43.702 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=110, payload=02 03 25 01 00 
    13:18:43.704 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 03 25 03 00 
    13:18:43.707 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=110, expected=SendData, cancelled=false      MISMATCH

chris · July 31, 2016, 11:29am

There are no meter reports being received, so as above, I would check the device configuration.

shorty707 · July 31, 2016, 11:31am

sorry forgot to mention
I did … all config looks good and is identical for node 2 (working) and node 5 (not working)

greetings

chris · July 31, 2016, 11:32am

Ok, but I still don’t think there’s anything I can do to help.

If the binding isn’t receiving any data, then you need to look at the device configuration. The only way the binding might be able to help is if you want to enable polling to get the data, but IMHO that’s not a good idea and without knowing the device, I sincerely doubt it’s needed.

shorty707 · July 31, 2016, 11:37am

could this also be an issue with how the device is “described” in the database?

chris · July 31, 2016, 11:39am

You should read through the device manual and see what needs to be set. If the manual says to set something in the device, and it’s not in the database, or is incorrect in the database, then yes, we need to fix that, but otherwise it won’t be an issue with the database.

shorty707 · July 31, 2016, 12:13pm

what I observed is that when I set the association for “Openhab Controller” in Habmin
then automatically all channels / items are depopulated and I have 0 active channels
and also asscociation group 1 is blank again and the Controller is not in there

mhhh

and all “PAN11” do show get config in habmin

chris · July 31, 2016, 12:17pm

How are you configuring your items? Is it done through HABmin, or through static files, or are you just letting the system automatically create them?

For the PAN11, please provide a full debug log from startup - I’m guessing that there’s an issue in the database that’s stopping it from completing initialisation.

shorty707 · July 31, 2016, 12:19pm

ok will restart and send you the log

for items …I just let the system automatically create them (at least the zwave items)

chris · July 31, 2016, 12:20pm

Ok - I’m not sure if that’s causing a problem with the items dissappearing. I personally don’t like this as you can’t change the labels or any other configuration about the item (since the item doesn’t really exist)

shorty707 · July 31, 2016, 12:29pm

whats your approach? static files? or via habmin a manual creation?

chris · July 31, 2016, 12:34pm

I use HABmin to create them and I disable the autocreation option (as per here).

If you let the system create the items, then they don’t really exist, and when you try and change the label, or anything else, you get an error (https://www.eclipse.org/forums/index.php/t/1079357/).

I also use my Json storage database to store the data rather than MapDB, so I can edit the files -:

I know everyone has their views on how they want to configure their system, so that’s just mine - I’m not saying it’s the best

shorty707 · July 31, 2016, 12:41pm

I used static files before and dont like MapDB for the reasons you name… So I wanted to go back to static files … will check that json storage db could be what I was looking for

I sent you a lenghty log from the full startup and wrote the node ids which seem to generate some trouble in the mail.
let me know when I can try anything or you need something else

cheers