zwave-js / node-zwave-js

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

Timestamp of targetValue never updated, when device only reports currentValue #6978

Open zargony opened 3 months ago

zargony commented 3 months ago

Checklist

Deploy method

Docker

Z-Wave JS UI version

9.14.4.40080a1

ZwaveJS version

12.12.1

Describe the bug

When setting a switch_multilevel targetValue (via MQTT or via web ui), the updated value is published in MQTT but it's timestamp is always set to 1684179981419 (which is 2023-05-15T19:46:21.419Z).

zwave-js-ui log (unrelated lines about http requests and power level reporting stripped):

2024-07-02 11:15:31.497 INFO MQTT: Message received on zwave/licht_esszimmer/switch_multilevel/endpoint_1/targetValue/set: '42'
2024-07-02 11:15:31.501 INFO Z-WAVE: Writing 42 to 12-38-1-targetValue
2024-07-02 11:15:31.564 DEBUG MQTT: Publishing to zwave/licht_esszimmer/lastActive: { time: 1719911731562, value: 1719911688110 } with options { qos: 1, retain: true }
2024-07-02 11:15:31.577 INFO Z-WAVE: [Node 012] Value updated: 38-1-targetValue 0 => 42
2024-07-02 11:15:31.575 DEBUG MQTT: Publishing to zwave/licht_esszimmer/switch_multilevel/endpoint_1/targetValue: { time: 1684179981419, value: 42 } with options { qos: 1, retain: true }
2024-07-02 11:15:31.586 DEBUG MQTT: Publishing to zwave/licht_esszimmer/switch_multilevel/endpoint_1/currentValue: { time: 1719911731583, value: 42 } with options { qos: 1, retain: true }
2024-07-02 11:15:31.589 INFO Z-WAVE: [Node 012] Value updated: 38-1-currentValue 0 => 42
2024-07-02 11:15:31.810 DEBUG MQTT: Publishing to zwave/licht_esszimmer/switch_multilevel/endpoint_1/currentValue: { time: 1719911731807, value: 42 } with options { qos: 1, retain: true }
2024-07-02 11:15:31.812 INFO Z-WAVE: [Node 012] Value updated: 38-1-currentValue 42 => 42
2024-07-02 11:15:31.821 DEBUG MQTT: Publishing to zwave/licht_esszimmer/lastActive: { time: 1719911731819, value: 1719911731804 } with options { qos: 1, retain: true }

This seems to happen with all my switch_multilevel devices (Fibaro Dimmer 2 FGD-212 as well as Fibaro Roller Shutter 2 FGRM-222). Setting a switch_binary however works as expected.

To Reproduce

Expected behavior

The time field is expected to show a recent time when value is changed

Additional context

Maybe related settings in Settings -> Gateway:

robertsLando commented 3 months ago

@zargony this is the intended behaviour, target value is write only, it's only published on startup in order to create it on MQTT side, you should check for currentValue timestamp instead

kpine commented 3 months ago

target value is write only

Devices can report target value along with current value, so it probably should not be read-only. The value itself is read-write.

robertsLando commented 3 months ago

Devices can report target value along with current value

Yeah to say it in a better way, I update it only when I receive an event from the driver that tells me that value is updated, also I use valueId.lastUpdate in the JSON time prop: https://github.com/zwave-js/zwave-js-ui/blob/40080a17ee730611bd3c89e04e10ad82bac60eec/api/lib/Gateway.ts#L1975

This means that for some reason driver is not udpating that property. I think the reason is that the device isn't reporting back the targetValue but only the currentValue change, this could be easily spotted using zniffer

cc @AlCalzone

AlCalzone commented 3 months ago

Please make a driver log of an interaction that causes this, loglevel debug and attach it here as a file (drag & drop into the text field).

zargony commented 3 months ago

I somehow missed that there's separate settings for ui and driver logging, sorry.

Here are ui and driver debug logs of the same action as described above

z-ui_2024-07-04.log zwavejs_2024-07-04.log

AlCalzone commented 3 months ago

I think what happens is that node-zwave-js doesn't set the timestamp when the value is changed through a user interaction, and your device only reports current value, not target value, so the timestamp for targetValue is never updated. I'll have to think about if this is working as intended or a bug.