How to monitor the intermediate states during a command for value change ?

nouknouk commented 7 years ago

Hi,

first, thanks for this usefull library.

I'd like to send zwave commands and associate JS promises, being resolved/rejected according to the real feedback provided by the zwave network. When testing, I set a value (the 'Level' value of a Fibaro FGD212), i get lot's of logs displayed by the zwave driver ; here is a summary (full logs are available at the end of this post):

1- queuing the command, 2- sending it, 3- ensure it is delivered to Z-Wave stack, 4- a callback ID (here 0xc2) 5- a confirmation that the expected callbackId was received 6- finally, a message with the new value

For all those summarized steps, I have no feedback on Javascript side, only for the last one (number 6), using an event ''value changed'

I wonder to be able to get more intermediate notifications (for steps 1 to 5, but especially during step 5, which looks the best step to resolve/reject my 'changeValue' promise).

Is there a way to get them ?

Thanks in advance.

full logs:

2017-04-19 21:52:12.410 Info, Node036, Value::Set - COMMAND_CLASS_SWITCH_MULTILEVEL - Level - 0 - 1 - 
2017-04-19 21:52:12.410 Info, Node036, SwitchMultilevel::Set - Setting to level 25
2017-04-19 21:52:12.410 Info, Node036,   Duration: Default
2017-04-19 21:52:12.410 Detail, Node036, Queuing (Send) MultiChannel Encapsulated (instance=1): SwitchMultilevelCmd_Set (Node=36): 0x01, 0x0f, 0x00, 0x13, 0x24, 0x08, 0x60, 0x0d, 0x01, 0x01,
 0x26, 0x01, 0x19, 0xff, 0x25, 0xc1, 0x87
2017-04-19 21:52:12.411 Detail, Node036, Queuing (Send) MultiChannel Encapsulated (instance=1): SwitchMultilevelCmd_Get (Node=36): 0x01, 0x0d, 0x00, 0x13, 0x24, 0x06, 0x60, 0x0d, 0x01, 0x01,
 0x26, 0x02, 0x25, 0xc2, 0x6d
2017-04-19 21:52:12.411 Detail, 
2017-04-19 21:52:12.411 Info, Node036, Sending (Send) message (Callback ID=0xc1, Expected Reply=0x13) - MultiChannel Encapsulated (instance=1): SwitchMultilevelCmd_Set (Node=36): 0x01, 0x0f,
 0x00, 0x13, 0x24, 0x08, 0x60, 0x0d, 0x01, 0x01, 0x26, 0x01, 0x19, 0xff, 0x25, 0xc1, 0x87

2017-04-19 21:52:12.419 Detail, Node036,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-04-19 21:52:12.419 Detail, Node036,   ZW_SEND_DATA delivered to Z-Wave stack
2017-04-19 21:52:12.437 Detail, Node036,   Received: 0x01, 0x07, 0x00, 0x13, 0xc1, 0x00, 0x00, 0x02, 0x28
2017-04-19 21:52:12.437 Detail, Node036,   ZW_SEND_DATA Request with callback ID 0xc1 received (expected 0xc1)
2017-04-19 21:52:12.437 Info, Node036, Request RTT 26 Average Request RTT 25                                                                                                         [13/1997]
2017-04-19 21:52:12.438 Detail,   Expected callbackId was received
2017-04-19 21:52:12.438 Detail,   Expected reply was received
2017-04-19 21:52:12.438 Detail,   Message transaction complete
2017-04-19 21:52:12.438 Detail, 
2017-04-19 21:52:12.438 Detail, Node036, Removing current message
2017-04-19 21:52:12.438 Detail, 
2017-04-19 21:52:12.438 Info, Node036, Sending (Send) message (Callback ID=0xc2, Expected Reply=0x04) - MultiChannel Encapsulated (instance=1): SwitchMultilevelCmd_Get (Node=36): 0x01, 0x0d,
 0x00, 0x13, 0x24, 0x06, 0x60, 0x0d, 0x01, 0x01, 0x26, 0x02, 0x25, 0xc2, 0x6d
