zwave-js / node-zwave-js

Z-Wave driver written entirely in JavaScript/TypeScript
https://zwave-js.github.io/node-zwave-js/
MIT License
742 stars 593 forks source link

GE Switches and Dimmers do not reflect double-up or double-down because they use the BasicCC for those events #1277

Closed blhoward2 closed 3 years ago

blhoward2 commented 3 years ago

Describe the bug

GE dimmer/switches are capable of double tap events, but those are not captured here and result in the current value going out of sync with the device.

These are the steps to make it work under qt-openzwave: https://community.home-assistant.io/t/howto-add-double-tap-support-for-ge-switches-and-dimmers-in-ozw-beta/228871/16.

The original qt-openzwave issue which has more detailed info is at: OpenZWave/qt-openzwave#60.

This appears to result from this because the devices use BasicCC for these events despite supporting the Multi-Level Command Class: #388

Non-compliant or not, it is how they work... Is there a way to IgnoreMapping here like in ozw 1.6?

Note: If possible, these devices should also auto-associate the controller into group 3 so that it receives the double-tap events.

To Reproduce Steps to reproduce the behavior:

  1. Pair switches in zwavejs2mqtt.
  2. Double tap up or down

Device information Which device(s) is/are affected? Various GE switches and dimmers (confirmed on 14294, 14291) What are the node IDs?

Logfile:

Note: I have a script that resets the light to the default levels upon turning on. That accounts for the 50 --> 50 messages.

Double-tap up (from a prior double-tap up state, hence 255-->255):

Screen Shot 2021-01-02 at 10 13 38 PM

Double-tap up from off, just in case being in a former double-tap state affects it (note this one is out of order on the console log):

Screen Shot 2021-01-02 at 10 16 16 PM

(The current value goes to 255 and HA thinks the device is now at 100%, but the physical dim has not changed. They are now out of sync. The currentValue is 255, the target Value is 50.)

Double-tap down:

Screen Shot 2021-01-02 at 10 14 02 PM

For comparison, off to normal on:

Screen Shot 2021-01-02 at 10 15 11 PM

For comparison, on to normal off:

Screen Shot 2021-01-02 at 10 15 43 PM

Console log:

Screen Shot 2021-01-02 at 10 17 08 PM

AlCalzone commented 3 years ago

Thanks for the detailed logs but I don't quite follow what is the expected behavior here. Could you break down for each event what you expect to happen and what actually happens?

blhoward2 commented 3 years ago

When you double tap up the device should send a BasicCC with a value of 255, but the load isn’t altered. When you double tap down it sends a Basic CC with a value of 0, but the load isn’t altered. When you do that it sends commands via direct association to Group 3 or you can react through an automation to the basic set. This has worked this way with SmartThings and ozw 1.6. 1.4 worked similarly but it sent a zwave event instead of a Basic CC.

Right now, the 255 and 0 are treated as reports as it probably wasn’t proper for GE to use the BasicCC this way. Because the actual load doesn’t change not only can you not use double tap with an automation, if you do it through direct association the current value goes out of sync with the actual device. It says 255 but the device is at 50, 0, or some other level. Likewise, if you double tap down the current value goes to 0 but the device is actually still on.

In ozw 1.6 you can define to IgnoreMapping in the device file, which prevents it being treated like a report per the standard. This is discussed in the one link I posted and fishwaldo explains that these devices needed to be treated as not following the standard for this to work.

In ozw you can also set auto=“true” to have the controller automatically added to group 3 so it receives the events. This isn’t strictly required but makes it easier to setup for new users.

AlCalzone commented 3 years ago

Got it, thanks! If you want to chime in, you can edit the association configuration of these devices to make group 3 a lifeline: https://zwave-js.github.io/node-zwave-js/#/development/config-files?id=associations (or just figure out which device IDs are affected)

I'll add a compat flag to disable mapping.

blhoward2 commented 3 years ago

Thanks! Happy to test once you’re there.

AlCalzone commented 3 years ago

1278 adds a compat option for this. You can add (or edit) the compat property in those device files to contain:

