[velux addon] incorrect position in binding with Somfy devices for custom position

darkfuncat commented 4 years ago

Expected Behavior

With Somfy devices, there is a feature to register a special position for each actuator ('my' position). For exemple the sunny position, or rainy, etc. When the actuator is set in this position with the remote, the binding should refresh the current real position as any other position.

Current Behavior

Currently the velux binding does not refresh the current position (when actuator set on this custom position) but instead failed and log an error (INFO level) Exemple : [INFO ] [.internal.handler.VeluxBridgeHandler] - handleCommandScheduled(velux:rollershutter:home:klf200_bureau:position,REFRESH): updating of item velux:rollershutter:home:klf200_bureau:position (type velux:rollershutter/position) failed.

Possible Solution

With log investigation in DEBUG/TRACE level, we can see that the KLF200 core API send this result for GW_GET_NODE_INFORMATION_CFM command : [TRACE] [internal.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate(): received packet C0 00 7F 02 10 07 00 07 00 62 75 72 65 61 75 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 80 00 00 00 00 00 00 00 00 00 00 00 00 00 05 F7 FF 50 00 F7 FF F7 FF F7 FF F7 FF 00 00 4F 06 ED F3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 F2 C0.

Depending of the API documentation, we see that :

"CurrentPosition" set as F7 FF ("No feed-back value known") instead of a % value in hex
"Target" set as "50 00", the real current position of the actuator (which is the 'MY' position for this somfy device exemple)
"state" set as "05", the "done" status

Possible fix/workaround would be :

check wether Somfy devices
if state == 5 (done), then we send the "target" field which is correct instead of the "currentPosition" field, which is buggy

Steps to Reproduce (for Bugs)

Record a custom/'my' position on somfy actuator
Set the actuator on this position (with any method)
Wait for binding to refresh the position

Context

Somfy devices with Velux addon

Your Environment

Any version of openhab or velux addon. Linux for hosting.

andrewfg commented 4 years ago

I have a feeling in my stomach that the recent improvements I made to the binding -- as described here -- might fix your issue.

=> Could you please kindly check it for me?

andrewfg commented 4 years ago

PS reason for my stomach feeling, is that in earlier versions of the binding, some delayed position change notifications “GW_XYZ_NTF” were not being received resp. processed. Whereas in my latest version these notifications should also get handled..

darkfuncat commented 4 years ago

Hi @andrewfg , Sounds good, thanks,, where can I find your new addon to test ? (I dont have OH3, still in 2.5.9 stable release ...)

andrewfg commented 4 years ago

In my first post there is a link to the jar file on github.

darkfuncat commented 4 years ago

I just installed your jar (snapshot 29/10/2020@20h30) and tested it. It works very nice event without restarting OH ! But unfortunately, this bug (8320) still remains unresolved. What do you think about my hack proposal ? I think it is safe for everyone as there are solid conditions before action (if somfy, if state done, if currentPos outOfBound ...) I can test quickly if needed ... just tell me =)

andrewfg commented 4 years ago

Hi @darkfuncat thankyou for the feedback.

Yes you are probably right about the need for a "hack". Let me finalise the other changes that I am making first, and then I will get back to you in a few days..

andrewfg commented 3 years ago

Hi @darkfuncat just a quick question: You posted a trace log for a GW_GET_NODE_INFORMATION_CFM message. But those messages are not actually relevant for updating the Item's state in the OpenHAB User Interface. The GW_GET_NODE_INFORMATION_NTF and GW_NODE_STATE_POSITION_CHANGED_NTF are the actual messages that count for updating the UI. So I wonder if you can please post some trace logs for those messages for your Somfy device?

darkfuncat commented 3 years ago

Hi @andrewfg Here are some logs. (i completly edit this post because previously was confusing)

pos_bureau_A.txt Position of roller shutter in room "bureau", at 20% (hexa code is 28 00) currentPos is OK, and target also
pos_bureau_B.txt Position of roller shutter in room "bureau", at 9% position recorded as 'MY' (hexa code is 12 00) currentPos is ERROR, but target is OK
pos_bureau_C.txt Position of roller shutter in room "bureau" 3 minutes later, still at 9% position recorded as 'MY' currentPos is ERROR, and target is ERROR also (F7 FF) These logs are not mandatory for hack, but shows another state (i thinks i push again the button 'my').

Hope this helps ...

pos_bureau_A.txt pos_bureau_B.txt pos_bureau_C.txt

darkfuncat commented 3 years ago

It is not easy for me to extract and separate logs as I dont know what is actualy relevant. Tell me if you want more.

andrewfg commented 3 years ago

