Z-Wave Telldus

Andreas_L · November 19, 2016, 8:44pm

Hi have a Telldus Magnetic Sensor Switch which is in the database, however I cannot add it it seems. By the way thanks for fixing the Vision sensor last time…

21:34:43.998 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Checking zwave:benext_plugindimmer_00_000
21:34:43.998 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Checking zwave:widom_wds_00_000
21:34:43.999 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
21:34:44.009 [INFO ] [smarthome.event.InboxAddedEvent     ] - Discovery Result with UID 'zwave:device:4902bef9:node15' has been added.
21:34:44.010 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:4902bef9:node15' to inbox.
21:34:44.010 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
21:34:44.014 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
21:34:44.014 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
21:34:44.014 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 01 70 
21:34:44.014 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 01 70 
21:34:44.015 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
21:34:44.529 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_ack changed from 116 to 117
21:34:44.563 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_sof changed from 194 to 195
21:34:44.578 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 01 00 00 B2 
21:34:44.581 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:34:44.581 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 4A 01 01 00 00 B2 
21:34:44.581 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 4A 01 01 00 00 B2 
21:34:44.581 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 01 00 00 
21:34:44.581 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
21:34:44.581 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
21:34:44.582 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=C1 01 
21:34:44.582 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 01 00 00 
21:34:44.582 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=AddNodeToNetwork, callback id=0, expected=AddNodeToNetwork, cancelled=false        transaction complete!
21:34:44.582 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
21:34:44.586 [INFO ] [smarthome.event.BindingEvent        ] - org.openhab.binding.zwave.event.BindingEvent@7c8b93fa
21:34:44.587 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 61ms/998ms.
21:35:08.069 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:RINCON_000E58D66BD801400' changed from OFFLINE to ONLINE
21:35:13.403 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
21:35:13.404 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
21:35:13.404 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
21:35:13.404 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller end inclusion
21:35:13.404 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
21:35:13.404 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 01 B4 
21:35:13.404 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 01 B4 
21:35:13.991 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_ack changed from 117 to 118
21:35:14.041 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_sof changed from 195 to 196
21:35:14.056 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 06 04 00 B1 
21:35:14.060 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:35:14.060 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 4A 01 06 04 00 B1 
21:35:14.060 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 4A 01 06 04 00 B1 
21:35:14.060 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 06 04 00 
21:35:14.060 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
21:35:14.060 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
21:35:14.060 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovered
21:35:14.065 [INFO ] [smarthome.event.BindingEvent        ] - org.openhab.binding.zwave.event.BindingEvent@444c6a2d
21:35:14.061 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveInclusionEvent
21:35:14.066 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 4: Newly included node already initialising at PING
21:35:14.067 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=05 01 
21:35:14.067 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 06 04 00 
21:35:14.067 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=AddNodeToNetwork, callback id=0, expected=AddNodeToNetwork, cancelled=false        transaction complete!
21:35:14.067 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
21:35:14.067 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 78ms/998ms.
Received disconnect from 127.0.0.1 port 8101:2: User session has timed out idling after 1800000 ms.

Andreas_L · November 29, 2016, 6:19pm

Is there any way I can manually edit some XML file or similar to get the node added to OpenHab?

Andreas_L · November 29, 2016, 6:24pm

This is the device by the way:

http://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/312

chris · November 29, 2016, 7:17pm

I’m not sure I understand the problem - what do you mean you can’t include it? Looking at the short log, it seems the device might have been included but the log is very short so it’s hard to know.

Andreas_L · November 29, 2016, 10:21pm

When I add it to Paper UI it comes up with the following information:

Z-Wave Node 15
Unknown Device

This device has not been fully discovered by the binding. There are a few possible reasons for this -:
The device is not in the database. If the device attributes show that this device has a valid manufacturer ID, device ID and type, then this is likely the case (eg. you see a label like “Z-Wave node 1 (0082:6015:020D::2.0)”). Even if the device appears to be in the database, some manufacturers use multiple sets of references for different regions or versions, and your device references may not be in the database. In either case, the database must be updated and you should raise an issue to get this addressed.
The device initialisation is not complete. Once the device is included into the network, the binding must interrogate it to find out what type of device it is. One part of this process is to get the manufacturer information required to identify the device, and until this is done, the device will remain unknown. For mains powered devices, this will occur quickly, however for battery devices the device must be woken up a number of times to allow the discovery phase to complete. This must be performed with the device close to the controller.

