Problems commanding color of EzMultiPli

[Aaron23 (Aaron)]

Hi Chris. Thanks for your response.

With logging set with “log:set DEBUG org.openhab.binding.zwave”, I capture a log portion where the command Backyard_Gate_Color_Indicator.sendCommand(“360,100,100”) was issued.

Looks like that starts around timestamp 2018-06-20 06:28:17.048

2018-06-20 06:28:16.977 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0A 00 13 05 03 25 01 FF 25 2C 32 
2018-06-20 06:28:16.986 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2018-06-20 06:28:16.988 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-20 06:28:17.002 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2C 00 00 02 C5 
2018-06-20 06:28:16.991 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
2018-06-20 06:28:17.008 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
2018-06-20 06:28:17.010 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2018-06-20 06:28:17.011 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: Sent Data successfully placed on stack.
2018-06-20 06:28:17.012 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-20 06:28:17.013 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 2C 00 00 02 00 00 CB 
2018-06-20 06:28:17.013 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 2C 00 00 02 00 00 CB 
2018-06-20 06:28:17.014 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=2C 00 00 02 
2018-06-20 06:28:17.015 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 44, Status = Transmission complete and ACK received(0)
2018-06-20 06:28:17.015 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from DONE
2018-06-20 06:28:17.016 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@36444c4b already registered
2018-06-20 06:28:17.017 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=5, callback=44, payload=05 03 25 01 FF 
2018-06-20 06:28:17.018 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=2C 00 00 02 
2018-06-20 06:28:17.019 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=44, expected=SendData, cancelled=false        transaction complete!
2018-06-20 06:28:17.019 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-06-20 06:28:17.020 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-06-20 06:28:17.021 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Response processed after 43ms/4146ms.
2018-06-20 06:28:17.048 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Command received zwave:device:07c3b712:node12:color_color --> 360,100,100
2018-06-20 06:28:17.052 [DEBUG] [ternal.converter.ZWaveColorConverter] - NODE 12: Converted command '360,100,100' to value 100 0 0 for channel = zwave:device:07c3b712:node12:color_color, endpoint = 0.
2018-06-20 06:28:17.054 [DEBUG] [.commandclass.ZWaveColorCommandClass] - NODE Node 12. Manufacturer 001E, Type 0004, Id 0001: Color refresh is already in progress
2018-06-20 06:28:17.055 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-06-20 06:28:17.056 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-06-20 06:28:17.056 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 14 00 13 0C 0D 33 05 05 02 64 03 00 04 00 00 00 01 00 25 2D A2 
2018-06-20 06:28:17.057 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 14 00 13 0C 0D 33 05 05 02 64 03 00 04 00 00 00 01 00 25 2D A2 
2018-06-20 06:28:17.067 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2018-06-20 06:28:17.068 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-20 06:28:17.069 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
2018-06-20 06:28:17.070 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
2018-06-20 06:28:17.071 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2018-06-20 06:28:17.075 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
2018-06-20 06:28:17.084 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2D 00 00 02 C4 
2018-06-20 06:28:17.085 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-20 06:28:17.086 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 2D 00 00 02 00 00 CA 
2018-06-20 06:28:17.087 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 2D 00 00 02 00 00 CA 
2018-06-20 06:28:17.087 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=2D 00 00 02 
2018-06-20 06:28:17.088 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 45, Status = Transmission complete and ACK received(0)
2018-06-20 06:28:17.089 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Starting initialisation from DONE
2018-06-20 06:28:17.091 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@1d48b06a already registered
2018-06-20 06:28:17.094 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=12, callback=45, payload=0C 0D 33 05 05 02 64 03 00 04 00 00 00 01 00 
2018-06-20 06:28:17.098 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=2D 00 00 02 
2018-06-20 06:28:17.100 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=45, expected=SendData, cancelled=false        transaction complete!
2018-06-20 06:28:17.101 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-06-20 06:28:17.102 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-06-20 06:28:17.103 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Response processed after 45ms/4146ms.
2018-06-20 06:28:24.162 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Polling...
2018-06-20 06:28:24.164 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Polling zwave:device:07c3b712:node7:switch_binary
2018-06-20 06:28:24.166 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 7: Generating poll message for SWITCH_BINARY, endpoint 0
2018-06-20 06:28:24.168 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 7: Creating new message for application command SWITCH_BINARY_GET
2018-06-20 06:28:24.170 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Polling zwave:device:07c3b712:node7:sensor_binary
2018-06-20 06:28:24.173 [DEBUG] [converter.ZWaveBinarySensorConverter] - NODE 7: Generating poll message for SENSOR_BINARY, endpoint 0
2018-06-20 06:28:24.175 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 7: Creating new message for application command SENSOR_BINARY_GET
2018-06-20 06:28:24.177 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Polling zwave:device:07c3b712:node7:sensor_general
2018-06-20 06:28:24.178 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 7: Generating poll message for SENSOR_MULTILEVEL, endpoint 0
2018-06-20 06:28:24.180 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 7: Creating new message for command SENSOR_MULTI_LEVEL_GET
2018-06-20 06:28:24.182 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Polling zwave:device:07c3b712:node7:alarm_general
2018-06-20 06:28:24.183 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 7: Generating poll message for ALARM, endpoint 0, alarm null, event null
2018-06-20 06:28:24.184 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 7: Creating new message for application command NOTIFICATION_GET V1
2018-06-20 06:28:24.185 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-06-20 06:28:24.185 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-06-20 06:28:24.186 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-06-20 06:28:24.186 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 07 02 25 02 25 2E CC 
2018-06-20 06:28:24.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
2018-06-20 06:28:24.188 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 7: Sending REQUEST Message = 01 09 00 13 07 02 25 02 25 2E CC 
2018-06-20 06:28:24.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 3. Queue={}
2018-06-20 06:28:24.197 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2018-06-20 06:28:24.198 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-20 06:28:24.199 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
2018-06-20 06:28:24.199 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
2018-06-20 06:28:24.201 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2018-06-20 06:28:24.202 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 7: Sent Data successfully placed on stack.
2018-06-20 06:28:24.214 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2E 00 00 02 C7 
2018-06-20 06:28:24.215 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-06-20 06:28:24.216 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 2E 00 00 02 00 00 C9 
2018-06-20 06:28:24.216 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 2E 00 00 02 00 00 C9

