Fibaro Switch 2: Unsupported multi instance command version (SOLVED)

I have two fibaro switch 2 devices. Node4 works fine while the other Node40 refuses to work.

it fails with the “Unsupported multi instance command version”.

  • I have deleted the thing again and readded it.
  • I have cleared the cache.
  • I have healed the network and the thing.

Nothing helped.

I found a lot of threads with that error but after several hours of trying to track down the root cause, I am looking for help.

Here is the definition of the items:

Switch F2_KidRoom1_Light1_F2R "Hauptlicht"      {channel="zwave:device:16117d1edc0:node4:switch_binary1" }
   
Switch F2_Office_Desk_Light   "Schreibtisch AZ" {channel="zwave:device:16117d1edc0:node40:switch_binary1"}

This is the log of Node 4

2018-06-24 18:30:08.369 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Command received zwave:device:16117d1edc0:node4:switch_binary1 --> ON
2018-06-24 18:30:08.382 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 4: Creating new message for application command SWITCH_BINARY_SET
2018-06-24 18:30:08.399 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Encapsulating message, instance / endpoint 1
2018-06-24 18:30:08.404 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2018-06-24 18:30:08.410 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-06-24 18:30:08.410 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
2018-06-24 18:30:08.416 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 04 07 60 0D 01 01 25 01 FF 25 1D 6F
2018-06-24 18:30:08.422 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 0E 00 13 04 07 60 0D 01 01 25 01 FF 25 1D 6F
2018-06-24 18:30:08.442 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-06-24 18:30:08.451 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-24 18:30:08.454 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-06-24 18:30:08.456 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-06-24 18:30:08.460 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-06-24 18:30:08.462 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: Sent Data successfully placed on stack.
2018-06-24 18:30:08.480 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 1D 00 00 05 F3
2018-06-24 18:30:08.482 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-24 18:30:08.485 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 1D 00 00 05 00 00 FD
2018-06-24 18:30:08.487 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 1D 00 00 05 00 00 FD
2018-06-24 18:30:08.489 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=1D 00 00 05
2018-06-24 18:30:08.492 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 29, Status = Transmission complete and ACK received(0)
2018-06-24 18:30:08.494 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Starting initialisation from DONE
2018-06-24 18:30:08.496 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@19aef4a already registered
2018-06-24 18:30:08.499 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=4, callback=29, payload=04 07 60 0D 01 01 25 01 FF
2018-06-24 18:30:08.501 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=1D 00 00 05
2018-06-24 18:30:08.503 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=29, expected=SendData, cancelled=false        transaction complete!
2018-06-24 18:30:08.506 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-06-24 18:30:08.507 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-06-24 18:30:08.510 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 4: Response processed after 80ms/4749ms.

This the log of Node 40