Hi @darkfuncat many thanks for the logs; I am digesting them..

darkfuncat commented 3 years ago

After some tests, you can forget "pos_bureau_C" situation, I am not able to reproduce the case where "target" is false. Or this is a very rare situation (perhaps when i change the 'my' recorded position) The focus is on A and B situation.

andrewfg commented 3 years ago

Hi @darkfuncat I made a new build of the binding jar file HERE which perhaps fixes your issue; could you kindly give it a try?

darkfuncat commented 3 years ago

I have just replace the jar with your new one and it restarted automatically succesfully. I made some quick tests with few rollershutter on 'my' :

no more warning/error/info log ! this is great
position is set to "UNDEF"

Here are some logs in debug level (not have time to set to trace, i will do it later). This is promising ! Thanks !

newbindDBG.log

darkfuncat commented 3 years ago

My bad, it works flawlessly now ! I made some other tests and all is OK. I figure that i didnt't wait for the 1 min timeout to have the status checked by the addon. (i made some tests too quickly i think) And my first test was with a multi roller remote, perhaps a hint for my futur tests... I will stay you inform.ed

darkfuncat commented 3 years ago

Hi @andrewfg I noticed these WARN logs today : 2020-11-16 18:23:22.655 [WARN ] [e.slip.io.DataInputStreamWithTimeout] - pollRunner() => slip message queue overflow => PLEASE REPORT !! 2020-11-16 18:23:22.693 [WARN ] [e.slip.io.DataInputStreamWithTimeout] - pollRunner() => slip message queue overflow => PLEASE REPORT !! 2020-11-16 18:23:22.731 [WARN ] [e.slip.io.DataInputStreamWithTimeout] - pollRunner() => slip message queue overflow => PLEASE REPORT !! 2020-11-16 18:23:22.769 [WARN ] [e.slip.io.DataInputStreamWithTimeout] - pollRunner() => slip message queue overflow => PLEASE REPORT !! So I am reporting =) Another question, did you commit this hack in the others snapshot i see on the forum ?

darkfuncat commented 3 years ago

After some new tests, I have found an issue. When I use my remote on a single shutter to 'my' position, all is fine, your fix is correct. When I use a multi remote on multiple shutter to 'my' position, all this shutter goes directly to 'UNDEF' in openhab with no position. I suspect in this case the target field is not set because of multiple commands at the same time ? I will try to grab some debug/trace logs. But I think that it will be great in case of 'out of field 0xF7FF' return code to not send a new UNDEF position, but keep the last position. (or not update position at all, not sending UNDEF) What do you think ?

andrewfg commented 3 years ago

So I am reporting =)

Thank you. How many actuators do you have in your system? And what is your refreshInterval?

did you commit this hack in the others snapshot i see on the forum ?

Yes.

I will try to grab some debug/trace logs.

Many thanks.

in case of 'out of field 0xF7FF' return code to not send a new UNDEF position, but keep the last position

I’m not sure about this. Surely if there is an error, it is better to know about it?

darkfuncat commented 3 years ago

I have 30 scenes and 13 actuators. refreshInterval is default (not defined), timeoutMsecs=2000, retries=10, isSequentialEnforced="false", isProtocolTraceEnabled="false" In this case of out of range 0xF7FF it is not really an error, it is more a position that the KLF200 does not resolve correctly due to lack of API I think. The usage of rollershutter is completly normal with the remote (just the KLF API is 'buggy' or missing a feature).

andrewfg commented 3 years ago

I have 30 scenes and 13 actuators.

Ok. I estimate that would mean about 100 messages maximum in 10 seconds. So I have increased the queue size to 500.

In this case of out of range 0xF7FF it is not really an error

You are right that it is not an error. The API specification says that 0xf7ff means 'No feed-back value known'; -- which means 'undefined' in other words. So what is wrong about telling the truth?

darkfuncat commented 3 years ago

Hi @andrewfg OK thanks for the update, if you provide me the last snapshot i will test the jar. For the second point, the fact is that the API should NOT return 0xF7FF in this case (because the shutter did not move at all since the last update, it is just a bug from the API/KLF). So Openhah received a good position, and after get an UNDEF for the same position. As I dont know how to ignore the UNDEF new position (I want to keep the old one which is correct in OH) I think that the plugin should not send UNDEF in this case, but keep the old position or not return anything at all. I am not very clear I understand =)

TLTR : the position of the shutter in OH is OK, but may change to UNDEF without any understandable reason and I dont know how to prevent this (ignore the new UNDEF position and keep the old one).

andrewfg commented 3 years ago

The jar file is HERE

.. the API should NOT return 0xF7FF in this case ..