If I delete it, start search for zwave devices, I get this:

pastebin.com

http://pastebin.com/raw/gTpNZJ0T

23:16:48.405 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
23:16:48.408 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Starting ZWave inclusion scan for zwave:serial_zstick:4902bef9
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery completed
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Checking zwave:zwaveme_zmerc2_00_000
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Checking zwave:vision_zs6101_00_000
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Checking zwave:ge_45609_00_000
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Checking zwave:aeon_dsb45_00_000
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Checking zwave:cbcc_swzcs1_00_000
23:16:48.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Checking zwave:fibaro_fgcc001_00_000

This paste has been truncated. show original

If I add it from the inbox I get this:
23:18:57.198 [INFO ] [smarthome.event.InboxRemovedEvent ] - Discovery Result with UID ‘zwave:device:4902bef9:node15’ has been removed.
23:18:57.199 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing ‘zwave:device:4902bef9:node15’ has been added.
23:18:57.200 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:device, thing.id=zwave:device:4902bef9:node15, service.id=393, service.bundleid=197, service.scope=singleton} - org.openhab.binding.zwave
23:18:57.201 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=394, service.bundleid=197, service.scope=singleton} - org.openhab.binding.zwave
23:18:57.202 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler.
23:18:57.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: MANUFACTURER not set
23:18:57.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller status changed to ONLINE.
23:18:57.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller is ONLINE. Starting device initialisation.
23:18:57.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating node properties.
23:18:57.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating node properties. MAN=2147483647
23:18:57.205 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising Thing Node…
23:18:57.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Polling intialised at 1800 seconds - start in 1800000 milliseconds.
23:18:57.207 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller initialised.
23:18:57.207 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller status changed to ONLINE.
23:18:57.207 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller is ONLINE. Starting device initialisation.
23:18:57.210 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:4902bef9:node15’ changed from UNINITIALIZED to INITIALIZING
23:18:57.211 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:4902bef9:node15’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
23:18:57.211 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:4902bef9:node15’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

chris · November 29, 2016, 10:35pm

I don’t really know what this device is, but if it’s a battery device, then it looks like it might not have woken up? Have you woken this up a few times in close proximity to the controller?

If so, then please provide a debug log showing this communication - the log you provided doesn’t really have much in it unfortunately.

Andreas_L · November 29, 2016, 10:59pm

Its a battery device. Magnetic door/window sensor. Has a dedicated wake-up switch Ive tried to activate many times… I had some trouble getting it added as it wasnt found by openhab. I did manage to add it to a secondary controller (z-way razberry) and had it working fine there. After that I could find it in openhab…

chris · November 29, 2016, 11:10pm

Can you get a debug log when you wake the device up. Currently in the log you provided, there’s no communication with the device and we need to solve that first.

Andreas_L · November 30, 2016, 7:11pm

Alright. So nothing happened in the z-wave log when I woke the device up. I did manage to start z-way, exclude it, restart openhab, and then magically it appeared as node 12. I now get Z-Wave status updates from the device, but it still shows up as unknown:

20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Config about to update 0 parameters…
20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Config about to update 0 parameters…
20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Config about to update 0 parameters…
20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Config about to update 0 parameters…
20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Config about to update 0 parameters…
20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Update ASSOCIATION group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@344a690d: Adding node_11_0
20:09:19.497 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Configuration synchronised
20:09:19.504 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller initialised.
20:09:19.505 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller status changed to ONLINE.
20:09:19.506 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller is ONLINE. Starting device initialisation.
20:09:19.506 [WARN ] [ome.core.thing.internal.ThingManager] - Attempt to register a handler twice for thing zwave:device:4902bef9:node12 at the same time will be ignored.
20:09:19.506 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising Thing Node…
20:09:19.506 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling intialised at 1800 seconds - start in 1800000 milliseconds.
20:09:19.506 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:device, thing.id=zwave:device:4902bef9:node12, service.id=386, service.bundleid=197, service.scope=singleton} - org.openhab.binding.zwave
20:09:19.510 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=387, service.bundleid=197, service.scope=singleton} - org.openhab.binding.zwave
20:09:19.514 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:4902bef9:node12’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
20:09:19.514 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:4902bef9:node12’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
20:09:19.515 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zwave:device:4902bef9:node12’ has been updated.
20:09:19.572 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_sof changed from 372 to 373
20:09:19.595 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 0C 04 30 03 FF 0A 3F
20:09:19.596 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:09:19.596 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 04 00 0C 04 30 03 FF 0A 3F
20:09:19.596 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0A 00 04 00 0C 04 30 03 FF 0A 3F
20:09:19.597 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 0C 04 30 03 FF 0A
20:09:19.597 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 12: Application Command Request (ALIVE:GET_CONFIGURATION)
20:09:19.597 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 12: Incoming command class SENSOR_BINARY
20:09:19.597 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 12: Received SENSOR_BINARY command V2
20:09:19.597 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - Processing Sensor Type 10
20:09:19.597 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - Sensor Type is DOORWINDOW
20:09:19.597 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 12: Sensor Binary report, type=Door/Window, value=255
20:09:19.597 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveBinarySensorValueEvent
20:09:19.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveBinarySensorValueEvent
20:09:19.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_BINARY, value = 255
20:09:19.597 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=12, callback=107, payload=0C 03 70 05 08
20:09:19.597 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 0C 04 30 03 FF 0A
20:09:19.597 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=107, expected=ApplicationCommandHandler, cancelled=false transaction complete!
20:09:19.597 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:09:19.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - GET_CONFIGURATION: Transaction complete (SendData:Request) success(true)
20:09:19.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - checking initialisation queue. Queue size 1.
20:09:19.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - message removed from queue. Queue size 0.
20:09:19.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - GET_CONFIGURATION: queue length(0), free to send(true)
20:09:19.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - GET_CONFIGURATION try 5: stageAdvanced(false)
20:09:19.601 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_1_1 - config
20:09:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_1_1 - index 1
20:09:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_2_1 - config
20:09:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_2_1 - index 2
20:09:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_3_1 - config
20:09:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_3_1 - index 3
20:09:19.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_4_1 - config
20:09:19.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_4_1 - index 4
20:09:19.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_5_1 - config
20:09:19.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_5_1 - index 5
20:09:19.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_6_1 - config
20:09:19.604 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_6_1 - index 6
20:09:19.604 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_7_1 - config
20:09:19.604 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_7_1 - index 7
20:09:19.604 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_8_1 - config
20:09:19.604 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_8_1 - index 8
20:09:19.604 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
20:09:19.605 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1
20:09:19.605 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
20:09:19.605 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
20:09:19.605 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Response processed after 1226ms/1226ms.
20:09:19.605 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
20:09:19.605 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 70 05 08 25 6C DD
20:09:19.605 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 70 05 08 25 6C DD
20:09:19.609 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_ack changed from 179 to 180
20:09:19.615 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_sof changed from 373 to 374
20:09:19.626 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
20:09:19.627 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:09:19.628 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
20:09:19.628 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
20:09:19.628 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
20:09:19.628 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
20:09:19.636 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4902bef9_serial_sof changed from 374 to 375
20:09:19.654 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 6C 00 00 03 84
20:09:19.655 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:09:19.655 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 6C 00 00 03 00 00 8A
20:09:19.655 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 6C 00 00 03 00 00 8A
20:09:19.655 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=6C 00 00 03
20:09:19.655 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 108, Status = Transmission complete and ACK received(0)
20:09:19.655 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=108, payload=0C 03 70 05 08
20:09:19.655 [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
20:09:19.655 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=108, expected=ApplicationCommandHandler, cancelled=false MISMATCH
20:09:24.607 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 2 attempts left!
20:09:24.608 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 12: Is sleeping
20:09:24.608 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 12: Putting message SendData in wakeup queue.
20:09:24.608 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:09:24.608 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 12: Message already on the wake-up queue. Removing original.
20:09:24.608 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 12: Putting message SendData in wakeup queue.

Andreas_L · November 30, 2016, 7:14pm

Never mind… After repeatedly deleting, adding, deleting, waking up and readding it was now detected!! Working fine now… Lesson learned was not to play around with secondary Z-wave controllers in the network.