HomePro ZDP200 - In database, but unknown

havaak · September 17, 2017, 4:24pm

Just started to migrate to OpenHAB 2.1 from 1.8. Same problem, node is found but shows as unknown device… what to do next?

log:
2017-09-17 18:16:26.851 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0

@chris, can you help us out, do you need more info?

chris · September 17, 2017, 4:40pm

If this is a battery device, try waking the device up. The 7FFFFFFF business means that it’s not downloaded the information required to identify the device.

havaak · September 17, 2017, 4:47pm

@chris,

its a pluggable module in which you can plug a lamp. It dims and switches on/off. Works with 1.9 and is in the database

ACT - Advanced Control Technologies ZDP200 HomePro ZDP200 Wall Dimmer All

kind regards

Han

chris · September 17, 2017, 4:49pm

All I can really say is that the binding is probably not communicating with the device - the 7FFFFFFF business means that it’s not downloaded the information required to identify the device. Until it knows this information, the database is irrelevant.

havaak · September 17, 2017, 4:53pm

@chris,

I downgraded to the OH 1 binding (zwave1) and then I am able to switch on/off and dim the device. Still the log shows the same:

2017-09-17 18:37:03.423 [WARN ] [nitialization.ZWaveNodeStageAdvancer] - NODE 2: Node advancer: SET_ASSOCIATION - Unknown device: 7fffffff:7fffffff:7fffffff

As I have 3 of these nodes I am now stuck at zwave1, that is if I want to have dinner

was not able to command the devices under the zwave binding.

chris · September 17, 2017, 5:10pm

Really I can’t comment much more without more information. I’d suggest to check the debug logs to find out what is happening.

havaak · September 27, 2017, 6:54pm

@chris,

I had another go after switching back to 1.9 to keep things running. I have removed 1.9 and installed OH2 zwave binding.

The Homepro ZDP200 shows as a new thing but it says “Z-Wave Node 2 Unknown Device” in the thing overview.

If I try to heal the node everythings looks ok but not the manufacturer info (this is btw on all 3 nodes I have). What is the next I could try?

log:

2017-09-27 20:42:57.138 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:0042a834:node2:switch_dimmer --> 44
2017-09-27 20:42:57.139 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command for unknown channel zwave:device:0042a834:node2:switch_dimmer with PercentType
2017-09-27 20:43:11.871 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Configuration update received
2017-09-27 20:43:11.875 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Configuration update action_heal to -232323
2017-09-27 20:43:11.875 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Starting heal on node!
2017-09-27 20:43:11.876 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from HEAL_START
2017-09-27 20:43:11.877 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@5fad2b65 already registered
2017-09-27 20:43:11.877 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - HEAL_START: queue length(0), free to send(true)
2017-09-27 20:43:11.877 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Initialisation retry timer started 5000
2017-09-27 20:43:11.877 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - HEAL_START try 1: stageAdvanced(false)
2017-09-27 20:43:11.877 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to DELETE_ROUTES
2017-09-27 20:43:11.878 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2017-09-27 20:43:11.878 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-09-27 20:43:11.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - DELETE_ROUTES try 0: stageAdvanced(true)
2017-09-27 20:43:11.878 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Generate return routes list
2017-09-27 20:43:11.878 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: No return routes required.
2017-09-27 20:43:11.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to RETURN_ROUTES
2017-09-27 20:43:11.879 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2017-09-27 20:43:11.879 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-09-27 20:43:11.879 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - RETURN_ROUTES try 0: stageAdvanced(true)
2017-09-27 20:43:11.879 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Generate return routes list
2017-09-27 20:43:11.879 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: No return routes required.
2017-09-27 20:43:11.879 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to NEIGHBORS
2017-09-27 20:43:11.879 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2017-09-27 20:43:11.879 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-09-27 20:43:11.879 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - NEIGHBORS try 0: stageAdvanced(true)
2017-09-27 20:43:11.880 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: NEIGHBORS - get RoutingInfo
2017-09-27 20:43:11.880 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 2: Request routing info
2017-09-27 20:43:11.883 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
2017-09-27 20:43:11.897 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-09-27 20:43:11.903 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-09-27 20:43:11.904 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 80 02 00 00 03 79
2017-09-27 20:43:11.906 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 02 00 00 03 79
2017-09-27 20:43:11.916 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 20 01 80 6D 83 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 B1
2017-09-27 20:43:11.931 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-09-27 20:43:11.931 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 20 01 80 6D 83 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 B1
2017-09-27 20:43:11.931 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 20 01 80 6D 83 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 B1
2017-09-27 20:43:11.931 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetRoutingInfo[0x80], type=Response[0x01], priority=High, dest=255, callback=0, payload=6D 83 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-09-27 20:43:11.932 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 2: Got NodeRoutingInfo request.
2017-09-27 20:43:11.932 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 2: Neighbor nodes: 1 3 4 6 7 9 10 16 17
2017-09-27 20:43:11.932 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNetworkEvent
2017-09-27 20:43:11.932 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNetworkEvent
2017-09-27 20:43:11.932 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetRoutingInfo[0x80], type=Request[0x00], priority=High, dest=255, callback=0, payload=02 00 00 03
2017-09-27 20:43:11.932 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetRoutingInfo[0x80], type=Response[0x01], priority=High, dest=255, callback=0, payload=6D 83 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-09-27 20:43:11.932 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetRoutingInfo, callback id=0, expected=GetRoutingInfo, cancelled=false        transaction complete!
2017-09-27 20:43:11.933 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - NEIGHBORS: Transaction complete (GetRoutingInfo:Request) success(true)
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - checking initialisation queue. Queue size 1.
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - message removed from queue. Queue size 0.
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - NEIGHBORS: queue length(0), free to send(true)
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Initialisation retry timer started 5000
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - NEIGHBORS try 1: stageAdvanced(false)
2017-09-27 20:43:11.933 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to DONE
2017-09-27 20:43:11.933 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2017-09-27 20:43:11.933 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties.
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=2147483647
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: action_heal, ,
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: switchall_mode, 255, 255
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: action_reinit, ,
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: action_remove, ,
2017-09-27 20:43:11.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: MANUFACTURER not set
2017-09-27 20:43:11.935 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - DONE try 0: stageAdvanced(true)
2017-09-27 20:43:11.935 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Serializing to file /var/lib/openhab2/zwave/node2.xml
2017-09-27 20:43:11.953 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Initialisation complete!
2017-09-27 20:43:11.956 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2017-09-27 20:43:11.958 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-09-27 20:43:11.961 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties.
2017-09-27 20:43:11.964 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=2147483647
2017-09-27 20:43:11.967 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: action_heal, ,
2017-09-27 20:43:11.971 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: switchall_mode, 255, 255
2017-09-27 20:43:11.977 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: action_reinit, ,
2017-09-27 20:43:11.984 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Property to update: action_remove, ,
2017-09-27 20:43:11.985 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: MANUFACTURER not set
2017-09-27 20:43:11.986 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 61ms/3266ms.

chris · September 29, 2017, 12:45pm

I would suggest to get a debug log during a reinitialisation so we can see why it’s not downloading the manufacturer data. Reinitialisation is an option in HABmin - select the thing, then it’s an advanced mode option in the thing menu.

havaak · October 1, 2017, 5:06pm

@chris,

can you explain what you mean with “reinitialisation”, there is no such option in the advanced settings menu of the thing. Only “remove”, setting as "failed and heal the node.

chris · October 1, 2017, 5:11pm

This option is only available if the device has completed initialisation in the first place. If it’s still initialising, the option won’t be available.

In this case, stop the binding, delete any XML for this node (in the {userdata}/zwave folder) and then restart the binding. This will fundimentally do the same thing.

havaak · October 1, 2017, 5:54pm

@chris,

logfile is running, how long does it have to run for?