[chris (Chris Jackson)]

This appears to be (mostly) ok I think -:

This shows the device acked the request, so I assume should have changed colour.

This shows that the value was set to red. I think the values are meant to be 0-255, so this probably should be 255 and not 100, but in any case red is correct for this HSB value -:

Maybe this device only works if the value is fully on and therefore the (roughly) half value of 100 instead of 255 means it doesn’t work?

[Aaron23 (Aaron)]

Chris,

You have a good point. The user manual is a bit ambiguous in this area. There is no dimming, so each of the three RGB LEDs are either on or off. It says the valud values are: 00 or FF; 00=OFF, 01-FF=ON.

I also wonder if it just doesn’t like that it’s being sent 5 color values instead of just 3, even though it probably should just ignore the ones it doesn’t know.

Are there debugging tools I could use to send commands where I can control the data sent? Then, I could test the above theories.

[chris (Chris Jackson)]

It says the valud values are: 00 or FF; 00=OFF, 01-FF=ON.

I will look to update the binding to fix the value it sends in the next few days. To me at the moment this is the most likely problem.

I also wonder if it just doesn’t like that it’s being sent 5 color values instead of just 3, even though it probably should just ignore the ones it doesn’t know.

It should ignore the other colors - the standard allows sending of these colors so it should just ignore channels it doesn’t have.

Are there debugging tools I could use to send commands where I can control the data sent?

Not that I’m aware of at least.

[5iver (Scott Rushworth)]

Are there debugging tools I could use to send commands where I can control the data sent?

You could use Zensys Tools for this. There are a few posts about it in the forum, but none that I recall about this specific functionality. I have used it in the past to do this though, so I know it would work.

Zensys zwave tool & zwave issues

OK, then I think I know how to proceed; I simply reinitialize one of the bad nodes, and log until it is woken up, then check to see what they say about neighbours. Looking in the log, all of the three controllers has responded “NODE xx: No neighbors reported”. The two smoke detectors I’m not sure about, will wait a couple of hours to make sure they have actually woken.

[chris (Chris Jackson)]

There’s a development version available here. Note that this is the dev version so needs to be installed as per the following link -:

OH2 Z-Wave refactoring and testing... and SECURITY

The latest version of the development binding dated 19th June 2018 is here. Toward the end of last year I spent some time doing some initial refactoring of the ZWave binding in OH2. This focussed on rewriting the way transactions work as this is an enabler for other areas of the code. At the same time I also restructured the different layers of the binding to make things cleaner, and done some changes to support a system of autocoding the command classes directly from the Z-Wave standard which…

[Aaron23 (Aaron)]

I will look to update the binding to fix the value it sends in the next few days. To me at the moment this is the most likely problem.

Thank you for the quick response!

Using Zensys to debug shows that the EzMultiPli doesn’t seem to care as long as the value is non-zero. I was able to send simple one-color commands and get it to work fine with 0x64 or 0xFF.

Three color commands work as expected too. This command results in a pure red color:

It should ignore the other colors - the standard allows sending of these colors so it should just ignore channels it doesn’t have.

Makes sense, but when I send the same 5 color command data as the one in the debug log I posted earlier, I get the same result (very brief red flash, then off)