Can you please explain to me exactly what is this case? What was the starting condition, and what series of steps ocurred to get you to the case that you refer to?

When I use a multi remote on multiple shutter to 'my' position, all this shutter goes directly to 'UNDEF' in openhab with no position. .. I will try to grab some debug/trace logs.

Could you please send me the respective logs?

andrewfg commented 3 years ago

PS it may be the case that the now resolved message queue overflow was the reason why the actuator positions were not received ??

darkfuncat commented 3 years ago

Hi @andrewfg I had time to make some tests and logs. I have many questions =) First, as always, I just replaced the jar and it restarted automaticaly like a charm. I did not have pollRunner() => slip message queue overflow => PLEASE REPORT !! since this restart.

I made a simple scenario for my device :

room and KLF device name : "bureau"
oh item name "bureauVolet"
'MY' position recorded at '91%' (sunny)
position at start (before 20h14) : 100%
I press 'MY' button, so the shutter open to 91% (20h14m55s)
I wait that OH updates the item position at 91% 2020-11-18 20:16:22.376 [vent.ItemStateChangedEvent] - bureauVolet changed from 100 to 91
I press again 'MY' button, the rollershutter obviously does not move because it is already on good position (20h16m47s)
I wait that OH updates the item to 'UNDEF' 2020-11-18 20:18:23.815 [vent.ItemStateChangedEvent] - bureauVolet changed from 91 to UNDEF

First question : It seems that OH need two cycles of velux addon to update the position of the item. Am i wrong ? In the logs we can see :

a first check with 91% value at 20h17m12s > no item update
a second check with 91% value at 20h18m12s > items updates OK

Second question : I dont understand the log 2020-11-18 20:18:21.653 [TRACE] [g.velux.internal.things.VeluxProduct] - setCurrentPosition(name=bureau,index=7) target 46592 replaced by 63487. Why target is replaced ?

I continue my tests ... =)

openhab-test2xmy.log

andrewfg commented 3 years ago

I dont understand the log 2020-11-18 20:18:21.653 [TRACE] [g.velux.internal.things.VeluxProduct] - setCurrentPosition(name=bureau,index=7) target 46592 replaced by 63487. Why target is replaced ?

Because the KLF reported a new value of target.

The logic that I have used is, (I think exactly as you originally requested), as follows..

if current position is valid (i.e. not 0xf7ff) then display position = current position
else, if target position is valid then display position = target position
else, (i.e. both current and target position are 0xf7ff), then display position = UNDEF

andrewfg commented 3 years ago

@darkfuncat thank you for your help. The essential messages to look at are the GW_GET_NODE_INFORMATION_NTF messages which are 124 bytes long, and the GW_NODE_STATE_POSITION_CHANGED_NTF which are 20 bytes long. See examples below.

