Error running command: Stdout:

[Ryamonster10]

Hello,

I am trying to use my Somfy blinds by sending commands to a Python script called Pi-Somfy. I have put in my up, down and stop, and timed my blinds and how long it takes to respond to requests. It works perfectly calling the commands in the terminal, and it sort of works in the home app too, but it says "Obstructed" and I get constant logs in Homebridge saying:
"Error running command:
Stdout:"
What is this being caused by?
My config file is here, and on my blinds, the same command is used for up and stop. https://pastebin.com/e5L9j4F5

Thanks,
Ryan

[dxdc]

Looks like there are a number of problems with your config. Have you tested these commands directly on the command line and ensured they return a default (zero) exit code?

Here are some aspects that are worth reviewing from an example part of your config, e.g.

"url": "file:// sudo python3 /home/pi/Pi-Somfy/operateShutters.py -c /home/pi/Pi-Somfy/operateShutters.conf \"Center\" -stop",

1. You have a space between file:// and sudo.
2. Your syntax does not look correct, but you should follow up with any syntax questions with https://github.com/Nickduino/Pi-Somfy
3. Your up URL uses the stop command at the end.

All that being said, it looks like Pi-Somfy supports MQTT out of the box. You're probably better off using a MQTT-based plugin like https://github.com/arachnetech/homebridge-mqttthing.

[Ryamonster10]

Makes sense, however if where it says "Move request sent (time)" is not the time to send the command (the amount that you should subtract to get your response delay), what is? In the docs it says that it is that message that defines that delay. Is it zero because I'm not sending http request?

[dxdc]

Is it zero because I'm not sending http request?

It should be, yes.

Regardless of the log messages, is the behavior working as expected now? There may also be a delay before PiSomfy returns, but I've never used it so couldn't say. If so, you could always add a & at the end to run it as a background command. It may speed up the relative performance of the plugin.

[Ryamonster10]

Consider the following series of actions (pasted from homebridge)

[06/01/2024, 17:12:08] [Center] Requested Move down (to 50%)
[06/01/2024, 17:12:21] [Center] Command succeeded in 13121 ms
[06/01/2024, 17:12:21] [Center] Stdout: 
[06/01/2024, 17:12:21] [Center] Calculated time to move from 100 to 50: 8430 ms
[06/01/2024, 17:12:21] [Center] Move request sent (13121 ms), waiting 8.4s (+ 2.4s response lag)...
[06/01/2024, 17:12:21] [Center] Stop command will be requested
[06/01/2024, 17:12:23] [Center] Timeout finished
[06/01/2024, 17:12:29] [Center] Requesting stop
[06/01/2024, 17:12:31] [Center] Command succeeded in 2110 ms
[06/01/2024, 17:12:31] [Center] Stdout: 
[06/01/2024, 17:12:31] [Center] Stop request sent
[06/01/2024, 17:12:32] [Center] End Move down to 50% (target 50%)

The original command is sent at 17:12:21. It is calculated that it will take 8.4 seconds to move there, but the command should be sent 2.4 seconds before that to account for response lag. 8.4 - 2.4 = 6.2. The stop command should be sent 6.2 seconds later (at 17:12:27) instead it is sent at 17:12:31 when the blind is already at the bottom, triggering it to go back up because my blinds use the same command for stop and up. Below is my config for that blind.

        {
            "name": "Center",
            "up_url": {
                "url": "file:// sudo python3 /home/pi/Pi-Somfy/operateShutters.py -c /home/pi/Pi-Somfy/operateShutters.conf \"Center\" -stop || exit 0 &",
                "retryDelay": 500
            },
            "down_url": {
                "url": "file:// sudo python3 /home/pi/Pi-Somfy/operateShutters.py -c /home/pi/Pi-Somfy/operateShutters.conf \"Center\" -down || exit 0 &",
                "retryDelay": 500
            },
            "motion_time_graph": {
                "up": [
                    {
                        "pos": 100,
                        "seconds": 15.98
                    },
                    {
                        "pos": 0,
                        "seconds": 0
                    }
                ],
                "down": [
                    {
                        "pos": 0,
                        "seconds": 16.86
                    },
                    {
                        "pos": 100,
                        "seconds": 0
                    }
                ]
            },
            "stop_url": {
                "url": "file:// sudo python3 /home/pi/Pi-Somfy/operateShutters.py -c /home/pi/Pi-Somfy/operateShutters.conf \"Center\" -stop || exit 0 &",
                "retryDelay": 500
            },
            "response_lag_ms": 2360,
            "unique_serial": true,
            "verbose": true,
            "accessory": "BlindsHTTP"
        },

[Ryamonster10]

Actually after doing some more testing. What I’ve realized really matters is the time between the first message and the second. Why does this take so long? Over 10 seconds.

[dxdc]

@Ryamonster10 thanks for the debugging logs.

The problem seems pretty clear -- it looks like your cli command is not returning quickly enough. If you graph out the timestamps otherwise (see below, where 17:12:21 is considered the starting 00:00 time), it all looks as expectd.

From your logs, the down command takes 13 seconds (13121 ms) to return, and the stop command takes 2 seconds (2110 ms). Your lag timeout of 2.4s is pretty close to the 2.1s, so the issue seems like it is your down command.

There is no expectation from the plugin that your command will take so long to return. Any expectation of how long the command takes should be taken into account for the lag timeout, but it seems you have a lot of variability.

00:00	17:12:21	[06/01/2024, 17:12:21] [Center] Move request sent (13121 ms), waiting 8.4s (+ 2.4s response lag)...
00:00	17:12:21	[06/01/2024, 17:12:21] [Center] Stop command will be requested
00:02	17:12:23	[06/01/2024, 17:12:23] [Center] Timeout finished
00:08	17:12:29	[06/01/2024, 17:12:29] [Center] Requesting stop
00:10	17:12:31	[06/01/2024, 17:12:31] [Center] Command succeeded in 2110 ms
00:10	17:12:31	[06/01/2024, 17:12:31] [Center] Stdout: 
00:10	17:12:31	[06/01/2024, 17:12:31] [Center] Stop request sent
00:11	17:12:32	[06/01/2024, 17:12:32] [Center] End Move down to 50% (target 50%)

• Why is operateShutters.py taking 13 seconds to return? Or, does it only return once the actual movement is complete?

I would suggest fixing that first.

If it only returns once the movement is complete, try setting your motion time to 0. That means your cli tool is doing the calculation for you.

You can also try running it as a background command. That may not necessarily fix the problem, because the stop command will be called before this one finishes, but the way you're invoking the background command is not correct. Also, note that your up command is requesting a stop.

It should be like this:

"url": "file:// sudo python3 /home/pi/Pi-Somfy/operateShutters.py -c /home/pi/Pi-Somfy/operateShutters.conf \"Center\" -stop &",

not:

"url": "file:// sudo python3 /home/pi/Pi-Somfy/operateShutters.py -c /home/pi/Pi-Somfy/operateShutters.conf \"Center\" -stop || exit 0 &",