Z-Wave Multi Channel (PE653)

🛎️ Get Help Devices
262

Thanks @chuck.schwer for working on adding the ManufacturerProprietary! It'll be very convenient to a lot of people working on more complex devices, I expect.

@keithriley thank you for the reply, and the detail! I'll email you privately about working on this.

I concur. Are these created by interrogating the hardware in any way? I ask because I have v3.3 of the firmware and I'm wondering if it's broken.

Acha, that'd be really too bad. . . . and could create a significant barrier to entry for people porting ST code. But if it's necessary, I am 100% committed to getting the PE653 running. Right now, I have to walk outside and turn on my hot tub by hand, like an animal.

1 Like
264

BTW, the problem is with this line around 1767:

def setCmd = zwave.multiInstanceV1.multiInstanceCmdEncap(instance: ch).encapsulate(zwave.basicV1.basicSet(value: $onOrOff))

it should be:

def setCmd = zwave.multiInstanceV1.multiInstanceCmdEncap(instance: ch).encapsulate(zwave.basicV1.basicSet(value: onOrOff))

^ no dollar sign

1 Like
267

In other news, I've started digging into this. Here's a trace of what happens when I click insertLogTrace (the bottom timestamp), followed by on2, with the HubAction classes:

dev:1302018-10-11 15:01:34.886:errorgroovy.lang.MissingMethodException: No signature of method: hubitat.device.HubAction.startsWith() is applicable for argument types: (java.lang.String) values: [delay] (on2)
dev:1302018-10-11 15:01:34.840:debug  - Events as sent: 
				0: 6006250102FF
				1: delay 1000
				2: 910005400102870301
				3: delay 1000
				4: 910005400101830101
dev:1302018-10-11 15:01:34.838:debug<<<<< rspFlg=false dly:1000/1000
			 Dev cmd: MultiInstanceCmdEncap(command:1, commandClass:37, instance:2, parameter:[255])  --> 6006250102FF, delay 1000
			<<<<< HubAction: 910005400102870301, delay 1000
			<<<<< HubAction: 910005400101830101
dev:1302018-10-11 15:01:34.836:trace  - 2: instanceof hubitat.device.HubAction
dev:1302018-10-11 15:01:34.832:trace  - 1: instanceof hubitat.device.HubAction
dev:1302018-10-11 15:01:34.829:trace  - 0: else: HubAction: MultiInstanceCmdEncap(command:1, commandClass:37, instance:2, parameter:[255]), format()=
dev:1302018-10-11 15:01:34.820:debug+++++ delayBetweenLog parm[3] dly=1000 responseFlg=false
dev:1302018-10-11 15:01:34.815:debug+++++ getRefreshCmds
dev:1302018-10-11 15:01:34.809:debug+++++ setChanState(2, 255)
dev:1302018-10-11 15:01:33.947:info----------------------- 15:01:33 -----------------------

I have a couple questions:

  • Is 6006250102FF the proper formatting for the 'on' event?
  • Why is the error referring to strings that are the action names, rather than the commands that are (I thought) sent?
268

The last value in parentheses is the name of the method where the exception came from: the on2 method. Please post your code, it appears you are still using HubActions somewhere.

269

Thanks!

They're referred to, but not generated anywhere:

(Note to anyone looking: The above code (obviously) is not working, so don't go trying to use it. . . . )

270

Line 1881 creates a HubAction

271

Ah. I'm not familiar with response. What's a better technique to employ here?

The input logged right there (I elided it from the above) is:

dev:1302018-10-11 15:04:25.463:trace  - 0: else: HubAction: MultiInstanceCmdEncap(command:1, commandClass:37, instance:2, parameter:[255]), format()=
dev:1302018-10-11 15:04:25.460:trace  - l -> MultiInstanceCmdEncap(command:1, commandClass:37, instance:2, parameter:[255])
272

the quick and dirty method is to add a toString() on the the end that will give you the string representation of it. Honestly though, I would get rid of that whole delayBetweenLog() method, use the built in delayBetween() method and convert all the zwave responses to strings instead of commands. ie:

this:

def off() {
	log("DEBUG", "+++++ off()")
    delayBetweenLog([
        zwave.basicV1.basicSet(value: 0x00),
        zwave.basicV1.basicGet()
    ])
}

becomes:

def off() {
    delayBetween([
        zwave.basicV1.basicSet(value: 0x00).format(),
        zwave.basicV1.basicGet().format()
    ], DELAY)
}
273

Killer, thanks you. I think the delayBetweenLog is there because there are proprietary commands that need inserted.... or to say it another way, how is it best to insert those 61005400.... commands, which are necessary?

Thanks again! The pieces are coming together.... maybe.

274

I can’t agree with Chuck this time. It’s throwing out the baby with the bath water. The delayBetween is a proven concept utilized in many drivers, but this implementation has numerous added features. For example the ability to provide consistent universal logging. Abstracts the different formatting for commands versus responses. Validated invalid items in the list, optimized the delay commands.

HE has implemented new code in the response list which has the good intention of optimizing unnecessary delay commands, but in the process they introduced a non-backward compatible requirement that all items in the list must be strings. This was not previously the case. They could easily make this type safe and avoid the exception. But alas, we can once again adopt the LCD approach and ensure HubActions are converted to strings in the response list prior to returning them.

The fix should be simple @joshua. Just need delayBetween to also convert the HubAction to a string. Note this code for regular commands:

if (responseFlg) {
            fmt = response(l)
        } else {
            fmt = l.format()
        }

This converts regular commands to strings. In the section a little higher it handles HubAction.

if (l instanceof hubitat.device.HubAction)

Just copy this code before the insert into the cmds list and insert fmt instead of l.

FYI, don’t let the debug output mislead you. Those lines that start with 91:
0: 6006250102FF
1: delay 1000
2: 910005400102870301
3: delay 1000
4: 910005400101830101
are not really strings, they are HubActions. It’s just that the HubAction in a log debug output renders itself as a string. The change I described will force them from an object to a string before inserting into the cmds list. This change will also be ST compatible (LCD).

If my suggestions are not specific enough let me know. Thanks for your help!

1 Like
276

Here's what I'm hearing:

  • delayBetween is a HE-provided method that will insert necessary delays between commands.

  • delayBetweenLog is a custom method that works in its place. It has a series of conditionals that selectively introduce only appropriate delays. It also logs information about the command set that results. It has special handling because the getRefreshCommands are proprietary, and sent as HubActions rather than the usual strings.

  • getRefreshCommands/addRefreshCommands encapsulates the proprietary magic commands that tell the PE653 to refresh the controls. It's added to any commands that will result in a state change that needs to be reflected, thus:

delayBetweenLog(addRefreshCmds(someActionThatGeneratesCommands()))

Right so far?

If so, I'm considering the following:

  • Create a executeCommands command that takes an optional refreshAfter argument. It will take the incoming command set as a list of Strings (resulting from format(), optionally append the refresh commands, log the result, and then call the stock delayBetween.

It could take HubActions, but I’m not seeing the benefit (yet). Instead I make the commands generated in setChanState get format()ted before they get returned, so strings are the lingua franca. This captures what @chuck.schwer suggested, while still drawing nice lines around the proprietary stuff @keithriley has so carefully dug up, but using the stock methods.

I did this.

private List refreshCommandStrings() { ["910005400102870301", "910005400101830101"] }
private List refreshCommandHubitatActions() { refreshCommandStrings().collect { new hubitat.device.HubAction(it) } }

private List executeCommands(commands, refreshControls = false) {
	log("DEBUG", 2, "+++++ executeCommands")
	logCommandList(commands)

	if (refreshControls) {
		commands += refreshCommandStrings()
	}

	log("DEBUG", 2, "----- executeCommands final set:")
	logCommandList(commands)
	delayBetween(commands)
}

This means that off2 now looks like:

def List off2() { executeCommands(setChanState(2, 0), true) }

This works, sort of! In that it generates a list of commands, including the refresh commands. A whole lot of things happen! Unfortunately, turning off is not one of them.

executeCommands correctly inserts the ‘refresh’ commands (the below, reading from the bottom, shows the original command set to turn off switch 2, and the final result, with the additional 'refresh' commands):


dev:1302018-10-11 21:06:50.492: debug - Events as sent:
         0: 600625010200
         1: 910005400102870301
         2: 910005400101830101
dev:1302018-10-11 21:06:50.490: debug ----- executeCommands final set:
dev:1302018-10-11 21:06:50.488: debug - Events as sent:
         0: 600625010200

And then a whole ton of events get sent back into the DTH, meaning the controller actually did something!

However, note how the code decides “event UNNECESSARY” - the state is already set correctly. But, it’s not. The response in the 84 command from the device is that the switch is still on. But the command transmitted was to turn it off.

…
dev:1302018-10-11 21:06:50.969: debug <<<<< Event unnecessary. name:switch2 evt: "on" ==> dev:(on)
dev:1302018-10-11 21:06:50.966: trace - 1: Map: [name:switch2, value:on, isStateChange:true, displayed:true, descriptionText:(switch2 set to on)]
dev:1302018-10-11 21:06:50.965: trace - l -> [name:switch2, value:on, isStateChange:true, displayed:true, descriptionText:(switch2 set to on)]
dev:1302018-10-11 21:06:50.964: debug <<<<< Event unnecessary. name:switch1 evt: "off" ==> dev:(off)
dev:1302018-10-11 21:06:50.959: trace - 0: Map: [name:switch1, value:off, isStateChange:true, displayed:true, descriptionText:(switch1 set to off)]
dev:1302018-10-11 21:06:50.958: trace - l -> [name:switch1, value:off, isStateChange:true, displayed:true, descriptionText:(switch1 set to off)]
dev:1302018-10-11 21:06:50.951: debug +++++ delayBetweenLog parm[9] dly=1000 responseFlg=true
…
dev:1302018-10-11 21:06:50.832: debug ..... createMultipleEvents( endpoint:2, name:switch2, externalParm:255, myParm:on)
dev:1302018-10-11 21:06:50.831: debug <<<<< Child Event unnecessary. name:07-ep1:switch1 evt: "off" ==> dev (off)
dev:1302018-10-11 21:06:50.800: debug ..... createMultipleEvents( endpoint:1, name:switch1, externalParm:0, myParm:off)
dev:1302018-10-11 21:06:50.793: debug ManufacturerProprietary event, [1]:40 [4]:84 payload: 05 40 02 02 84 00 00 00 02 00 00 01 5B 00 00 14 38 00 00 00 00 03 03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
dev:1302018-10-11 21:06:50.786: trace <<< Incoming: [zw device: 07, command: 9100, payload: 05 40 02 02 84 00 00 00 02 00 00 01 5B 00 00 14 38 00 00 00 00 03 03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ]

Here we see createMultipleEvents reporting that the externalParm of switch2 is on, despite 'off' having just been sent.
I interpret this as the 84 command reporting that switch 2 is on (which is correct, the pump is running; payload[SWITCHES_84] & 2 is 1) - which is unfortunate, because I told it to turn off.
From here unsurprisingly nothing else happens.

I think I interpret this as 600625010200 not being the correct code to turn off switch2.

# off
setChanState(5, 0)				0: 600625010500
setChanState(4, 0)				0: 600625010400
setChanState(3, 0)				0: 600625010300
setChanState(2, 0)				0: 600625010200
setChanState(1, 0)				0: 600625010100

# on
setChanState(5, 255)			0: 6006250105FF
setChanState(4, 255)			0: 6006250104FF
setChanState(3, 255)			0: 6006250103FF
setChanState(2, 255)			0: 6006250102FF
setChanState(1, 255)			0: 6006250101FF

These are refreshingly consistent and therefore plausible. But they don't make anything happen.

So now I find myself wondering - is v3.3 of the firmware my problem? Because this feels like solid communication, which falls apart when it hits the device.

Just to be thorough, here's what setChanState looks like:

private List setChanState(ch, on) {
	log("DEBUG", 2, "+++++ setChanState($ch, $on)")
	def cmds =[
		zwave.multiInstanceV1.multiInstanceCmdEncap(instance: ch).encapsulate(zwave.switchBinaryV1.switchBinarySet(switchValue: (on ? 0xFF : 0))).format() ,
	]
}

Oh! And, when I manually switch the device off, I get an 84 command reporting that switch2 is now off.:

dev:1302018-10-11 21:47:18.069:debug  - Events as sent: 
		0: [name:switch2, value:off, isStateChange:true, displayed:true, descriptionText:(switch2 set to off)]
		1: [name:airTempFreeze, value:0, unit:F, displayed:true, isStateChange:true]
		2: [name:airTempSolar, value:0, unit:F, displayed:true, isStateChange:true]
		3: [name:clock, value:21:37, displayed:false, descriptionText:PE653 Clock: 21:37]

So the issue really appears to be the command that's being sent to the device.

277

That method is also provided by Smartthings:

https://docs.smartthings.com/en/latest/device-type-developers-guide/building-z-wave-device-handlers.html#sending-commands

278

@joshua, The advantage of not converting them to strings prior to calling the common function is that the logging in the common function can display the far more meaningful command class name and parameter list. Once you convert to strings all you have left is the very terse command strings. Under normal circumstances these are not useful in debugging. It is far more preferable to have these remain readable. That said, it is also sometimes useful to see the actual generated strings, and that is a good segway to what I believe is the fundamental problem here...

This is a sample of the log display in ST when I turn off switch 2:
<<<<< Dev cmd: MultiInstanceCmdEncap(parameter: [0], command: 1, instance: 2, commandClass: 37) --> 600602250100, delay 1000
<<<<< HubAction: 910005400102870301, delay 1000
<<<<< HubAction: 910005400101830101

Notice that each command shows its name and parameters as well as the generated string. The key command here is the MultiInstanceCmdEncap. What you may quickly notice is that the string is not the same as what we are now seeing on HE. The MultiInstanceCmdEncap command class is "6006" and the next byte must be the "channel" (2 in this case), this is then followed by a simple command (switchBinarySet in this case) which is "2501" followed by the switchBinarySet parameter to turn off 0x00 (versus on: 0xFF).

Your logs show that HE is inserting the channel in the wrong place:
600625010200

zwave.multiInstanceV1.multiInstanceCmdEncap(instance:ch).encapsulate(zwave.switchBinaryV1.switchBinarySet(switchValue: (on ? 0xFF : 0))).format() ,

This had been reported as working correct before the latest release by @JDogg016 and others. Seems like something got broken...

Tagging @chuck.schwer and @mike.maxwell

@joshua, Your conclusions about the events are spot on and you correctly questioned if the generated string was correct. Don't give up on PE653 v3.3 just yet. Let see what the HE guys say, but you could prove this to yourself easily by temporarily hacking in the correct string into setChanState and see if your equipment responds.

One last thing. I have no objection to utilizing a built in delayBetween function if it exists on both platforms, but if it is HE only then we are back to the same compatibility issue, and I'd rather just leave the code as is.

Best of luck!

279

@joshua, Separately, I finally got a couple minutes to try a simple fix for the HubAction String issue and it really looks like a simple one line patch. In delayBetweenLog find this section and change the highlighted line to render the HubAction as a String (I tried .format() and it is not a supported method, at least on ST):

if (l instanceof physicalgraph.device.HubAction) {
        if (cmds) {
			def c = cmds.last()			//check if there is already a delay prior to this
            if (!(c instanceof String || c instanceof GString) || c.take(6) != "delay ") {
                cmds << "delay $dly"
	            devStr = devStr.concat(", delay $dly")
            }
        }
        cmds << "${l}"
        devStr = devStr.concat("\n<<<<< HubAction: $l")

Change cmds << l to cmds << "${l}"

281

Thanks, we'll take a look at it.

282

Fantastic! Thanks, @chuck.schwer!

283

Yes, in 1.1.5 we aren't dealing with this command properly, we were in 1.1.4, and we will again in 1.1.6!

284

Thanks, @mike.maxwell. I've noticed there isn't much of a culture of test-driven development w/ Groovy, or at least not an obvious one. I was thinking of driving this DTH with Spock. Do y'all use a testing framework? What do you think of Spock, or do you have any other suggestions?

285

Am I allowed to be the guy that asks when? This was devastating as HE is the only way I can control my pool. No pool pump running for about 20 days now.

1 Like
286

1.1.6 is targeted for next week, I can't say exactly when next week.

1 Like