2020-11-18 20:15:10.357 [TRACE] [internal.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate() [KLF200.BFX] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => 07 00 07 00 62 75 72 65 61 75 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 80 00 00 00 00 00 00 00 00 00 00 00 00 00 05 C8 00 C8 00 F7 FF F7 FF F7 FF F7 FF 00 00 4F 39 D7 1B 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
..
2020-11-18 20:18:21.644 [TRACE] [internal.bridge.slip.SlipVeluxBridge] - bridgeDirectCommunicate() [KLF200.BFX] GW_OPENHAB_RECEIVEONLY => GW_NODE_STATE_POSITION_CHANGED_NTF => received data => 07 05 F7 FF F7 FF F7 FF F7 FF F7 FF F7 FF 00 00 D7 D8 00 00

To avoid capturing so much non essential data in the logs I suggest you only trace the SlipVeluxBridge messages; as follows..

log:set INFO org.openhab.binding.velux
log:set TRACE org.openhab.binding.velux.internal.bridge.slip.SlipVeluxBridge

And furthermore, within these traces the essential bytes are positions 1 and 85..89 in GW_GET_NODE_INFORMATION_NTF and positions 1..6 in GW_NODE_STATE_POSITION_CHANGED_NTF -- see images below..

andrewfg commented 3 years ago

First question : It seems that OH need two cycles of velux addon to update the position of the item.

Correct GW_GET_NODE_INFORMATION_NTF sets it to 91% (B600) and GW_NODE_STATE_POSITION_CHANGED_NTF sets it to UNDEF (F7FF)

_PS it would be interesting to see if the next GW_GET_NODE_INFORMATION_NTF message (about one minute later) would set it back to to 91% (B600) again. (However your log does not extend that far..)_

PPS perhaps it is worth pointing out that both of the messages in the image above are NON COMPLIANT to the KLF 200 API specification. These are BUGS in the Somfy devices. So, regardless of whatever 'kludges' and work arounds we may devise here, I think that you (@darkfuncat) should report these bugs to the development department at Somfy.

darkfuncat commented 3 years ago

log:set INFO org.openhab.binding.velux log:set TRACE org.openhab.binding.velux.internal.bridge.slip.SlipVeluxBridge

Hello, Oh I didn't ever know we can do that. I will go with it now.

Correct GW_GET_NODE_INFORMATION_NTF sets it to 91% (B600) and GW_NODE_STATE_POSITION_CHANGED_NTF sets it to UNDEF (F7FF) PS it would be interesting to see if the next GW_GET_NODE_INFORMATION_NTF message (about one minute later) would set it back to to 91% (B600) again. (However your log does not extend that far..)

I will try to test more next few days and post filtered logs here.

PPS perhaps it is worth pointing out that both of the messages in the image above are NON COMPLIANT to the KLF 200 API specification. These are BUGS in the Somfy devices. So, regardless of whatever 'kludges' and work arounds we may devise here, I think that you (@darkfuncat) should report these bugs to the development department at Somfy.

I already tried to contact them but without valuable response. They are not very open to discussion and not open at all for open source technologies. (We have some regrets, me, friends and neighboors to have buy Somfy products ... but that's it) Without the velux KLF200 there would be zero solution to integrate somfy io-homecontrol in open source and LAN capacities. I agree this is a bug basicaly between somfy/KLF200 : somfy that does not send correctly or KLF200 API that not understand correctly ? We can see that the API is ready to handle such things with FP1CurrentPosition, FP2CurrentPosition, FP3CurrentPosition, FP4CurrentPosition fields (useless now), perhaps a new version of API will correct this, but there is no more activity from velux I think. I agree with you that there is a non-compliance here, that's why I dont speak of a FIX for a bug, but actualy more a HACK to correct the lack of functionality between somfy/KLF API.

Anyway, I will try to do some more tests, because I realize that there are other things i dont understand. I will do some other posts but the teaser is (weird) :

I have another controller (for 3 device at a time), and when I activate this one, KLF200/binding reports INSTANTLY the new position ... (without waiting for the refresh cycle)
garage door with Somfy also, do the same : instantly report openg/closing I was thinking that the state was refreshed only with cycle within the plugin.

andrewfg commented 3 years ago

I was thinking that the state was refreshed only with cycle within the plugin.

There are 3 opportunities for the state to be updated..

The binding makes GW_RECEIVE_ONLY calls every refreshInterval (every 10 seconds) that processes whatever pending messages that the KLF has sent in the meantime; for example GW_NODE_STATE_POSITION_CHANGED_NTF messages.
The binding makes GW_GET_NODE_INFORMATION_REQ calls every minute, and may receive GW_GET_NODE_INFORMATION_NTF either immediately, or in the next GW_RECEIVE_ONLY call above.
The binding makes GW_COMMAND_SEND_REQ when you change something in OpenHAB, and may receive GW_NODE_STATE_POSITION_CHANGED_NTF either immediately, or in the next GW_RECEIVE_ONLY call above.

darkfuncat commented 3 years ago

Many many thanks, it is cristal clear now for me. Thanks to your explanations and informations, I can now post a simple clear chronology log for my scenario :

18:07:00.734 [TRACE] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => ...00 00 00 00...
18:08:00.625 [TRACE] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => ...00 00 00 00...
18:08:20 > I press 'MY' button (from 0% to 91%)
18:09:00.615 [TRACE] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => ...00 00 00 00...
18:09:39.700 [TRACE] GW_OPENHAB_RECEIVEONLY => GW_NODE_STATE_POSITION_CHANGED_NTF => received data => ...F7 FF B6 00...
18:09:41.814 bureauVolet changed from 0 to 91
18:10:00.838 [TRACE] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => ...F7 FF B6 00...
18:10:20 > I press 'MY' button again (no move, device already at 91%)
18:11:00.841 [TRACE] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => ...F7 FF B6 00...
18:11:39.735 [TRACE] GW_OPENHAB_RECEIVEONLY => GW_NODE_STATE_POSITION_CHANGED_NTF => received data => ...F7 FF F7 FF...
18:11:41.858 bureauVolet changed from 91 to UNDEF
18:12:00.843 [TRACE] GW_GET_NODE_INFORMATION_REQ => GW_GET_NODE_INFORMATION_NTF => received data => ...F7 FF F7 FF...

Full log here : simple2xMY.txt

We see that even if GW_GET_NODE_INFORMATION_REQ is called after a move, the result is not correct (the reality) until KLF200 update its own position. I suppose this is a delay/timeout between the KLF200 and the device itself ?

andrewfg commented 3 years ago

The relevant bytes are as follows..

Node Id (one byte)
State (one byte)
Current Position (two bytes)
Target Position (two bytes)

For any particular move, you might get several xx_NTF messages, with different values of State. Namely State = 2 = message received, State = 3 = waiting for power, State = 4 = moving, State = 5 = movement done. Obviously the State = 5 is the most relevant.

darkfuncat commented 3 years ago

The relevant bytes are as follows..

Node Id (one byte)

State (one byte)

Current Position (two bytes)

Target Position (two bytes)

Yes I understood, that's why I posted only Current&Target Position for the simplified log. (I filtered by node ID=7 in this scenario and state=5). In the file there is the whole line.

darkfuncat commented 3 years ago

Hi @andrewfg , and again, thanks to all your efforts.

Here comes the second scenario logs (even weirder). Scenario : I'am just pressing button 'my' on a mutli device remote (3 devices with ID 00, 01, 0C) from position 0% to 'my'. Complete logs here : openhab-testmulti.log Simplified chain logs for device id 00 here : openhab-testmulti-node00simple.log

I need help to understand if you have a little more time on this problem please =)

There is a state of 02 (which means ‘Not used’ in the doc) and a mixed up of 02, 04, 05 in the time
All the 3 devices do not follow the same logic (2 are refreshed in 'real time', 1 at the end)
And the Item status goes directly to "UNDEF" at the end of the move, without the final position.

Can you help me to understand ?

For the fun part, I have another global remote that can control all my 12 devices to 'my' positions ... but I am affraid of the result ! But I will test in few days, I am curious.

andrewfg commented 3 years ago

Can you help me to understand ?

Let me try. Please see the excerpts from your own log below, in which I have deleted everything except the pattern [actuator Id] [state] [current position] [target position]

Actuators 00 and 0C have silent mode set, in contrast to 01 which has regular mode. This probably explains why 00 and 0C take longer to move and therefore produce more NoTiFications.
When you first opened this issue, you described a pattern [07] 05 F7 FF 50 00 (for actuator 07) where current position is undefined, but target position was OK. And based on that pattern you hypothesised a hack solution. But I do not see that pattern in actuators 00, 01 or 0C. So your hypothetical hack would not work. (??) => What does actuator 07 have different vs. actuators 00, 01 and 0C?
For actuators 00 and 0C the ultimate state is [0x] 05 F7 FF F7 FF which means the KLF is saying it can determine neither the current position nor the target position. Which in plain text means undefined. Or ??
By contrast for actuator 01 the ultimate state is [01] 05 00 00 00 00. So why is it different than 00 and 0C?

19:23:40.836 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 02 00 00 D2 00
19:23:40.841 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 05 00 00 00 00
19:23:40.855 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 02 00 00 F7 FF
19:23:40.859 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 04 00 00 00 00
19:23:40.866 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 04 0E 00 0E 00
19:23:50.826 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 04 4A 00 4A 00
19:23:50.837 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 04 88 00 88 00
19:24:00.830 GW_NODE_STATE_POSITION_CHANGED_NTF => [00] 05 F7 FF F7 FF
19:24:03.466 GW_GET_NODE_INFORMATION_NTF        => [00] 05 F7 FF F7 FF 
19:24:04.789 GW_GET_NODE_INFORMATION_NTF        => [00] 05 F7 FF F7 FF 
19:25:01.365 GW_GET_NODE_INFORMATION_NTF        => [00] 05 F7 FF F7 FF 
19:25:02.715 GW_GET_NODE_INFORMATION_NTF        => [00] 05 F7 FF F7 FF 
19:26:01.399 GW_GET_NODE_INFORMATION_NTF        => [00] 05 F7 FF F7 FF 

19:23:40.819 GW_NODE_STATE_POSITION_CHANGED_NTF => [01] 02 00 00 D2 00
19:23:40.844 GW_NODE_STATE_POSITION_CHANGED_NTF => [01] 02 00 00 F7 FF
19:25:10.841 GW_NODE_STATE_POSITION_CHANGED_NTF => [01] 05 F7 FF F7 FF
19:25:10.841 GW_NODE_STATE_POSITION_CHANGED_NTF => [01] 05 F7 FF F7 FF
19:24:04.354 GW_GET_NODE_INFORMATION_NTF        => [01] 05 00 00 00 00 
19:25:02.263 GW_GET_NODE_INFORMATION_NTF        => [01] 05 00 00 00 00 

19:23:40.824 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 02 00 00 D2 00
19:23:40.829 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 05 00 00 00 00
19:23:40.848 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 02 00 00 F7 FF
19:23:40.851 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 04 00 00 00 00
19:23:40.862 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 04 0E 00 0E 00
19:23:50.822 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 04 44 00 44 00
19:23:50.832 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 04 7C 00 7C 00
19:24:00.825 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 04 F7 FF F7 FF
19:24:00.835 GW_NODE_STATE_POSITION_CHANGED_NTF => [0C] 05 F7 FF F7 FF
19:24:06.150 GW_GET_NODE_INFORMATION_NTF        => [0C] 05 F7 FF F7 FF 
19:25:04.032 GW_GET_NODE_INFORMATION_NTF        => [0C] 05 F7 FF F7 FF

andrewfg commented 3 years ago

For the fun part .. I am curious

PS if you want some 'real' fun, please let me know if you can understand the KLF API Specification 13 Appendix 1 -- it seems to be in 'Danglish' and perhaps a 'Franglais' perspective may help ;)