2018-06-24 19:36:21.753 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 40: Command received zwave:device:16117d1edc0:node40:switch_binary --> ON
2018-06-24 19:36:21.758 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 40: Creating new message for application command SWITCH_BINARY_SET
2018-06-24 19:36:21.765 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-06-24 19:36:21.770 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 28 03 25 01 FF 25 D1 E2
2018-06-24 19:36:21.775 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 40: Sending REQUEST Message = 01 0A 00 13 28 03 25 01 FF 25 D1 E2
2018-06-24 19:36:21.777 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
2018-06-24 19:36:21.787 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 40: Command received zwave:device:16117d1edc0:node40:switch_binary1 --> ON
2018-06-24 19:36:21.794 [WARN ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 40: Unsupported multi instance command version: 0.
2018-06-24 19:36:21.793 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-06-24 19:36:21.797 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 40: No messages returned from converter
2018-06-24 19:36:21.805 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-24 19:36:21.809 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 D1 00 00 02 38
2018-06-24 19:36:21.813 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-06-24 19:36:21.820 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-06-24 19:36:21.825 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-06-24 19:36:21.828 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 40: Sent Data successfully placed on stack.
2018-06-24 19:36:21.831 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-24 19:36:21.835 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 D1 00 00 02 00 00 36
2018-06-24 19:36:21.837 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 D1 00 00 02 00 00 36
2018-06-24 19:36:21.839 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=D1 00 00 02
2018-06-24 19:36:21.841 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 40: SendData Request. CallBack ID = 209, Status = Transmission complete and ACK received(0)
2018-06-24 19:36:21.843 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 40: Starting initialisation from DONE
2018-06-24 19:36:21.844 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@962516 already registered
2018-06-24 19:36:21.847 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=40, callback=209, payload=28 03 25 01 FF
2018-06-24 19:36:21.849 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=D1 00 00 02
2018-06-24 19:36:21.851 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=209, expected=SendData, cancelled=false        transaction complete!
2018-06-24 19:36:21.853 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-06-24 19:36:21.855 [DEBUG] [curityCommandClassWithInitialization] - NODE 40: updating lastSentMessageTimestamp
2018-06-24 19:36:21.857 [DEBUG] [curityCommandClassWithInitialization] - NODE 40: updating lastSentMessageTimestamp
2018-06-24 19:36:21.859 [DEBUG] [curityCommandClassWithInitialization] - NODE 40: updating lastSentMessageTimestamp
2018-06-24 19:36:21.861 [DEBUG] [curityCommandClassWithInitialization] - NODE 40: updating lastSentMessageTimestamp
2018-06-24 19:36:21.862 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 40: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-06-24 19:36:21.865 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 40: Response processed after 83ms/4749ms.

I compared the whole configuration of both line by line (from the json db). The only thing that is different is the setting of the lifeline group.

Node4: set to Openhab Controller

“group_1”: [
“node_1_0”
],

Node40: is not set (no entry in the config)

I am not sure whether this the cause. Though I tried to set Number 2’s group to the openhab-controller via Habmin or Paper but when saving it, it throws an exception in the background

2018-06-24 18:55:48.770 [ERROR] [st.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at 'things/zwave:device:16117d1edc0:node40/config'
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.handleConfigurationUpdate(ZWaveThingHandler.java:623) [231:org.openhab.binding.zwave:2.4.0.201806152142]

so, I cannot do that setup.

I have uploaded the logfile here: https://we.tl/yiLtHrLDrp (how can I attached a log file to that thread as the .log extension is not allowed?)

So, basically the question is what it means, when it says “Unsupported multi instance command version”. Looking in the source code didn’t give me more insight on that topic.

I hope someone has an idea how to solve that problem.

thanks in advance
Stefan

PS: I am using version 1.4

What OH version do you run? (“1.4” ???)
Did you try to run the development zwave binding version ?

Thanks Markus,

I am using

231 │ Active │ 80 │ 2.4.0.201806152142 │ ZWave Binding

I thought that this should be current “enough”. Should I move to an even newer version?

@chris Is there a newer version I should try? The link at the top of the thread links to 2.3.0. Can you point to a newer version of 2.4.x I should try?

and still, though, I’d loved to understand what the “unsupported multi instance…” thing actually means.

I just wanted to add that after some research I found one understable explanation what multi channel or multi instance means. I would recommend reading this here:

5.3.4 Multi Channels versus Multi Instances at http://www.z-wave.info/book-z-wave-basics/buch-z-wave-grundlagen-kapitel-5/

This actually could hint at the fact that I indeed have to set channel 0 to the openhab-controller (which I can’t because it fails with an exception).

Question: Could I just edit the json-database? Or, I remember, that I once saw that there are configs for the z-wave adapter somewhere on disk that define all discovered things but I can’t find it anymore.

@chris Can you point me to the right direction?

cheers
Stefan

Better delete the thing and re-create it by (eventually ex-) and reincluding
Well you can edit jsondb if all else fails but you shouldn’t (if you do, shutdown OH meanwhile, take file backups and be very careful). It’s /var/lib/openhab2/jsondb/org.eclipse.smarthome.core.thing.Thing.json.
It’s likely a lot safer and might work without shutting down OH to edit discovery results file instead of jsondb, then to acknowledge discovered things in UI after editing. The file to contain discovery results is org.eclipse.smarthome.config.discovery.DiscoveryResult.json.

I’m not really sure where in the process this is happening? This could be normal if the binding hasn’t downloaded the data from the device yet - the binding finds out about the supported command classes early in the process, but only finds the version later in the process. It shouldn’t stay at version 0, but without seeing an initialisation log, I can’t really comment too much on this.

Can you supply this?

No - this won’t work. The binding doesn’t go through and update the configuration if you change it outside of the UI as this would require a LOT of additional traffic on startup that would swamp the network.

@chris , the device has been fully initialized. What you see in the log above is happening when a click on an item (basicui or paper ui) is done by me. I uploaded the log file to https://we.tl/yiLtHrLDrp

If the update on the json db does not work, do you know why there is an exception when I try to change the association in User Interface?

an additional question is: I am using zwave “2.4.0.201806152142”. I only upgraded to 2.4 because my whole system was broken and it was the only way to get it running again. Is that zwave version recommended by you or should I move to a different one.

btw, I am seeing quite a few messages with “security” like

2018-06-26 19:02:35.817 [DEBUG] [curityCommandClassWithInitialization] - NODE 40: Received SECURITY command V0
2018-06-26 19:02:35.824 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 40: Received SECURITY_NONCE_GET
2018-06-26 19:02:35.830 [ERROR] [ve.internal.protocol.ZWaveController] - Exception during ZWave thread: Input 2. {}
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.sendNonceReport(ZWaveSecurityCommandClass.java:432) [231:org.openhab.binding.zwave
your code goes here

Does that tell you anything?

TIA
Stefan

Moving from the 2.4 version to the newer(!) 2.3-snapshot development version solved the problems (thanks to @sihui explaining that 2.3-snapshot is newer than the version in OH 2.4).
The errors have gone away and the things that used to work, work again now as expected. I was also able to add the new fibaro double switches to my network.

1 Like

Please note that this is ONLY true for the development binding that is manually downloaded from the development thread.

Do you refer to the link at the very beginning of this thread Zwave-Refactoring ?

Yes.