Device could not be resolved to a thingType! Although it exists in the Database

chris2 · August 19, 2016, 4:22am

I wanted to start updating the CT101 Thermostat in the database, but have run into a problem.

When I scan for the Thermostat and add it as a Thing I get the following error:

“Device could not be resolved to a thingType! 0098:6501:000C::9.0”

I expected the device to at least be identified, as there is basic (although incomplete) data in the database.

What am I missing here that is preventing OpenHab from matching this CT101 thermostat with the CT101 device info in the database?

Manufacturer=0098
Type:ID=6501:000C
Frimware =9.0 (data base item has Firmware=Any)

I’d appreciate any pointers.

chris2 · August 21, 2016, 2:44am

Update:
I just reinstalled the OpenHab2 from CloudBees, just to make sure I have the most recent version.
Problem still exists, however I now see data in Habmin2, that apears to hav ebeen pulled from the device, and it still shows as unknown:

chris · August 21, 2016, 7:25am

This device isn’t in the database in the binding yet since we don’t have enough information - hence the note in the online database that I guess you are referring to when you say it is in the database -:

If you have the XML, then either upload it (if you have an account, or create one if not), or at least provide it here so I can load it. Once this is done we can finalise the database and get it into the binding.

chris2 · August 21, 2016, 4:51pm

Ah, thanks.

Is there any way to test the XML locally before adding to the database?

There’s probably going to be some trial and error to get a valid XML built, and I’d rather go through that locally rather than wasting anyone else time.

Thanks

chris · August 21, 2016, 5:37pm

The binding creates the XML automatically - it’s stored in the userdata/zwave folder.

chris2 · August 21, 2016, 11:26pm

There’s nothing in there for node5, I see node3 (a range extender) and node1 (the zstick), but nothing for node5? If I understand correctly, OH2 should have created the node5.xml automatically?

Thanks

chris2 · August 22, 2016, 1:58am

So the plot thickens, I looked in the zwave debug log and looks like node5 is not initializing correctly.

If I read this correctly, it seems to get stuck at this point, then start over:

18:36:34.351 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Incoming command class MULTI_INSTANCE
18:36:34.352 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 5: Received MULTI_INSTANCE command V2
18:36:34.352 [ERROR] [class.ZWaveMultiInstanceCommandClass] - NODE 5: Unsupported command class 0x01

I attached the log, would appreciate any pointers on anything I can do to resolve this.

Thanks

18:36:34.191 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Incoming command class MULTI_INSTANCE
18:36:34.191 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 5: Received MULTI_INSTANCE command V2
18:36:34.192 [ERROR] [class.ZWaveMultiInstanceCommandClass] - NODE 5: Unsupported command class 0x01
18:36:34.192 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=5, callback=84, payload=05 06 60 0D 01 01 85 05
18:36:34.193 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 07 60 06 01 01 85 06 01
18:36:34.193 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=84, expected=ApplicationCommandHandler, cancelled=false        transaction complete!
18:36:34.194 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
18:36:34.194 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
18:36:34.194 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - STATIC_VALUES: Transaction complete (SendData:Request) success(true)
18:36:34.195 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - checking initialisation queue. Queue size 2.
18:36:34.195 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - message removed from queue. Queue size 1.
18:36:34.196 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - STATIC_VALUES: queue length(1), free to send(true)
18:36:34.196 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Initialisation retry timer started 80000
18:36:34.196 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - queued packet. Queue length is 1
18:36:34.197 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
18:36:34.197 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Response processed after 145ms/379ms.
18:36:34.198 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
18:36:34.198 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 05 06 60 0D 01 02 85 05 25 55 7C
18:36:34.199 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0D 00 13 05 06 60 0D 01 02 85 05 25 55 7C
18:36:34.208 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
18:36:34.211 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
18:36:34.211 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
18:36:34.212 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
18:36:34.212 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
18:36:34.212 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
18:36:34.299 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 55 00 00 09 B7
18:36:34.302 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
18:36:34.302 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 55 00 00 09 00 00 B9
18:36:34.302 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 55 00 00 09 00 00 B9
18:36:34.303 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=55 00 00 09
18:36:34.303 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 85, Status = Transmission complete and ACK received(0)
18:36:34.303 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=5, callback=85, payload=05 06 60 0D 01 02 85 05
18:36:34.304 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=55 00 00 09
18:36:34.304 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=85, expected=ApplicationCommandHandler, cancelled=false      MISMATCH
18:36:34.348 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 05 07 60 06 02 01 85 06 01 13
18:36:34.349 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
18:36:34.350 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 05 07 60 06 02 01 85 06 01 13
18:36:34.350 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 05 07 60 06 02 01 85 06 01 13
18:36:34.351 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 07 60 06 02 01 85 06 01
18:36:34.351 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Application Command Request (ALIVE:STATIC_VALUES)
18:36:34.351 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 5: Incoming command class MULTI_INSTANCE
18:36:34.352 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 5: Received MULTI_INSTANCE command V2
18:36:34.352 [ERROR] [class.ZWaveMultiInstanceCommandClass] - NODE 5: Unsupported command class 0x01
18:36:34.352 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=5, callback=85, payload=05 06 60 0D 01 02 85 05
18:36:34.353 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 05 07 60 06 02 01 85 06 01
18:36:34.353 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=85, expected=ApplicationCommandHandler, cancelled=false        transaction complete!
18:36:34.353 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
18:36:34.353 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
18:36:34.354 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - STATIC_VALUES: Transaction complete (SendData:Request) success(true)
18:36:34.354 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - checking initialisation queue. Queue size 1.
18:36:34.354 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - message removed from queue. Queue size 0.
18:36:34.354 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - STATIC_VALUES: queue length(0), free to send(true)
18:36:34.354 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Initialisation retry timer started 80000
18:36:34.355 [ERROR] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: Retries exceeded at STATIC_VALUES
18:36:34.355 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Retry timout: Can't advance
18:36:34.355 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Response processed after 156ms/379ms.

chris · August 22, 2016, 8:13am

It looks like the device is responding with the MULTI_INSTANCE encapsulation command, but it looks like the MULTI_CHANNEL format .

The MULTI_INSTANCE version only has a single instance ID where MULTI_CHANNEL has both source and destination endpoints listed - in this response, it looks like the device has added both endpoints into the packet so the binding is trying to interpret the destination endpoint (1) as the command class.

This looks to me like a bug in the device and to support this we’ll have to add some sort of bodge to the binding to make it interpret the commands differently. The question is how to do this in a way that doesn’t break other things.

It’s also possible that this device is using a newer definition of the class, but this would mean that they’ve defined something in a non-backward compatible way which would be quite bad!

Can you please open an issue on this on the issue tracker, and also provide a full startup debug log with the issue.

chris2 · August 22, 2016, 6:31pm

Done, see issue #1200. Thx.

chris · August 22, 2016, 6:39pm

Thanks (although it should have been in the Z-Wave repo ). What node number is it - 5?

chris2 · August 22, 2016, 6:41pm

Sorry, & yes, node 5 is the CT101.

chris2 · August 22, 2016, 9:02pm

Issue moved to ZWave repo, https://github.com/openhab/org.openhab.binding.zwave/issues/new, #52. Thx,