andrewfg commented 3 years ago

@darkfuncat can you please try an experiment for me? Namely, after you execute your remote MY command, wait until the actuators have reached their ultimate position, and the position becomes UNDEF, please then press the STOP button in OpenHAB PaperUI (see below). I am wondering if STOP might provoke the KLF to restore its position display from UNDEF to the proper actual value? It is just an idea..

darkfuncat commented 3 years ago

Hi @andrewfg

@darkfuncat can you please try an experiment for me?

OK i tried another time the scenario 2 (multi remote for 3 devices, simple press 'MY') I tried to extract the logs like yours. And after UNDEF, i tried tu push 'stop' button in OH UI for 2 devices (00, 0C). See the sequence :

14:51:49.946 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 02 00 00 D2 00
14:51:49.951 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 05 00 00 00 00
14:51:49.972 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 02 00 00 F7 FF
14:51:49.977 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 04 00 00 00 00
14:51:49.988 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 04 0C 00 0C 00
14:51:51.507 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 04 4A 00 4A 00
14:51:53.626 [vent.ItemStateChangedEvent] - salleDeBainVolet changed from 0 to 37
14:51:59.941 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 04 86 00 86 00
14:52:01.758 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 05 F7 FF F7 FF
14:52:05.939 [vent.ItemStateChangedEvent] - salleDeBainVolet changed from 37 to UNDEF
14:52:06.786 GW_GET_NODE_INFORMATION_NTF            => 00 05 F7 FF F7 FF
14:53:00.701 GW_GET_NODE_INFORMATION_NTF            => 00 05 F7 FF F7 FF
14:53:44.394 [ome.event.ItemCommandEvent] - Item 'salleDeBainVolet' received command STOP
14:53:49.965 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 02 F7 FF D2 00
14:53:49.973 GW_NODE_STATE_POSITION_CHANGED_NTF     => 00 05 F7 FF F7 FF
14:54:02.864 GW_GET_NODE_INFORMATION_NTF            => 00 05 F7 FF F7 FF

