node-zwave-js icon indicating copy to clipboard operation
node-zwave-js copied to clipboard

Timestamp of targetValue never updated, when device only reports currentValue

Open zargony opened this issue 1 year ago • 6 comments

Checklist

  • [X] I am not using Home Assistant. Or: a developer has told me to come here.
  • [X] I have checked the troubleshooting section and my problem is not described there.
  • [X] I have read the changelog and my problem is not mentioned there.

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

  • Set zwave-js-ui to named topics, time-value payload and ignore locations
  • Using an mqtt client, locate targetValue of a device with switch_multilevel command class, e.g. zwave/my_light/switch_multilevel/endpoint_1/targetValue
  • Set a new targetValue by publishing e.g. {"value":42} to the set topic zwave/my_light/switch_multilevel/endpoint_1/targetValue/set
  • Watch the new targetValue appear in zwave/my_light/switch_multilevel/endpoint_1/targetValue with a constant old timestamp: {"time":1684179981419,"value":42}

Expected behavior

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

Additional context

Maybe related settings in Settings -> Gateway:

  • Topic type: Named topics
  • Payload type: JSON Time-Value
  • Ignore Location: on

zargony avatar Jul 02 '24 10:07 zargony

@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

robertsLando avatar Jul 02 '24 13:07 robertsLando

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.

kpine avatar Jul 02 '24 15:07 kpine

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

robertsLando avatar Jul 02 '24 15:07 robertsLando

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).

AlCalzone avatar Jul 02 '24 16:07 AlCalzone

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

zargony avatar Jul 04 '24 09:07 zargony

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.

AlCalzone avatar Jul 04 '24 18:07 AlCalzone