search

dxdc / homebridge-blinds

:sunrise: Homebridge Plugin to control my blinds over HTTP
https://www.npmjs.com/package/homebridge-blinds
ISC License
54 stars 25 forks source link

Plugin seems to send incorrect commands #64

Closed genfersee closed 2 years ago

genfersee commented 3 years ago

Hello! I am facing an new issue for a few days: After upgrading my Jbmedia Light Manager to the latest Firmware, sending blind commands in a row make the plugin unstable.

For example, I launch a scene in Homekit to shut down 3 blinds. With any old Light Manager FW, it was working ok, no problem. Since latest FW, only 1 out of the 3 blinds shuts down properly and homebridge-blinds plugin is sending DOWN commands to 1 of the blinds every second endlessly. Restaring Homebridge is the only way to recover to normal behaviour. During that, I get some endless spinning weels running on the 3 blinds tiles in Homekit.

I can also reproduce the issue by tapping manually for example DOWN on blind 1 and then very quickly (less than 1 sec after) after DOWN on blind 2. Then only blind 1 reacts and plugin sends endlessly DOWN commands every seconds.

Please let me know how we could investigate this issue... :)

dxdc commented 3 years ago

@genfersee

Can you enable "verbose": true in the settings and post your logs as well as your config? I'm wondering if the plugin is getting an unexpected response from your blinds.

genfersee commented 3 years ago

Hi @dxdc ! Here is my config:

"accessories": [
        {
            "name": "Bureau Ouest",
            "up_url": "http://192.xx.xx.xx/control?cmd=up,typ,som,did,xxxxxx,aid,11,acmd,1,seq,3,smk,0,1&id=11",
            "down_url": "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,11,acmd,0,seq,3,smk,0,0&id=11",
            "motion_time": 3000,
            "show_toggle_button": true,
            "stop_url": "http://192.168.xx.xx/control?cmd=my,typ,som,did,xxxxxx,aid,11,acmd,3,seq,3&id=11",
            "show_stop_button": true,
            "trigger_stop_at_boundaries": false,
            "webhook_port": xxxxxx,
            "verbose": true,
            "accessory": "BlindsHTTP"
        },
        {
            "name": "Bureau Sud",
            "up_url": "http://192.xx.xx.xx/control?cmd=up,typ,som,did,xxxxxx,aid,12,acmd,1,seq,3,smk,1,1&id=12",
            "down_url": "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,12,acmd,0,seq,3,smk,1,0&id=12",
            "motion_time": 3000,
            "show_toggle_button": true,
            "stop_url": "http://192.xx.xx.xx/control?cmd=my,typ,som,did,xxxxxx,aid,12,acmd,3,seq,3&id=12",
            "show_stop_button": true,
            "trigger_stop_at_boundaries": false,
            "webhook_port": xxxxx,
            "verbose": true,
            "accessory": "BlindsHTTP"
        },
        {
            "name": "Chambre Ouest",
            "up_url": "http://192.xx.xx.xx/control?cmd=up,typ,som,did,xxxxxx,aid,13,acmd,1,seq,3,smk,2,1&id=13",
            "down_url": "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,13,acmd,0,seq,3,smk,2,0&id=13",
            "stop_url": "http://192.xx.xx.xx/control?cmd=my,typ,som,did,xxxxxx,aid,13,acmd,3,seq,3&id=13",
            "toggle_url": "http://192.xx.xx.xx/control?cmd=toggle,typ,som,did,xxxxxx,aid,13,acmd,2,seq,3,smk,2,0&id=13",
            "show_stop_button": true,
            "show_toggle_button": true,
            "motion_time": "3000",
            "http_method": "POST",
            "trigger_stop_at_boundaries": false,
            "webhook_port": xxxxx,
            "verbose": true,
            "accessory": "BlindsHTTP"
        },
        {
            "name": "Salon Sud",
            "up_url": "http://xx.xx.xx.xx/control?cmd=up,typ,som,did,xxxxxx,aid,14,acmd,1,seq,3,smk,3,1&id=14",
            "down_url": "http://xx.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,14,acmd,0,seq,3,smk,3,0&id=14",
            "stop_url": "http://xx.xx.xx.xx/control?cmd=my,typ,som,did,xxxxxx,aid,14,acmd,3,seq,3&id=14",
            "toggle_url": "http://xx.xx.xx.xx/control?cmd=toggle,typ,som,did,xxxxxx,aid,14,acmd,2,seq,3,smk,3,0&id=14",
            "show_stop_button": true,
            "show_toggle_button": true,
            "motion_time": "3000",
            "http_method": "POST",
            "trigger_stop_at_boundaries": false,
            "webhook_port": xxxxx,
            "verbose": true,
            "accessory": "BlindsHTTP"
        }
    ],