14:51:49.931 GW_NODE_STATE_POSITION_CHANGED_NTF     => 01 02 00 00 D2 00
14:51:49.956 GW_NODE_STATE_POSITION_CHANGED_NTF     => 01 02 00 00 F7 FF
14:52:07.452 GW_GET_NODE_INFORMATION_NTF            => 01 05 00 00 00 00
14:53:01.363 GW_GET_NODE_INFORMATION_NTF            => 01 05 00 00 00 00
14:53:09.954 GW_NODE_STATE_POSITION_CHANGED_NTF     => 01 05 F7 FF F7 FF
14:53:12.076 [vent.ItemStateChangedEvent] - salleDEauVolet changed from 0 to UNDEF
14:53:59.544 [ome.event.ItemCommandEvent] - Item 'salleDEauVolet' received command STOP
14:53:59.972 GW_NODE_STATE_POSITION_CHANGED_NTF     => 01 02 F7 FF D2 00
14:53:59.979 GW_NODE_STATE_POSITION_CHANGED_NTF     => 01 05 F7 FF F7 FF
14:54:03.542 GW_GET_NODE_INFORMATION_NTF            => 01 05 F7 FF F7 FF

14:51:49.936 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 02 00 00 D2 00
14:51:49.941 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 05 00 00 00 00
14:51:49.962 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 02 00 00 F7 FF
14:51:49.967 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 04 00 00 00 00
14:51:49.982 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 04 0E 00 0E 00
14:51:51.453 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 04 44 00 44 00
14:51:53.631 [vent.ItemStateChangedEvent] - chambreSuiteVolet changed from 0 to 34
14:51:59.936 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 04 7C 00 7C 00
14:52:01.752 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 04 F7 FF F7 FF
14:52:03.821 GW_NODE_STATE_POSITION_CHANGED_NTF     => 0C 05 F7 FF F7 FF
14:52:05.946 [vent.ItemStateChangedEvent] - chambreSuiteVolet changed from 34 to UNDEF
14:52:08.993 GW_GET_NODE_INFORMATION_NTF            => 0C 05 F7 FF F7 FF
14:53:02.902 GW_GET_NODE_INFORMATION_NTF            => 0C 05 F7 FF F7 FF
14:54:05.061 GW_GET_NODE_INFORMATION_NTF            => 0C 05 F7 FF F7 FF