"compat": {
  // other options (if any)
  "disableBasicMapping": true,
}
blhoward2 commented 3 years ago

You're fast! You don't off the top of your head know the build arg to build a zwavejs2mqtt docker image incorporating this commit for testing do you? I've never done it with a pending commit to a dependency.

AlCalzone commented 3 years ago

let me check if I find this somewhere

AlCalzone commented 3 years ago

https://github.com/zwave-js/zwavejs2mqtt/tree/master/docker#build Should be the ZWJ_BRANCH arg

blhoward2 commented 3 years ago

Which device file do I need to edit to add the compat flag?

./node_modules/@zwave-js/config/config/devices/0x0063/ge_14291_zw4005.json ./node_modules/zwave-js/node_modules/@zwave-js/config/config/devices/0x0063/ge_14291_zw4005.json

I added it to one and re-interveiwed everything but that didn't seem to do it. I'm trying the other one now. It should be at the same level as the other options?

// Jasco Products GE 14291 (ZW4005)
// In-Wall Paddle Switch
{
    "_approved": true,
    "manufacturer": "Jasco Products",
    "manufacturerId": "0x0063",
    "label": "GE 14291 (ZW4005)",
    "description": "In-Wall Paddle Switch",
    "devices": [
        {
            "productType": "0x4952",
            "productId": "0x3036"
        },
        {
            "productType": "0x4952",
            "productId": "0x3185"
        }
    ],
    "firmwareVersion": {
        "min": "0.0",
        "max": "255.255"
    },
    "supportsZWavePlus": true,
    "compat": {
        // other options (if any)
        "disableBasicMapping": true,
    },
    "paramInformation": {
 (Continued)
AlCalzone commented 3 years ago

That looks correct. New log please

blhoward2 commented 3 years ago

Is there a file that would reflect the node cache and whether the compat was recognized while setting up the devices? I had a json file in the store listing the nodes and the command classes. I wiped it thinking it would be like the ozwcache but it hasn't been recreated even after all of the devices are interviewed. I'm unsure if there is in an incompatibility between the state of the change to logging as well, but the zwave log file is no longer being populated even though it it is set to log to file. Weird.

This is what I built this morning: DOCKER_BUILDKIT=1 docker build --build-arg SRC=git-clone-src --build-arg Z2M_BRANCH=master --build-arg ZWJ_BRANCH=compat-disable-basic-mapping --no-cache -f zwavejs2mqtt/docker/Dockerfile.contrib -t zwavejs2mqtt .

I'll send you the console log file shortly.

blhoward2 commented 3 years ago

I see that you've merged it so I'm rebuilding with:

DOCKER_BUILDKIT=1 docker build --build-arg SRC=git-clone-src --build-arg Z2M_BRANCH=master --build-arg ZWJ_BRANCH=master --no-cache -f zwavejs2mqtt/docker/Dockerfile.contrib -t zwavejs2mqtt .

Once that is done I'll manually edit the device files and give it another try.

blhoward2 commented 3 years ago

Nope. As best as I can tell I turned on the compat flag though I'm unsure where to confirm that. In ozw I'd go look in the cache file. I can only access the console log as it isn't logging to file for some reason but it looks the same to me:

00:30:25.836 DRIVER « [Node 003] [REQ] [ApplicationCommand]

                      └─[BasicCCSet]

                          target value: 255

00:30:25.842 CNTRLR   [Node 003] treating BasicCC Set as a report

00:30:25.844 CNTRLR   [Node 003] [~] [Multilevel Switch] currentValue: 50 => 255        [Endpoint 0]

2021-01-04 00:30:25.847 INFO ZWAVE: Node 3: value updated: 38-0-currentValue 50 => 255

00:30:25.991 SERIAL « 0x01080004006702820115                                              (10 bytes)

00:30:25.994 DRIVER   Dropping message because it could not be deserialized: The command class Hail 

                      is not implemented

00:30:25.994 SERIAL » [ACK]                                                                   (0x06)
AlCalzone commented 3 years ago

There are cache files (store directory in zjs2mqtt) but the log seems like it didn't apply the option. Could you send me the cache files before wiping them?

blhoward2 commented 3 years ago

That's what is weird...I'm not seeing a cache file at all when I run this image (built off both masters) or the one this morning. Nor is the log file being updated despite the Log to File option under Zwave being turned on. The container is still running and has completed querying everything as far as I can tell.

Screen Shot 2021-01-03 at 7 48 19 PM

I'm also getting these errors periodically under this image:

01:00:27.853 CNTRLR   [Node 121] [~] [Meter] deltaTime[66817]: 0 => 0                   [Endpoint 0]

2021-01-04 01:00:27.857 ERROR GATEWAY: Error while discovering value 121-50-0-deltaTime-66817 of node 121: The config has not been loaded yet! The config has not been loaded yet!

ZWaveError: The config has not been loaded yet!

    at lookupMeter (/usr/src/app/node_modules/@zwave-js/config/src/Meters.ts:80:9)

    at Object.meterType (/usr/src/app/lib/Constants.js:21:19)

    at Gateway.discoverValue (/usr/src/app/lib/Gateway.js:1598:32)

    at Gateway.onValueChanged (/usr/src/app/lib/Gateway.js:234:10)

    at ZwaveClient.emit (events.js:314:20)

    at ZwaveClient.EventEmitter.emit (domain.js:483:12)

    at ZwaveClient.updateValue (/usr/src/app/lib/ZwaveClient.js:746:12)

    at ZwaveClient.onNodeValueUpdated (/usr/src/app/lib/ZwaveClient.js:395:15)

    at ZWaveNode.emit (events.js:314:20)

    at ZWaveNode.EventEmitter.emit (domain.js:483:12)

    at ZWaveNode.translateValueEvent (/usr/src/app/node_modules/zwave-js/src/lib/node/Node.ts:351:8)

    at ValueDB.emit (events.js:314:20)

    at ValueDB.EventEmitter.emit (domain.js:483:12)

    at ValueDB.setValue (/usr/src/app/node_modules/zwave-js/node_modules/@zwave-js/core/src/values/ValueDB.ts:224:10)

    at MeterCCReport.persistValues (/usr/src/app/node_modules/zwave-js/src/lib/commandclass/MeterCC.ts:602:12)

    at new MeterCCReport (/usr/src/app/node_modules/zwave-js/src/lib/commandclass/MeterCC.ts:534:8)

2021-01-04 01:00:27.859 INFO ZWAVE: Node 121: value updated: 50-0-deltaTime-66817 0 => 0

01:00:27.861 SERIAL » [ACK]                                                                   (0x06)

01:00:27.873 DRIVER « [Node 121] [REQ] [ApplicationCommand]

                      └─[MeterCCReport]

                          type:       Electric

                          scale:      A

                          rate type:  Consumed

                          value:      0.507

                          time delta: 0 seconds
AlCalzone commented 3 years ago

@robertsLando any idea?

blhoward2 commented 3 years ago

To be clear also, no changes to settings. And going back to the dev image brought back both cache files and the log.

robertsLando commented 3 years ago

@AlCalzone When discovering a value I read the config to get the meter type sensor type etc... that error is thrown by zwavejs so the question is if it's ok that the config file isn't loaded at that point, or should i catch that error?

blhoward2 commented 3 years ago

If you read up further, there is a bigger issue perhaps. I’m not seeing any cache files and the logger stops working if I build an image off both masters. I know there have been changes to the logger so that part may just be a mid-match in commits.

robertsLando commented 3 years ago

@blhoward2 The problem is that if you are using zwavejs master it has some breaking changes (introduced with version 6.0.0) that still needs to be sorted in zwavejs2mqtt

blhoward2 commented 3 years ago

Is there anyway to see how the node has been setup? I just need to verify if the compat flag added was acted upon so I can test this change. The log files look no different so either it isn’t being seen or the change isn’t have the desired effect.

robertsLando commented 3 years ago

@blhoward2 Please use this: https://github.com/zwave-js/zwavejs2mqtt/pull/84

The branch name is fix#23

AlCalzone commented 3 years ago

Is there anyway to see how the node has been setup?

Not without debugging - it should be on the private _deviceConfig property of the node instance.

blhoward2 commented 3 years ago

I’m happy to try that later if you can point me in the general direction. Otherwise I suppose we need to wait for the two branches to come back into parity. I’ve done so in python before but I’m a novice with node-js.

kpine commented 3 years ago

I also own these switches and use this functionality, so I'm interested in seeing this resolved.

Just to confirm, for all devices BasicCC Set commands are automatically mapped to some other value? Coming from OZW, only Reports are mapped by default. If the mapping is disabled, how is the command recognized? Is it treated as a value or some kind of event?

In OZW a Basic Set triggers a "node event" instead of a value change, so a state is never maintained. That approach allows these switches to be used like a fake Central Scene. For example, when I do a double tap (Basic Set 0xff) it triggers my automation software to set the load to 100% brightness. If I double tap off (Basic Set 0x0) it goes to 20% brightness. When restarting the automation software or the zwave-js application (e.g. zwavejs2mqtt) it will incorrectly trigger the automation unless it there is something that can distinguish it from being a cached value. It's also a problem if the application doesn't transmit updates when there's no change in value, even though that has meaning to the automation (double-tap on -> set level to 100%, change level to 5%, double-tap on -> set level to 100%).

blhoward2 commented 3 years ago

I also own these switches and use this functionality, so I'm interested in seeing this resolved.

Just to confirm, for all devices BasicCC Set commands are automatically mapped to some other value? Coming from OZW, only Reports are mapped by default. If the mapping is disabled, how is the command recognized? Is it treated as a value or some kind of event?

In OZW a Basic Set triggers a "node event" instead of a value change, so a state is never maintained. That approach allows these switches to be used like a fake Central Scene. For example, when I do a double tap (Basic Set 0xff) it triggers my automation software to set the load to 100% brightness. If I double tap off (Basic Set 0x0) it goes to 20% brightness. When restarting the automation software or the zwave-js application (e.g. zwavejs2mqtt) it will incorrectly trigger the automation unless it there is something that can distinguish it from being a cached value. It's also a problem if the application doesn't transmit updates when there's no change in value, even though that has meaning to the automation (double-tap on -> set level to 100%, change level to 5%, double-tap on -> set level to 100%).

This is sort of how it works. In ozw 1.4 it sends a node event. In ozw 1.6 it does not, it uses a report to update a mapped sensor value using the basic set. The first step is to get it working with the value unmapped. Then we can figure out the best way to represent the event.

kpine commented 3 years ago

This is sort of how it works. In ozw 1.4 it sends a node event. In ozw 1.6 it does not, it updates a mapped sensor value using the basic set.

Node Events are the default 1.6 behavior. To force a value requires setting compatibility flags in the device XML files. Not sure it's really relevant, except that the value behavior makes it difficult to handle double-tap events.

The first step is to get it working with the value unmapped. Then we can figure out the best way to represent the event.

OK, well I think that's what my question was, I guess it is not decided yet. I just wanted to point out that there are applications of this that would benefit by having a way to distinguish between values that were triggered "now". vs. being cached, if an "event" is not the right API. Ozwdaemon is lacking that distinction which is a pain to deal with.

blhoward2 commented 3 years ago

This is sort of how it works. In ozw 1.4 it sends a node event. In ozw 1.6 it does not, it updates a mapped sensor value using the basic set.

Node Events are the default 1.6 behavior. To force a value requires setting compatibility flags in the device XML files. Not sure it's really relevant, except that the value behavior makes it difficult to handle double-tap events.

You're right. I looked back and was misremembering. In any event, irrelevant as you say. Updating the sensor didn't make it difficult..you got a sensor to automate off of. And an MQTT topic which is what I used in Appdaemon.

kpine commented 3 years ago

In any event, irrelevant as you say. Updating the sensor didn't make it difficult..you got a sensor to automate off of. And an MQTT topic which is what I used in Appdaemon.

For my automations it's difficult because there is no way to distinguish between a cached value vs. a live value. HA does not provide the capability via the sensors, and ozwd does not via the MQTT messages. I don't want the automations to trigger when HA or the z-wave gateway restart, only when the switch is actually pressed, the cached state is not useful. I've handled this by comparing the timestamps of the message vs "now", but it's not reliable.

blhoward2 commented 3 years ago

@blhoward2 Please use this: zwave-js/zwavejs2mqtt#84

The branch name is fix#23

@robertsLando This branch would not start when built with the master branch of node-zwave-js. I left a comment in the PR for it with the error message.

robertsLando commented 3 years ago

@kpine In version 6 there are value notification and value updated events to distinguish them

robertsLando commented 3 years ago

@blhoward2 I think that's a build error of zwave-js, are you using docker or are you building it your own?

AlCalzone commented 3 years ago

Just to confirm, for all devices BasicCC Set commands are automatically mapped to some other value? Coming from OZW, only Reports are mapped by default. If the mapping is disabled, how is the command recognized? Is it treated as a value or some kind of event?

With the aforementioned config flag, the Basic CC is not hidden and you will see persistent values for it. So far it made no sense to distinguish between Set and Report, because they mean the same most of the time.

What you write above sounds to me more like we need a different flag that treats Basic CC as events, not states.

blhoward2 commented 3 years ago

@blhoward2 I think that's a build error of zwave-js, are you using docker or are you building it your own?

I used docker, using the command from the docker documentation you linked me to. I tried both the git-src one and downloading/checking out and the local-src one.

robertsLando commented 3 years ago

Are you using zwavejs master with zwavejs2mqtt master?

blhoward2 commented 3 years ago

Are you using zwavejs master with zwavejs2mqtt master?

For this I used the branch you indicated, plus the Zwavejs master. If you look at the screenshot in the PR where I said the build was uneventful the exact build command is at the top.

DOCKER_BUILDKIT=1 docker build --build-arg SRC=git-clone-src --build-arg Z2M_BRANCH=fix#23 --build-arg ZWJ_BRANCH=master --no-cache -f zwavejs2mqtt/docker/Dockerfile.contrib -t zwavejs2mqtt .

AlCalzone commented 3 years ago

Dockerfile needs an update ==> https://github.com/zwave-js/zwavejs2mqtt/pull/154

robertsLando commented 3 years ago

The problem is explained here

@larstobi The fix needed in DOcker contrib is explained there

robertsLando commented 3 years ago

@blhoward2 try now, fixed by https://github.com/zwave-js/zwavejs2mqtt/pull/154

blhoward2 commented 3 years ago

Logging is broken so I can't see the debug-level, but I think this is working. Double tap is now updating command class 32 instead of 38.

2021-01-06 00:07:54.343 INFO ZWAVE: Node 3: value added: 32-0-currentValue => 255
2021-01-06 00:07:54.655 INFO ZWAVE: Node 3: value added 3-32-0-currentValue => 255
2021-01-06 00:08:07.259 INFO ZWAVE: Node 3: value updated: 38-0-currentValue 50 => 50
2021-01-06 00:08:20.287 INFO SOCKET: User disconnected 9lBSkwUPlCn3boyrAAAB
2021-01-06 00:08:27.776 INFO ZWAVE: Node 3: value updated: 32-0-currentValue 255 => 255
2021-01-06 00:08:32.627 INFO ZWAVE: Node 3: value updated: 32-0-currentValue 255 => 0
2021-01-06 00:08:38.582 INFO ZWAVE: Node 3: value updated: 32-0-currentValue 0 => 255

I'll try my first PR later to add the compat flag to the device files and then close.

blhoward2 commented 3 years ago

I also own these switches and use this functionality, so I'm interested in seeing this resolved.

Just to confirm, for all devices BasicCC Set commands are automatically mapped to some other value? Coming from OZW, only Reports are mapped by default. If the mapping is disabled, how is the command recognized? Is it treated as a value or some kind of event?

In OZW a Basic Set triggers a "node event" instead of a value change, so a state is never maintained. That approach allows these switches to be used like a fake Central Scene. For example, when I do a double tap (Basic Set 0xff) it triggers my automation software to set the load to 100% brightness. If I double tap off (Basic Set 0x0) it goes to 20% brightness. When restarting the automation software or the zwave-js application (e.g. zwavejs2mqtt) it will incorrectly trigger the automation unless it there is something that can distinguish it from being a cached value. It's also a problem if the application doesn't transmit updates when there's no change in value, even though that has meaning to the automation (double-tap on -> set level to 100%, change level to 5%, double-tap on -> set level to 100%).

I haven't yet tested the reset part, but I did check and it does send the double-up or double-down to mqtt even when in that state already. 255-->255, etc. Even if it does I setup a binary sensor that is on for 10-15 seconds after startup and use that to block a variety of automations. That way my garage door doesn't go up when the mode switches to Home on startup, etc.

blhoward2 commented 3 years ago

Thanks all! I think the node-js-zwave level of implementing this is complete. Further discussion under zwavejsmqtt: https://github.com/zwave-js/zwavejs2mqtt/issues/116

kpine commented 3 years ago

@kpine In version 6 there are value notification and value updated events to distinguish them

Could we get Basic Set to be treated as a notification? This change fixes the Basic Set issue for GE switches, but they are still values instead of notifications.

blhoward2 commented 3 years ago

@kpine In version 6 there are value notification and value updated events to distinguish them

Could we get Basic Set to be treated as a notification? This change fixes the Basic Set issue for GE switches, but they are still values instead of notifications.

This may make sense. I know @jcam was looking at this for Central Scene last night. Does that break anything though where a switch actually needs basic set? Does that happen much anymore?

kpine commented 3 years ago

Does that break anything though where a switch actually needs basic set?

That's a valid question. My only perspective is coming from OZW, and pre-ozwd time, Basic Set was always an event, so in HA you'd use the zwave.node_event event. In OZW you have to jump through hoops to convert Set to Report (e.g. a value). However, I realize that's not necessarily the case here.

blhoward2 commented 3 years ago

Does that break anything though where a switch actually needs basic set?

That's a valid question. My only perspective is coming from OZW, and pre-ozwd time, Basic Set was always an event, so in HA you'd use the zwave.node_event event. In OZW you have to jump through hoops to convert Set to Report (e.g. a value). However, I realize that's not necessarily the case here.

I too have only ever dealt with it in this context. I believe under the standard it is the failsafe for if anything to be able to control it, though. @AlCalzone thoughts as to if this ever gets used to actually control the switch?

kpine commented 3 years ago

My follow question would be, if you are disabling the mapping it's for a good reason, would that be enough to assume notification instead of value. If not, could there be a setting as part of the flag that indicates which you prefer?

blhoward2 commented 3 years ago

Maybe it’s only used for basic control from other devices (e.g. direct association) and never the controller, so it would be ok? With respect to double taps it would probably be easier as it gets around HA not refreshing the value. I too recall it sending out zwave_events under ozw 1.4.

blhoward2 commented 3 years ago

Reopening so @AlCalzone can take a look

kpine commented 3 years ago

Maybe it’s only used for basic control from other devices (e.g. direct association) and never the controller, so it would be ok?

Typically Basic Set is for one device to control another, you can basically bypass the controller completely using associations. Almost all devices are required to respond to a basic set command in some way, for example a dimmer switch should allow for basic set to toggle or change the brightness. I doubt Jasco/GE has our use case in mind when they designed the switches this way. They probably just wanted to let you control other devices (with either single or double click) by direct association.

With respect to double taps it would probably be easier as it gets around HA not refreshing the value. I too recall it sending out zwave_events under ozw 1.4.

Well, that's my motivation in digging into this. 😁 The ozw 1.4 event method worked perfectly with no complications. The incomplete method adopted by ozwd made this difficult because of the persistent state. I'm worried about how HA will handle the values with zwave-js as well, if they aren't notifications.