So I reproduced the issue with the logs i.e. starting a scene in Homekit which shuts down 3 out of 4 of my blinds. Resukt is that only "Bureau Sud" blind is down. "Bureau Ouest" and "Chambre Ouest" are still up.

Here are the logs:

[10.06.2021 à 07:52:55] Homebridge v1.3.4 (Homebridge) is running on port 51825.
[10.06.2021 à 07:52:57] [Bureau Ouest] Requested CurrentPosition: 100%
[10.06.2021 à 07:52:57] [Bureau Ouest] Requested TargetPosition: 100%
[10.06.2021 à 07:52:57] [Bureau Sud] Requested CurrentPosition: 100%
[10.06.2021 à 07:52:57] [Bureau Sud] Requested TargetPosition: 100%
[10.06.2021 à 07:52:57] [Chambre Ouest] Requested CurrentPosition: 100%
[10.06.2021 à 07:52:57] [Chambre Ouest] Requested TargetPosition: 100%
[10.06.2021 à 07:52:57] [Salon Sud] Requested CurrentPosition: 100%
[10.06.2021 à 07:52:57] [Salon Sud] Requested TargetPosition: 100%
[10.06.2021 à 07:53:02] [Homebridge UI] Homebridge Config UI X v4.41.1 is listening on :: port 8080
[10.06.2021 à 07:53:26] [Bureau Sud] Requested CurrentPosition: 100%
[10.06.2021 à 07:53:26] [Bureau Sud] Requested TargetPosition: 100%
[10.06.2021 à 07:53:26] [Bureau Ouest] Requested TargetPosition: 100%
[10.06.2021 à 07:53:26] [Bureau Ouest] Requested CurrentPosition: 100%
[10.06.2021 à 07:53:26] [Salon Sud] Requested CurrentPosition: 100%
[10.06.2021 à 07:53:26] [Salon Sud] Requested TargetPosition: 100%
[10.06.2021 à 07:53:26] [Chambre Ouest] Requested TargetPosition: 100%
[10.06.2021 à 07:53:26] [Chambre Ouest] Requested CurrentPosition: 100%
[10.06.2021 à 07:53:33] [Bureau Sud] Requested Move down (to 0%)
[10.06.2021 à 07:53:33] [Chambre Ouest] Requested Move down (to 0%)
[10.06.2021 à 07:53:33] [Bureau Ouest] Requested Move down (to 0%)

And the plugin keeps sending endlessly the commands:

07:55:30 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:29 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:27 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:26 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:24 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:22 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:21 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:19 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:17 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:16 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:14 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:12 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:10 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:08 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:07 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:05 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:04 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:01 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:55:00 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:58 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:56 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:54 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:52 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:50 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:49 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:48 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:45 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:44 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:42 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:41 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:39 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:38 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:36 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:35 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:33 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:32 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:31 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:29 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:27 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:26 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:24 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:22 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:20 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:19 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:17 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:16 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:14 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:12 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:10 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:09 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:07 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:05 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:04 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:01 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:54:00 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:58 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:57 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:55 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:54 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:52 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:50 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:49 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:47 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:46 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:44 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:43 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:41 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:40 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:39 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:37 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:36 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
07:53:34 | 192.xx.xx.xx > down,som,did,xxxxxx,aid,12,off,seq,3,smk,1,0
dxdc commented 3 years ago

Thanks @genfersee :

For one thing,

And the plugin keeps sending endlessly the commands:

This seems like an error with your "Bureau Sud", based on the presence of F34CCA in the logs.

  1. Please try (from the command line) curl -vs "http://192.168.33.21/control?cmd=down,typ,som,did,F34CCA,aid,12,acmd,0,seq,3,smk,1,0&id=12" and make sure that the blinds go down. Compare with the instructions for another blind. Try sending different blind instructions quickly (command-line) to see if there is some change in behavior there.

  2. Try controlling the blinds individually from HK, not in a group. Do you see a difference? I'm also wondering if your IP address (192.168.33.21) is getting overwhelmed with API requests and not returning or causing some other issue. I don't understand why 192.168.33.43 is being shown in the log file.

  3. Try commenting out the JSON entry for "Bureau Sud" and see what happens? Or, at least remove it from your grouped blinds control.

genfersee commented 3 years ago

Thanks! I forgot to remove these old togglt-url parameters :)

Any of the 4 blinds are reacting perfectly to the urls in command line (up, down), if the commands are not sent too quickly. For example for "Bureau Sud":

curl -vs "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,12,acmd,0,seq,3,smk,1,0&id=12" makes the blind "Bureau Sud" go down and we get:

*   Trying 192.xx.xx.xx...
* TCP_NODELAY set
* Connected to 192.xx.xx.xx (192.xx.xx.xx) port 80 (#0)
> GET /control?cmd=down,typ,som,did,xxxxxx,aid,12,acmd,0,seq,3,smk,1,0&id=12 HTTP/1.1
> Host: 192.xx.xx.xx
> User-Agent: curl/7.64.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Connection: close
< Access-Control-Allow-Origin: *
< Cache-Control: max-age=86400
< 
* Closing connection 0

Then I tried to send the 3 following commands quickly in a row (with let's say 300ms between each): curl -vs "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,13,acmd,0,seq,3,smk,2,0&id=13" curl -vs "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,11,acmd,0,seq,3,smk,0,0&id=11" curl -vs "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,12,acmd,0,seq,3,smk,1,0&id=12"

And I see the same issue: 1 out of 3 blinds get down and the 2 other gets stucks.:

$ curl -vs "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,11,acmd,0,seq,3,smk,0,0&id=11"
*   Trying 192.xx.xx.xx...
* TCP_NODELAY set
* Connected to 192.xx.xx.xx (192.xx.xx.xx) port 80 (#0)
> GET /control?cmd=down,typ,som,did,xxxxxx,aid,11,acmd,0,seq,3,smk,0,0&id=11 HTTP/1.1
> Host: 192.xx.xx.xx
> User-Agent: curl/7.64.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Connection: close
< Access-Control-Allow-Origin: *
< Cache-Control: max-age=86400
< 
* Closing connection 0

and

$ curl -vs "http://192.xx.xx.xx/control?cmd=down,typ,som,did,xxxxxx,aid,13,acmd,0,seq,3,smk,2,0&id=13"
*   Trying 192.xx.xx.xx...
* TCP_NODELAY set
* Connected to 192.xx.xx.xx (192.xx.xx.xx) port 80 (#0)
> GET /control?cmd=down,typ,som,did,xxxxxx,aid,13,acmd,0,seq,3,smk,2,0&id=13 HTTP/1.1
> Host: 192.xx.xx.xx
> User-Agent: curl/7.64.1
> Accept: */*
>

This last one remains stuck! I managed to reproduce the issue and your plugin is not involved so I will investigsate back with jbmedia!

Thanks a lot for your help!

dxdc commented 3 years ago

This last one remains stuck! I managed to reproduce the issue and your plugin is not involved so I will investigsate back with jbmedia!

Glad you've found the root of the issue... it seems like an issue with the endpoint. Good luck!

genfersee commented 2 years ago

Hello @dxdc So far we did not find a solution with jbmedia. As a workaround, is there a way to introduce a 1 or 2 sec delay (in plugin config) between 4 blind down commands sent by Homekit to the pluggin? Kind regard!

dxdc commented 2 years ago

@genfersee Each blinds instance is independent, so there's no way to introduce a queue since each instance is not aware of the other one. When you toggle 4 blinds at once, this is managed by HomeKit, not the blinds accessory -- and it is not queued. You can try to introduce a slightly different response_lag for each, but I think this is a bit of a hack and won't be a reliable permanent fix.

If you can't fix the firmware, I would suggest creating your own middleware endpoint and managing the queue that way. NodeRED is a great solution for this kind of thing.

genfersee commented 2 years ago

Thanks a lot @dxdc , they fixed the endless loop issue in a new FW! But now I see some unexpected behaviour.

Here is my config:

  "accessories": [
        {
            "name": "Bureau Ouest",
            "up_url": "http://192.168.33.21/control?cmd=up,typ,som,did,98DC09,aid,11,acmd,1,seq,3,smk,0,1&id=11",
            "down_url": "http://192.168.33.21/control?cmd=down,typ,som,did,98DC09,aid,11,acmd,0,seq,3,smk,0,0&id=11",
            "motion_time": 3000,
            "show_toggle_button": true,
            "stop_url": "http://192.168.33.21/control?cmd=my,typ,som,did,98DC09,aid,11,acmd,3,seq,3&id=11",
            "show_stop_button": true,
            "trigger_stop_at_boundaries": false,
            "webhook_port": 51828,
            "verbose": false,
            "accessory": "BlindsHTTP"
        },
        {
            "name": "Bureau Sud",
            "up_url": "http://192.168.33.21/control?cmd=up,typ,som,did,F34CCA,aid,12,acmd,1,seq,3,smk,1,1&id=12",
            "down_url": "http://192.168.33.21/control?cmd=down,typ,som,did,F34CCA,aid,12,acmd,0,seq,3,smk,1,0&id=12",
            "motion_time": 3000,
            "show_toggle_button": true,
            "stop_url": "http://192.168.33.21/control?cmd=my,typ,som,did,F34CCA,aid,12,acmd,3,seq,3&id=12",
            "show_stop_button": true,
            "trigger_stop_at_boundaries": false,
            "webhook_port": 51829,
            "verbose": true,
            "accessory": "BlindsHTTP"
        },
        {
            "name": "Chambre Ouest",
            "up_url": "http://192.168.33.21/control?cmd=up,typ,som,did,CBFB83,aid,13,acmd,1,seq,3,smk,2,1&id=13",
            "down_url": "http://192.168.33.21/control?cmd=down,typ,som,did,CBFB83,aid,13,acmd,0,seq,3,smk,2,0&id=13",
            "stop_url": "http://192.168.33.21/control?cmd=my,typ,som,did,CBFB83,aid,13,acmd,3,seq,3&id=13",
            "show_stop_button": true,
            "show_toggle_button": true,
            "motion_time": "3000",
            "http_method": "POST",
            "trigger_stop_at_boundaries": false,
            "webhook_port": 51830,
            "verbose": true,
            "accessory": "BlindsHTTP"
        },
        {
            "name": "Salon Sud",
            "up_url": "http://192.168.33.21/control?cmd=up,typ,som,did,33DFAE,aid,14,acmd,1,seq,3,smk,3,1&id=14",
            "down_url": "http://192.168.33.21/control?cmd=down,typ,som,did,33DFAE,aid,14,acmd,0,seq,3,smk,3,0&id=14",
            "stop_url": "http://192.168.33.21/control?cmd=my,typ,som,did,33DFAE,aid,14,acmd,3,seq,3&id=14",
            "show_stop_button": true,
            "show_toggle_button": true,
            "motion_time": "3000",
            "http_method": "POST",
            "trigger_stop_at_boundaries": false,
            "webhook_port": 51831,
            "verbose": true,
            "accessory": "BlindsHTTP"
        }
    ],

I defined a scene in Homekit for stopping the 4 blinds. So this scene is supposed to trigger the 4 stop_url above.

The plugin says:

[24.07.2021, 13:47:54] [Chambre Ouest] Requesting manual stop
[24.07.2021, 13:47:54] [Bureau Sud] Requesting manual stop
[24.07.2021, 13:47:54] [Bureau Ouest] Requesting manual stop
[24.07.2021, 13:47:54] [Salon Sud] Requesting manual stop
[24.07.2021, 13:47:56] [Bureau Sud] Request succeeded in 2520 ms after 1 / 5 attempts
[24.07.2021, 13:47:56] [Bureau Sud] Body (200): OK
[24.07.2021, 13:47:56] [Bureau Sud] Stop request sent
[24.07.2021, 13:47:56] [Chambre Ouest] Request succeeded in 2546 ms after 1 / 5 attempts
[24.07.2021, 13:47:56] [Chambre Ouest] Body (200): OK
[24.07.2021, 13:47:56] [Chambre Ouest] Stop request sent
[24.07.2021, 13:47:58] [Bureau Ouest] Stop request sent
[24.07.2021, 13:47:59] [Salon Sud] Request succeeded in 4619 ms after 1 / 5 attempts
[24.07.2021, 13:47:59] [Salon Sud] Body (200): OK
[24.07.2021, 13:47:59] [Salon Sud] Stop request sent

And on blind interface I see:

13:47:58 | 192.168.33.43 > my,som,did,33DFAE,aid,14,acmd,3,seq,3
13:47:57 | 192.168.33.43 > my,som,did,98DC09,aid,11,acmd,3,seq,3
13:47:56 | 192.168.33.43 > my,som,did,CBFB83,aid,13,acmd,3,seq,3
13:47:55 | 192.168.33.43 > my,som,did,CBFB83,aid,13,acmd,3,seq,3

As you can see, some actions are missing on plugin side. An on blind interface, a command is sent twice!

Kind regards, Yohann

dxdc commented 2 years ago

Hi @genfersee 3-5 seconds for a reply from a local server is still a long time.

Was there ever a reply from Bureau Ouest? Based on what you sent me, it seems like there was no response from your blinds. I can see here:

[24.07.2021, 13:47:58] [Bureau Ouest] Stop request sent

But I don't see any follow up from that.

I still suspect your blinds interface as the problem. Try something like the following. It may need some more work, but here is the basic concept.

  1. Create the below file (e.g., test.sh).
  2. Add the executable bit (chmod +x test.sh)
  3. Run the command (./test.sh)

I have not seen or experienced the behavior you describe, so I suspect it's still a bug in the firmware of your blinds. If each blind works properly when run independently in HomeKit, but it doesn't work properly as a group, the issue is most likely your firmware.

#!/bin/sh

( NAME="Bureau Ouest" && echo "start: ${NAME}" && STATE=$( curl -sL "http://192.168.33.21/control?cmd=my,typ,som,did,98DC09,aid,11,acmd,3,seq,3&id=11" ) && echo "${NAME}: ${STATE}" ) &
( NAME="Bureau Sud" && echo "start: ${NAME}" && STATE=$( curl -sL "http://192.168.33.21/control?cmd=my,typ,som,did,F34CCA,aid,12,acmd,3,seq,3&id=12" ) && echo "${NAME}: ${STATE}" ) &
( NAME="Chambre Ouest" && echo "start: ${NAME}" && STATE=$( curl -sL "http://192.168.33.21/control?cmd=my,typ,som,did,CBFB83,aid,13,acmd,3,seq,3&id=13" ) && echo "${NAME}: ${STATE}" ) &
( NAME="Salon Sud" && echo "start: ${NAME}" && STATE=$( curl -sL "http://192.168.33.21/control?cmd=my,typ,som,did,33DFAE,aid,14,acmd,3,seq,3&id=14" ) && echo "${NAME}: ${STATE}" ) &
dxdc commented 2 years ago

By the way, you also have motion time set to 3000, but your HTTP response is much longer. It's possible that is the reason for the duplicate entry you're seeing (depending).

genfersee commented 2 years ago

Many thanks for your help! Indeed, the 4 blinds work perfectly when operated separately. You are right, the issue is also reproduced when executing the test.sh....! I will then get back to firmware team... And inde I also increased motion time to 10000. Kind regards!

genfersee commented 2 years ago

Unfortunately, they will not investigate anymore into this since they consider Homebrige is not able to send commands in an approriate manner. Their latest firmware makes processing all incoming commands in the order received. Consecutive commands reside in a queue until these are processed.

Can we make sure that the timeout of the HTTP requests is long enough, so that no timeout occurs before each command has been processed? 5s might be too short...

If no solution, I will revert to the old FW which was working perfectly.

dxdc commented 2 years ago

Can we make sure that the timeout of the HTTP requests is long enough, so that no timeout occurs before each command has been processed? 5s might be too short...

Are you seeing an issue with timeouts? One thing that you can try is using a request object instead of plain string for your URLs. See: https://github.com/request/request#requestoptions-callback

Setting time here will show you a lot more detail on the aspects of the request, which can be useful for troubleshooting. You can also customize HTTP timeouts here per the request documentation.

      "up_url": {
        "url": "http://192.168.33.21/control?cmd=up,typ,som,did,CBFB83,aid,13,acmd,1,seq,3,smk,2,1&id=13",
        "maxAttempts": 5,
        "retryDelay": 2000,
        "time": true
      },
genfersee commented 2 years ago

Thanks! I get the same result...

[24.07.2021, 19:03:21] [Chambre Ouest] Requesting manual stop
[24.07.2021, 19:03:21] [Bureau Sud] Requesting manual stop
[24.07.2021, 19:03:21] [Bureau Ouest] Requesting manual stop
[24.07.2021, 19:03:21] [Salon Sud] Requesting manual stop
[24.07.2021, 19:03:24] [Bureau Sud] Request profiling: {"wait":2.5440509999971255,"dns":0,"tcp":13.338219999997818,"firstByte":2584.9201420000027,"download":3.7785250000015367,"total":2604.580937999999}
[24.07.2021, 19:03:24] [Bureau Sud] Request succeeded in 2637 ms after 1 / 5 attempts
[24.07.2021, 19:03:24] [Bureau Sud] Body (200): OK
[24.07.2021, 19:03:24] [Bureau Sud] Stop request sent
[24.07.2021, 19:03:24] [Chambre Ouest] Request profiling: {"wait":5.325809000001755,"dns":0,"tcp":12.591974000002665,"firstByte":2602.3920419999995,"download":0.9872350000005099,"total":2621.2970600000044}
[24.07.2021, 19:03:24] [Chambre Ouest] Request succeeded in 2684 ms after 1 / 5 attempts
[24.07.2021, 19:03:24] [Chambre Ouest] Body (200): OK
[24.07.2021, 19:03:24] [Chambre Ouest] Stop request sent
[24.07.2021, 19:03:25] [Bureau Ouest] Request profiling: {"wait":1.8304599999974016,"dns":0,"tcp":2649.7852120000025,"firstByte":1205.9500449999978,"download":2.0931150000033085,"total":3859.658832000001}
[24.07.2021, 19:03:25] [Bureau Ouest] Stop request sent
[24.07.2021, 19:03:26] [Salon Sud] Request profiling: {"wait":2.047074000001885,"dns":0,"tcp":2665.3972769999964,"firstByte":1860.8414970000013,"download":0.9575479999984964,"total":4529.243395999998}
[24.07.2021, 19:03:26] [Salon Sud] Request succeeded in 4549 ms after 1 / 5 attempts
[24.07.2021, 19:03:26] [Salon Sud] Body (200): OK
[24.07.2021, 19:03:26] [Salon Sud] Stop request sent

and

19:03:26 | 192.168.33.43 > my,som,did,33DFAE,aid,14,acmd,3,seq,3
19:03:25 | 192.168.33.43 > my,som,did,98DC09,aid,11,acmd,3,seq,3
19:03:23 | 192.168.33.43 > my,som,did,CBFB83,aid,13,acmd,3,seq,3
19:03:22 | 192.168.33.43 > my,som,did,CBFB83,aid,13,acmd,3,seq,3
dxdc commented 2 years ago

You asked about changing the timeout, which is how you can do it. This plugin can't fix the bug in the firmware :)

genfersee commented 2 years ago

Got your point now :) I will try! Thanks for your support :)