I dont understand :

why 1 device (01) does not interact like the 2 others (00, 0C) because 00 and 01 are stricly the same roller shutters
some messages with '02' state (at each beginning of sequence it seems)
why KLF send multiple messages with '04' state and OH does not update all states
why KLF send a '05' message state with positions '00 00 00 00' at the beginning
why final position goes directly to 'F7 FF F7 FF' with this multi-remote, instead of single remote that sends 'current/target' to expected 'F7 FF my my'
why a message '02 F7 FF D2 00' after I press 'stop' command in UI

PS if you want some 'real' fun, please let me know if you can understand the KLF API Specification 13 Appendix 1 -- it seems to be in 'Danglish' and perhaps a 'Franglais' perspective may help ;)

I did not understand the section 13. Perhaps only an attempt to explain how the values work ?

andrewfg commented 3 years ago

why 1 device (01) does not interact like the 2 others (00, 0C) because 00 and 01 are stricly the same roller shutters

Look at byte 69 in the traces; in 00, 0c it is 01 (silent mode) whereas in 01 it is 00 (normal mode)

some messages with '02' state (at each beginning of sequence it seems)

Indeed. Notwithstanding what it says in the API, this seems to be normal.

why KLF send multiple messages with '04' state and OH does not update all states

State 04 means 'moving' so current position will have various values as the movement proceeds. If 02 <= state <= 04 then OH will display the target (destination) position. If state == 05 then OH will display the current (actual) position.

why KLF send a '05' message state with positions '00 00 00 00' at the beginning

No idea. (Ask Somfy).

why final position goes directly to 'F7 FF F7 FF' with this multi-remote, instead of single remote that sends 'current/target' to expected 'F7 FF my my'

Same answer as above.

why a message '02 F7 FF D2 00' after I press 'stop' command in UI

Target value D200 means "same as current". Which in this case means F7FF (don't know). So see answer above :)

only an attempt to explain how the values work

Indeed, Unfortunately I stress the word 'only' :)

darkfuncat commented 3 years ago

Thanks for informations. I did not notice previously there was a notion of 'silent' vs 'normal'. The fact is I dont know why some roller shutters are in 'normal' mode and other in 'silent' mode. (simple remote with only 3 buttons UP, MY/STOP, DOWN) Particulary between actuators 00 and 01 (they are stricly the same one, model, etc.)

BUT after another test, I discover that one of my device (01), even with my single remote, goes directly to UNDEF when I press MY.

Conclusion by now with my tests :

your fix works correctly with my devices (except one) if I push MY button only once
if I press again 'my' button state goes to UNDEF
if I use a multi remote the state goes directly to UNDEF

I will do some further tests, especially with another remote that can select any device or group of device.

darkfuncat commented 3 years ago

Update :

if I use a multi remote the state goes directly to UNDEF

Some tests after : when I use a multi-device remote, whatever device I control, if there are more than one roller shutter in the group the status goes directly to UNDEF. Same thing with scenes under OH.

andrewfg commented 3 years ago

@darkfuncat as you correctly observe, most of your remote actions end up with an undefined position, and I am beginning to think that there is no way to solve your request.

I think that once an actuator gets into an undefined position, it needs some kind of 'provocation' to rediscover its real position again. I was hoping the STOP command might do that, but apparently not. There is another 'provocation' we can try..

Normally OH sends absolute position move commands (e.g. move to 0% .. 100%) to the KLF. The KLF also supports relative position move commands (e.g. move to current position +/- 100%) so perhaps the relative move command 'move to current position +0%' (position CCE8) could 'provoke' the actuator to rediscover its current position.

Relative position commands have not yet been implemented in the binding, so I wrote a 'quick & dirty' implementation in a new build jar file HERE whereby relative position move commands can be sent via a 'Rule Action' function called moveRelative().

So can you please i) install this new jar file, ii) issue your 'MY' command, iii) wait until the actuator reaches its ultimate position, and then finally iv) call the moveRelative() function in the following rule..

