Fast successive commands lead to skipped TX

[wilriker]

Hardware

ESP32-C3

Firmware version

v2.4.7

Application version

v2.4.7

What happened? What did you expect to happen?

I have my setup connected to Home Assistant via your integration. And I have groups defined in HA (I know I could define them also in EPPSomfy-RTS but I don't want to do that).

Now when I e.g. click on close for the "All" group HA will send 11 down commands to ESPSomfy-RTS as fast as it can. Sometimes all 11 commands will be transmitted to the shades but about half of the time it will skip one of these. And by skip I mean that at least the shade does not move but ESPSomfy-RTS thinks it successfully sent the command since it does update the expected shade position.

I think I never saw it skip more than one. Also it's not always the same one that is skipped although most of the time it is one of the first elements in the group. But AFAICT these commands will be sent async so I'm not sure how predictable the order is.

It did work reliably when I was using my prototype ESP32 and only started to have this behavior when miniaturizing it with an ESP32-C3 Super Mini. My first suspect (based on #486) was that the voltage regulator on the C3 could not keep up with the fast successive transmissions leading to a brown out on the transceiver module. Thus I added a 100nF Low-ESR capacitor to the 3.3V rail. That did not help though so this either was not the problem at all or not all of the problem to solve.

It also works reliably when I trigger them one by one (thus implicitly adding a delay between commands).

Now I need some guidance on how to process with debugging this issue. What could I do here? Also: would it be feasable to add a global delay (configurable) between sending commands. I think even a small delay like 10-50ms would already solve my issue.

How to reproduce it (step by step)

1. Create group in HA with 10-15 shades
2. Send a command to this group
3. Not all shades actually move while HA "thinks" they all do move

Logs

########## Here I activated a Scene in HA setting 9/11 shades fully down and 2/11 in a specific position. These all went through #####
Sending Shade Command

Received:{"shadeId":1,"command":"down"}

CMD:Down ADDR:175483 RCODE:2792 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 165ms
Sending Shade Command

Received:{"shadeId":2,"target":54}

Moving to 54.00% from 0.00% using Down

CMD:Down ADDR:14128006 RCODE:91 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 157ms
Sending Shade Command

Received:{"shadeId":3,"command":"down"}

CMD:Down ADDR:15851207 RCODE:2831 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":4,"command":"down"}

CMD:Down ADDR:821976 RCODE:80 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 156ms
Sending Shade Command

Received:{"shadeId":5,"command":"down"}

CMD:Down ADDR:11584649 RCODE:52 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":7,"command":"down"}

CMD:Down ADDR:13040865 RCODE:53 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 168ms
Sending Shade Command

Received:{"shadeId":6,"command":"down"}

CMD:Down ADDR:5254515 RCODE:51 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 162ms
Sending Shade Command

Received:{"shadeId":11,"target":35}

Moving to 35.00% from 0.00% using Down

CMD:Down ADDR:2006435 RCODE:95 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 162ms
Sending Shade Command

Received:{"shadeId":10,"command":"down"}

CMD:Down ADDR:15935221 RCODE:51 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 162ms
Sending Shade Command

Received:{"shadeId":9,"command":"down"}

CMD:Down ADDR:1658754 RCODE:51 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 161ms
Sending Shade Command

Received:{"shadeId":8,"command":"down"}

CMD:Down ADDR:13252451 RCODE:51 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 222ms
CMD:My ADDR:14128006 RCODE:92 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing Somfy: 379ms
CMD:My ADDR:2006435 RCODE:96 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing Somfy: 144ms
########## Here I told HA to open all 11 shades again (for testing purposes) while some of them were still moving down #####
Sending Shade Command

Received:{"shadeId":5,"command":"up"}

CMD:Up ADDR:11584649 RCODE:53 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 166ms
Sending Shade Command

Received:{"shadeId":10,"command":"up"}

CMD:Up ADDR:15935221 RCODE:52 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":6,"command":"up"}

CMD:Up ADDR:5254515 RCODE:52 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 162ms
Sending Shade Command

Received:{"shadeId":7,"command":"up"}

CMD:Up ADDR:13040865 RCODE:54 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 164ms
Sending Shade Command

Received:{"shadeId":4,"command":"up"}

CMD:Up ADDR:821976 RCODE:81 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 168ms
Sending Shade Command

Received:{"shadeId":1,"command":"up"}

CMD:Up ADDR:175483 RCODE:2793 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":11,"command":"up"}

CMD:Up ADDR:2006435 RCODE:97 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 164ms
Sending Shade Command

Received:{"shadeId":8,"command":"up"}

CMD:Up ADDR:13252451 RCODE:52 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":2,"command":"up"}

CMD:Up ADDR:14128006 RCODE:93 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 157ms
Sending Shade Command

Received:{"shadeId":9,"command":"up"}

CMD:Up ADDR:1658754 RCODE:52 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 261ms

####### This one failed - interstingly last in the sequence #############
Sending Shade Command

Received:{"shadeId":3,"command":"up"}

CMD:Up ADDR:15851207 RCODE:2832 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 165ms
Timing Somfy: 101ms
Timing Somfy: 214ms

####### I had to pretend to move it down again so HA enables the up button (shade was still in closed position) #############
Sending Shade Command

Received:{"shadeId":3,"command":"down"}

CMD:Down ADDR:15851207 RCODE:2833 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 162ms
######## Now actually moving it up #####################
Sending Shade Command

Received:{"shadeId":3,"command":"up"}

CMD:Up ADDR:15851207 RCODE:2834 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 163ms

######## Here I enabled the scene again after all shades did move up and it worked  ##########
Sending Shade Command

Received:{"shadeId":1,"command":"down"}

CMD:Down ADDR:175483 RCODE:2794 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 169ms
Sending Shade Command

Received:{"shadeId":2,"target":54}

Moving to 54.00% from 0.00% using Down

CMD:Down ADDR:14128006 RCODE:94 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":3,"command":"down"}

CMD:Down ADDR:15851207 RCODE:2835 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 164ms
Sending Shade Command

Received:{"shadeId":4,"command":"down"}

CMD:Down ADDR:821976 RCODE:82 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 163ms
Sending Shade Command

Received:{"shadeId":6,"command":"down"}

CMD:Down ADDR:5254515 RCODE:53 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 165ms
Sending Shade Command

Received:{"shadeId":8,"command":"down"}

CMD:Down ADDR:13252451 RCODE:53 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 167ms
Sending Shade Command

Received:{"shadeId":7,"command":"down"}

CMD:Down ADDR:13040865 RCODE:55 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 164ms
Sending Shade Command

Received:{"shadeId":5,"command":"down"}

CMD:Down ADDR:11584649 RCODE:54 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 162ms
Sending Shade Command

Received:{"shadeId":11,"target":35}

Moving to 35.00% from 0.00% using Down

CMD:Down ADDR:2006435 RCODE:98 REPEAT:0

Enabled receive on Pin #2 Timing: 1
Timing WebServer: 164ms
Sending Shade Command

Received:{"shadeId":10,"command":"down"}

CMD:Down ADDR:15935221 RCODE:53 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 162ms
Sending Shade Command

Received:{"shadeId":9,"command":"down"}

CMD:Down ADDR:1658754 RCODE:53 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing WebServer: 195ms
CMD:My ADDR:14128006 RCODE:95 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing Somfy: 236ms
CMD:My ADDR:2006435 RCODE:99 REPEAT:0

Enabled receive on Pin #2 Timing: 0
Timing Somfy: 145ms
Timing Somfy: 210ms
Loading file /index.html

Timing WebServer: 172ms
Socket [1] Connected from 192.168.20.31 url: /
Initializing Socket Client 1
Max Heap: 86004

Free Heap: 148464

Min Heap: 92632

Timing WebServer: 470ms

[rstrouse]

The issue is not what it seems. Every command you sent went out on the radio. However, not every motor heard it even though it made it to the receiver on the motor. This is because not all motors recover at the same rate after decoding a frame. Every frame in the airwaves is decoded by every motor in the listening area. There is a cooling off period after each frame where most motors can keep up and process the next hardware sync. However, some are slow to start streaming bytes again. The solution to slow recovery are repeats. Simply increase the number of repeats until you get what you desire. Start with 1 and increase as needed.

I know you do not want to create groups in ESPSomfy RTS but this overcomes the limitations on the motors by reducing the number of frames on the airwaves. When grouped at the motor, a single frame is sent to command all members but this breaks down when you want to say set all to 54%. The speed of each motor is going to be different so these are broken into individual frames.

[wilriker]

Thanks for reminding me of the receiver cool down. That's stuff I knew about eight years ago when I built my first solution on pushstack's blog posts.

But that leaves me with the question: why did it work with not a single one of these "skips" when I ran it with a "normal" ESP32? Was that simply slower in responding to the HTTP requests and thus having a larger delay between the individual commands?

One reason I do not want to create groups is that I do not know how many remotes a motor can store. Currently each motor is paired with four remote addresses already. One of these is obsolete but I cannot unpair it since it died with my previous solution. Do you happen to know how many remotes a motor can store? I also have something in the back my head that this is a ring so newer ones would eventually overwrite the oldest ones. And the first two address are the physical remotes and I don't want to go through the process of running through the house and programming them again. ;-)

[rstrouse]

The S3 processor and WiFi buffers are faster. You were getting the benefit of the HTTP request delays adding to the cooldown on the DOWD chip. The built in cooldown on transmit is optimistic meaning it is set to nominal performance in around the half frame range. Adding a repeat frame will make sure that it sees the hardware sync followed by the software sync.

Most all motors allow for 12 stored addresses. However, I have seen more than one motor that was full of abandoned addresses that either came from the factory that way or the installer was goofing around with them before install. If you run into one you can simply factory reset it and pair it up again. If you have access to kill the power on it the process is easy. If not, then it gets a bit more complicated.

[rstrouse]

Also, in my experience the only motors that overwrite the first address are for the gate motors. All others are much more insidious in that they act like they paired successfully but they do not actually store the address. This may account for the recommendations from Somfy to factory reset the motor if you are having pairing problems.

[wilriker]

I went boldly and added each motor in three different groups to ESPSomfy-RTS and it seems that all motors are still happily accepting all physical remotes. :-) I also added a "Repeat 1 Time" to all individual shade controllers (I don't think I will need them for the groups as these are usually not triggered in short succession).

One thing I don't fully understand is what you wrote above:

When grouped at the motor, a single frame is sent to command all members but this breaks down when you want to say set all to 54%. The speed of each motor is going to be different so these are broken into individual frames.

Does that mean that when I say "Group 'Upstairs' to 54%"

1. it will start the movement for the full group but then will individually stop them at 54% or
2. it will break it down into individual commands from the start
3. or does "break down" mean "it will not work at all"? ;-)

One last question: instead of adding the repeat frames I would rather see an option to adjust the built in cooldown on transmit. Would that be an option for you to implement? Or point me at the right code location (I was searching myself already but could not find it easily), so I could start implementing it myself and bring up a PR?!

[rstrouse]

It will break it down into commands for the individual motors. It has to do this because some may need to go up and some may need to go down to get to 54%.

You are correct you will likely not need them for the groups but keep in mind it is very difficult to get only one frame sent when pressing the buttons on the remote and you will not notice a repeated frame overall.

[wilriker]

Yeah, once thinking about it for longer than a second I realized that it could not be No. 1 (except with very complicated code to detect what to use best).

The only thing I realized by now is that the shades commanded to move (from fully open) to an intermediate position actually stop a tad bit late (I happen to have a reference point to compare against) with repeated frames. But that might be a coincidence. Can recheck tonight.

I was again searching for that frame delay and I could not find it for regular commands. The only occurrence I found was when it will be pushed to tx_queue but that only happens for frames that were received from a repeater and then will be emitted locally again. This is beginning to drive me crazy. Can you point me to where you add that delay for any regular transmit, please? ;-)

[rstrouse]

Remember that the transceiver code executes on a single thread. It is not capable of sending our more than one frame at a time. So, the cool-down is baked into the sendFrame method as part of the silence on the radio.

ESPSomfy-RTS/Somfy.cpp

Line 4312 in eb75868

void Transceiver::sendFrame(byte *frame, uint8_t sync, uint8_t bitLength) {