I followed the log with a tail -f and noted that the binding is comparing my node (NODE 19) to the database. It fails to so however

2017-10-01 19:39:39.864 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:act_45602_00_000
2017-10-01 19:39:39.864 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:act_zdm230_00_000
2017-10-01 19:39:39.864 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:act_zdp200_00_000
2017-10-01 19:39:39.864 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:act_zdw103_00_000
2017-10-01 19:39:39.864 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:act_zdw120_00_000 
....
2017-10-01 19:39:39.883 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:fibaro_fgs221_01_00
2017-10-01 19:39:39.909 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Checking zwave:zyxel_st812_00_000
2017-10-01 19:39:39.911 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0

The hardware is mentioned in the database however:

ACT - Advanced Control Technologies ZDP200 HomePro ZDP200 Wall Dimmer All 2

In the logfile there is some stuff regarding manufacterer:

2017-10-01 19:39:41.147 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer - advancing to DONE
2017-10-01 19:39:41.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-10-01 19:39:41.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Updating node properties.
2017-10-01 19:39:41.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Updating node properties. MAN=2147483647
2017-10-01 19:39:41.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Property to update: action_heal, ,
2017-10-01 19:39:41.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Property to update: switchall_mode, 255, 255
2017-10-01 19:39:41.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: MANUFACTURER not set
2017-10-01 19:39:41.149 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer: loop - DONE try 0: stageAdvanced(true)
2017-10-01 19:39:41.149 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 19: Serializing to file /var/lib/openhab2/zwave/node19.xml
2017-10-01 19:39:41.151 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer: Initialisation complete!
2017-10-01 19:39:41.152 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-10-01 19:39:41.152 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Updating node properties.
2017-10-01 19:39:41.153 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Updating node properties. MAN=2147483647
2017-10-01 19:39:41.153 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Property to update: action_heal, ,
2017-10-01 19:39:41.158 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Property to update: switchall_mode, 255, 255
2017-10-01 19:39:41.158 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: MANUFACTURER not set

regards and thanks for your support!

Han

chris · October 1, 2017, 6:57pm

Can you post say the first 5 or 10 minutes (or up to 10MB of data) somewhere on the net and I’ll take a look. The little parts above don’t really provide a lot of useful info…

Cheers
Chris

havaak · October 1, 2017, 8:01pm

@chris,

have send you an email with a link to the file. The node of interest is Node 19.

thx

Han

chris · October 1, 2017, 9:03pm

So the problem is that the device isn’t reporting that it supports basic command classes such as the manufacturer specific, version etc.

I guess this is an old device as I’m pretty sure that this is not compliant to the current standards.

The big question is if it supports these classes, but just doesn’t report them in the NIF, or if it’s not even supported - if it’s not supported, then there’s no way to identify it…

I’ll do an update to the database to force this command class and well see if that helps…

havaak · October 2, 2017, 4:37am

Chris,

to catch this change I need to install the latest version of the binding I guess?

cheers

Han

chris · October 2, 2017, 7:38am

You will, yes. I’ve not actually updated the binding yet - just the database. I’ll do an export of the database tonight hopefully…

Cheers
Chris

morten · October 2, 2017, 7:54am

Thanks guys!

I didn’t get an answer for a long time, so I just stopped using the devices. It’s great, Hannibal, that you brought this up again. I’ve partly followed your discussion, and would have loved to help debugging, but I’ve just moved to a new house, and haven’t installed my system yet.

Looking forward to know if they work in the new binding.

havaak · October 5, 2017, 6:19pm

@chris,

do you know when a new build will be available? My current ones dates back to 09/30

regards

Han

chris · October 5, 2017, 6:30pm

Well, the last merge was on the 3rd Oct. I don’t think builds happen automatically sometimes - I’ll kick one off manually now.

havaak · October 11, 2017, 12:10pm

I had a go at the latest binding, but I am sorry to say the ZDP200 still shows the same behaviour. I’ll have a closer look at the logfiles later on but I think the ZDP220 are no longer supported