2017-04-19 21:52:12.447 Detail, Node036,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-04-19 21:52:12.447 Detail, Node036,   ZW_SEND_DATA delivered to Z-Wave stack
2017-04-19 21:52:12.464 Detail, Node036,   Received: 0x01, 0x07, 0x00, 0x13, 0xc2, 0x00, 0x00, 0x02, 0x2b
2017-04-19 21:52:12.464 Detail, Node036,   ZW_SEND_DATA Request with callback ID 0xc2 received (expected 0xc2)
2017-04-19 21:52:12.464 Info, Node036, Request RTT 25 Average Request RTT 25
2017-04-19 21:52:12.464 Detail,   Expected callbackId was received
2017-04-19 21:52:12.475 Detail, Node036,   Received: 0x01, 0x0d, 0x00, 0x04, 0x00, 0x24, 0x07, 0x60, 0x0d, 0x01, 0x01, 0x26, 0x03, 0x19, 0x84
2017-04-19 21:52:12.475 Detail, 
2017-04-19 21:52:12.476 Info, Node036, Response RTT 36 Average Response RTT 36
2017-04-19 21:52:12.476 Info, Node036, Received a MultiChannelEncap from node 36, endpoint 1 for Command Class COMMAND_CLASS_SWITCH_MULTILEVEL
2017-04-19 21:52:12.476 Info, Node036, Received SwitchMultiLevel report: level=25
2017-04-19 21:52:12.476 Detail, Node036, Refreshed Value: old value=0, new value=25, type=byte
2017-04-19 21:52:12.476 Detail, Node036, Changes to this value are not verified
2017-04-19 21:52:12.476 Detail, Node036,   Expected reply and command class was received
2017-04-19 21:52:12.476 Detail, Node036,   Message transaction complete
2017-04-19 21:52:12.477 Detail, 
2017-04-19 21:52:12.477 Detail, Node036, Removing current message
2017-04-19 21:52:12.477 Detail, Node036, Notification: ValueChanged

nouknouk commented 7 years ago

It seems we can get some information by enabling the OZW configuration option "NotifyTransactions":

ozw = new OpenZwaveDriver({ConsoleOutput: true, NotifyTransactions: true}

In such case, we get some feedback via the 'notification' event:

ozw.on("notification", function (nodeid, notif) { 
   // for NotifyTransactions callbacks, 
   // notif === 0 (aka. "message complete")
});

I tried with my Fibaro light dimmer ; after requesting a change of the 'level' value, I get two notifications:

one with nodeid = 0 (aka. the zwave controller itself) ; it seems related to the fact that the zwave message has been sent by the hardware.
one with nodeid = 36 (aka. the Fibaro dimmer) ; seems related to the reception of the value change; according to logs, it seems related to a second message automatically sent by OZW library to Fibaro Dimmer, in parallel to my 'setValue' action ; the second message is a 'get value').

Notes:

other attempts with other zwave values (like 'bright'/'dim'/'inc'/'dec' zwave buttons declared in the Fibaro Dimmer) don't make any action on my light, and in such case I receive only the notification for node 0.
no such notification received when the light is put on/off manually using the 'normal' wall switch (in such case, only a 'value update' notification is received.

==> it seems there is no way in the API to bind a call to an OZW action (like 'setValue') to a transactionID and get this ID back in the notification when the action is finished, to make the link. This seems not possible even in the openzwave library itself.

==> That smells like a hell to be able to reliabily trace the (asynchronous) results of the commands trigerred, especially in case multiple commands are sent in parallel to the same node.

Any thought about that ?

Thanks in advance.

ekarak commented 7 years ago

This is a known issue about OpenZWave and there's no easy way around it. Some ZWave devices don't even bother to report a manual status change, and you need to enable polling on them. If you're updating UI values then you're better off subscribing to value change events.

I believe the protocol per se does not allow passing user data within a request, so the only way you can correlate a request and the status change is by some sort of FSM. I've done some work recently using the machina.js library and I think I can hack together a small demo in the following days.

nouknouk commented 7 years ago

thanks for your answer.

Just some questions/remarks:

zwave being a reliable protocol, i suppose the controller should receive at least a 'techical acknowledgment' frame from the device, to state that the request frame has been well delivered (and so, no re-sending is needed). Even if this is not as complete as a 'ack message' that the action itself has been well performed (typically a value change), this could be a first info, no?
unless i'm mistaken, the "transaction id" i see in the logs is present in one of the bytes that are 'sent' (again, according to the logs). no?

Le 28 avril 2017 7:08:35 PM Elias Karakoulakis notifications@github.com a écrit :

This is a known issue about OpenZWave and there's no easy way around it. Some ZWave devices don't even bother to report a manual status change, and you need to enable polling on them. If you're updating UI values then you're better off subscribing to value change events.

I believe the protocol per se does not allow passing user data within a request, so the only way you can correlate a request and the status change is by some sort of FSM. I've done some work recently using the machina.js library and I think I can hack together a small demo in the following days.

-- You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub: https://github.com/OpenZWave/node-openzwave-shared/issues/163#issuecomment-298053910

reneklootwijk commented 5 years ago

@ekarak Did you ever manage to hack together a state machine to match received notifications to issued commands? I would very interested.

nouknouk commented 5 years ago

FYI, I raised the question in openzwave google group:

https://groups.google.com/forum/#!topic/openzwave/QSNaRe8JHLc

OpenZWave / node-openzwave-shared

How to monitor the intermediate states during a command for value change ? #163