But here’s what I think may be going on … I also learned that it does seem to respond to the cool white (01) color capability. When that’s set to on/1, it turns the LED on to white. So, perhaps what it’s doing is treating the cool white as a command to turn on/off all LEDs. So when it sees cool white set to off/0 it turns all LEDs off. If that’s true and it’s processing the command byte-by-byte as it’s received, then it would turn the red LED on then immediately off - which matches what I saw.

[Aaron23 (Aaron)]

You could use Zensys Tools for this.

Thank you for the pointer! See above post for details.

[chris (Chris Jackson)]

perhaps what it’s doing is treating the cool white as a command to turn on/off all LEDs.

It seems like a reasonable assumption. I think I can safely refactor the code to do this differently without changing the way it works for other devices, so I’ll take a look at this tonight.

[Aaron23 (Aaron)]

It seems like a reasonable assumption. I think I can safely refactor the code to do this differently without changing the way it works for other devices, so I’ll take a look at this tonight.

I took a look at the code involved here. To keep it clean, I’m wondering if a new colorMode is in order? Looking at the things database, it seems to me that many of the color output devices that use colorMode=RGB are actually RGBW devices (4 independent channels). Should you create a new color mode “RGBW” for them? Then RGB devices would be used for devices without a truely independent white channel (like EzMultiPli).

Then, ZWaveColorConverter::receiveCommand could handle RGB and RGBW separately, using a new overloaded of ZWaveColorCommandClass::setColor which would only take R, G, B colors and create a shorter message without the white channels for RGB only devices.

The reason the level comes out to 100 instead of 255 is that HSBType’s RGB accessors are giving back a percent scaled value which receiveCommand uses directly. It seem that’s a bug that should be fixed in ZWaveColorConverter::receiveCommand.

If you agree and could point me to build instructions, I could try it out.

[chris (Chris Jackson)]

To keep it clean, I’m wondering if a new colorMode is in order?

I don’t think that’s necessary. I plan to simply refactor the way the colors are sent and I think this ought to sort it out.

[Aaron23 (Aaron)]

I don’t think that’s necessary. I plan to simply refactor the way the colors are sent and I think this ought to sort it out.

Obviously you know this code base and design philosophy vastly better than I do so I’ll curiously await what you have in mind

My thinking was as follows:

1. I assume there is a good reason for existing devices to be able to take R,G,B,CW colors simultaneously and that you don’t want to affect the translation for these devices at all. But maybe that’s wrong? Edit: I now see that the code doesn’t ever simultaneously use non-0 values in the RGB and CW fields anyway.
2. Based on what I think I found about how EzMultiPli treats Cold White, there is no way to get a color (not all white or all off) if you send the cold white level (no matter what its value is)

I could not think of a way to achieve both 1 and 2 by looking at colors alone, so I figured a channel type differentiation would be required.

[Aaron23 (Aaron)]

Based on what I think I found about how EzMultiPli treats Cold White, there is no way to get a color (not all white or all off) if you send the cold white level (no matter what its value is)

Thinking about it a little further, this part might not be totally true. If my theory is correct (sequential command byte processing), then reversing the order of the CW and the RGB components would fix the issue with the EzMultiPli. Though I’m not sure if that would be OK for the other devices.

[chris (Chris Jackson)]

I assume there is a good reason for existing devices to be able to take R,G,B,CW colors simultaneously

Not really - it’s just the way that I wrote the code 3 or 4 years ago.

there is no way to get a color (not all white or all off) if you send the cold white level (no matter what its value is)

I’m not sure I understand your point. If we only send RGB in RGB mode, and only send CW / WW in white mode, then this shouldn’t be an issue.

Maybe we might also need another RGBW mode at some point, but at the moment I don’t see that it’s needed and I prefer not to add extra modes that then require changes in the database etc if we can avoid it.

[Aaron23 (Aaron)]

I’m not sure I understand your point. If we only send RGB in RGB mode, and only send CW / WW in white mode, then this shouldn’t be an issue.

Maybe we might also need another RGBW mode at some point, but at the moment I don’t see that it’s needed and I prefer not to add extra modes that then require changes in the database etc if we can avoid it.

This makes more sense to me now. I forgot about the possibility of using the other white modes to make RGB, CW and WW separate commands.

[jjennings308 (James Jennings)]

Aaron - Do you every get it working?

[chris (Chris Jackson)]

I believe that this was resolved a few months ago and should be in the latest binding.

[Aaron23 (Aaron)]

Yes, Chris resolved this issue and I’m using EzMultiPli today. I have not advanced to the latest binding yet, but I assume it would work there too.

[jjennings308 (James Jennings)]

Aaron - could you please post an example of what you are doing? I can currently get the white light on but when I try color I am getting the color to flash on and then it goes off.

[chris (Chris Jackson)]

What version of the binding are you using? I would recommend to use the latest if you aren’t already (eg 2.4 M4).