{ note: you must edit the following rule to enter the name of your trigger Item, the name of your KLF bridge, and the nodeId of your actuator to be tested }

rule "Execute moveRelative() Command"
when
  Item The_Trigger_Item changed // <= an Item in your system that is (mis-)used to trigger the rule
then
  val nodeId = "0" // <= the node id of the actuator under test
  val relativePosition = "0" // keep this 0
  val veluxActions = getActions("velux", "velux:klf200:yourBridgeName") // enter your bridge name
  val success = veluxActions.moveRelative(nodeId, relativePosition)
  logWarn("Rules", "Velux moveRelative() executed: " + success)
end

EDIT: if moveRelative(0) fails to provoke a status change, I wonder if there are any other possible provocations, such as..

Send a regular move command to the actuator via OH => presumably this does indeed work (but please confirm)
Send a STOP command => does not work
Send a moveRelative(0) command => to be tested above
Wait say 15 minutes => ??
Wait say 1 hour => ??
Power cycle the KLF => ??
Send a regular move command followed immediately by a STOP command => ??
Any other thoughts ??

darkfuncat commented 3 years ago

Hi @andrewfg I tried with the new jar your command, but it throws an error : [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Execute moveRelative() Command': 'moveRelative' is not a member of 'org.eclipse.smarthome.core.thing.binding.ThingActions'; The jar size is 427398. Perhaps I am not doing the right install ? I ve just replaced the jar in OH addons and it restarts automatically. For others points :

Wait say 15 minutes => no effect
Wait say 1 hour => no effect
Power cycle the KLF => not tested yet

andrewfg commented 3 years ago

Command': 'moveRelative' is not a member of 'org.eclipse.smarthome.core.thing.binding.ThingActions'; The jar size is 427398

It looks like you do have the correct jar file (the date is 2020-11-20 18:54, and size 427398) so probably the error is that you are calling moveRelative with the wrong type of arguments; both arguments nodeId and relativePosition must be String values; so "1" , "0" etc. WITH enclosing quote marks (and "13" rather than 0C).

andrewfg commented 3 years ago

..

  val veluxActions = getActions("velux", "velux:klf200:home")
  val success = veluxActions.moveRelative("13", "0")

darkfuncat commented 3 years ago

Hi @andrewfg I copied/paste exactly your code but it still produces the same error log. How do you find the jar version in the OH UI ? I am searching everywhere but I have not this information of the 'bundleVersion', nor in the logs.

And in binding section :

I use OH stable 2.5.10. (except your addon)

andrewfg commented 3 years ago

How do you find the jar version in the OH UI ? I am searching everywhere but I have not this information of the 'bundleVersion', nor in the logs.

You will find a Thing called "Velux Binding Information". If you instantiate that Thing, and look at its properties you will see its bundle version.

andrewfg commented 3 years ago

darkfuncat commented 3 years ago

Yes I did it. Bridge velux:klf200:home "cagibi - controller (Velux KLF200)" @ "cagibi" [ ipAddress="KLF200.BFX", protocol="slip", tcpPort=51200, password="xxx", timeoutMsecs=2000, retries=10, isSequentialEnforced="false", isProtocolTraceEnabled="false" ]

And :

  val veluxActions = getActions("velux", "velux:klf200:home")
  val success = veluxActions.moveRelative("13", "0")

You will find a Thing called "Velux Binding Information". If you instantiate that Thing, and look at its properties you will see its bundle version.

I have only one thing, i will try to instanciate this other thing "Velux Binding Information". I did not restart OH yet for weeks. Perhaps some cache ?

andrewfg commented 3 years ago

I uploaded yet another jar here in which the moveRelative() action is called automatically if the actuator goes into an undefined state. i.e. Without the necessity of triggering a rule. NOTE: this may not be a good idea since it risks to interfere with your "MY" commands..

darkfuncat commented 3 years ago

Thanks @andrewfg I will give it a try tonight. Another test I am doing also : I have made another hack other your hack (mmmh... not sure it is good idea but ...), in OH rules, I set a contant with the favorite position 'my' for each actuator. And I trigger the UNDEF to set to this memory value. I will try sooner and stay you informed. If this works, perhaps it may be a clean new feature of the plugin instead of a dirty code in my specific rules? It can even work with non-somfy device I guess ...

andrewfg commented 3 years ago

in OH rules, I set a constant with the favorite position 'my' for each actuator. And I trigger the UNDEF to set to this memory value

Yes, that is basically what I am trying to do via moveRelative(xx, 0), although with the extra sophistication of not having to store the constant, because moveRelative(xx, 0) says "move to stored/current position +0%"..

openhab / openhab-addons