ZWave Dev Binding Unknown command class while processing Multi Channel Capability Report Command

I’ve been seeing the the following in my ZWave logs for Fibaro single/dual relays (eg FGS-212, FGS-221 etc):

18-Apr-2018 20:36:26.802 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 04 11 06 60 0A 02 10 01 25 B8 
18-Apr-2018 20:36:26.803 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 17: resetResendCount initComplete=true isDead=false
18-Apr-2018 20:36:26.803 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_MULTI_CHANNEL, endpoint 0
18-Apr-2018 20:36:26.803 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY not supported
18-Apr-2018 20:36:26.803 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_MULTI_CHANNEL V2 MULTI_CHANNEL_CAPABILITY_REPORT
18-Apr-2018 20:36:26.803 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Process Multi-channel capability Report
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoints are the same device class = true
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoint Id = 1
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoints is dynamic = false
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Basic = BASIC_TYPE_ROUTING_SLAVE 0x4
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Generic = GENERIC_TYPE_SWITCH_BINARY 0x10
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Specific = SPECIFIC_TYPE_POWER_SWITCH_BINARY 0x1
18-Apr-2018 20:36:26.804 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_BASIC, endpoint 1 created
18-Apr-2018 20:36:26.804 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Unknown command class 0x1
18-Apr-2018 20:36:26.804 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_SWITCH_BINARY
18-Apr-2018 20:36:26.804 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 created
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoint 1: Adding command class COMMAND_CLASS_SWITCH_BINARY.
18-Apr-2018 20:36:26.804 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Version = 1, version set. Enabling extra functionality.
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoint Id = 2
18-Apr-2018 20:36:26.804 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoints is dynamic = false
18-Apr-2018 20:36:26.805 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Basic = BASIC_TYPE_ROUTING_SLAVE 0x4
18-Apr-2018 20:36:26.805 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Generic = GENERIC_TYPE_SWITCH_BINARY 0x10
18-Apr-2018 20:36:26.805 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Specific = SPECIFIC_TYPE_POWER_SWITCH_BINARY 0x1
18-Apr-2018 20:36:26.805 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_BASIC, endpoint 2 created
18-Apr-2018 20:36:26.805 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Unknown command class 0x1
18-Apr-2018 20:36:26.805 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_SWITCH_BINARY
18-Apr-2018 20:36:26.805 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_SWITCH_BINARY, endpoint 2 created
18-Apr-2018 20:36:26.805 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoint 2: Adding command class COMMAND_CLASS_SWITCH_BINARY.
18-Apr-2018 20:36:26.805 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 17: Version = 1, version set. Enabling extra functionality.
18-Apr-2018 20:36:26.805 [ERROR] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoint 3 not found. Cannot set command classes.

I’ve had a look through the code and I think there is an off by 1 error when reading the “Command Class 1” from the “Multi Channel Capability Report Command”.

In ZWaveMultiInstanceCommandClass::handleMultiChannelCapabilityReport() the follow variables are read from the incoming message:

        int receivedEndpointId = payload.getPayloadByte(2) & 0x7F;
        boolean dynamic = ((payload.getPayloadByte(2) & 0x80) != 0);
        int genericDeviceClass = payload.getPayloadByte(3);
        int specificDeviceClass = payload.getPayloadByte(4);

The offset of 4 when reading specificDeviceClass, which I believe to be 0x01 (SPECIFIC_TYPE_POWER_SWITCH_BINARY) from the logging.

Further onZWaveMultiInstanceCommandClass::addSupportedCommandClasses() is called, which does:

        for (int i = 0; i < payload.getPayloadLength() - 4; i++) {
            // Get the command class ID
            int data = payload.getPayloadByte(4 + i);
            ...

I suspect that the - 4 and 4 + i should be 5 as the offset into the message to read the first Command Class. The other side effect of this may be reading too many Command Classes from the incoming message.

I am not sure whether this then cascades into the final error in the log, but to me it looks like the cause of the debugging message of “Unknown command class 0x1”.

Thanks,
Steve.

Thanks for the report - please can you provide a log that is not filtered on the node number and I’ll have a look.

Thanks.

Actually - don’t worry - I now see you added the receive message at the top…

Yes - you are right. I’ll update this - it will make the error go away, but it’s not causing any problem other than the annoying error log.

Thanks for the report.

In a similar theme is the final error in the log caused by the for loop in the same method:

        int startId = endpointsAreTheSameDeviceClass ? 1 : receivedEndpointId;
        int endId = endpointsAreTheSameDeviceClass ? getNode().getEndpointCount() : receivedEndpointId;

        boolean supportsBasicCommandClass = getNode().supportsCommandClass(CommandClass.COMMAND_CLASS_BASIC);

        for (int endpointId = startId; endpointId <= endId; endpointId++) {
        ...

I can see in the XML file for the node <endpointId>0</endpointId>, <endpointId>1</endpointId> and <endpointId>2</endpointId>, which I assume means 3 endpoints (0, 1, 2)?

I don’t know enough about the ZWave protocol to know whether the loop should be over endpoints 0, 1, 2 or 1, 2 or something else.

Thanks,
Steve.

I don’t know without seeing more information. Endpoint 0 is perfectly valid, but you normally won’t see endpoint 0 used in a multi-channel request (it may even not be allowed - I forget now).

If you can supply a full debug log I’ll take a better look.

Sorry, It seems I forgot the to mention that I am assuming the for loop is running over endpoints 1…3, which is then causing the error log message:

18-Apr-2018 20:36:26.805 [ERROR] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 17: Endpoint 3 not found. Cannot set command classes.

as the last entry in the log. i.e. I assume from the log that endpointsAreTheSameDeviceClass is true and getNode().getEndpointCount() is returning 3.

How much of a log do you need? - that was snipped from a log getting on for 1GB in size now…

This should be correct. As above, you shouldn’t normally see endpoint 0 used in a multi-channel command (I think it’s allowed in some new versions of the command though under specific conditions).

A startup log would be good - reset the log (ie delete it), then restart the binding and send the log once the device is initialised. It hopefully isn’t bigger than 10MB or so…

I believe that this is now fixed by recent changes to the dev binding in PR #878 and PR #883 from Chris.

Many thanks,
Steve.