Slow websockets with Windows client

[mcspr]

Thinking about 9f817ae / #896
optimistic_yield() did not do what I assumed it did - it just yields if loop spent more time that time value it is given (in usec).

Doing some testing with new ESPAsyncWebServer I got hit with queueing problem. As of me-no-dev/ESPAsyncWebServer@bed4146 queue limit for ws messages is 8, so messages dropped after some point.

Config difference from baseline

pio platform feature/stage (see #1260 for ldscripts generator)
esp8266/Arduino@5493552 / 2.4.2-85-ge5493552 / lwip2 high bandwidth
https://github.com/me-no-dev/ESPAsyncTCP#7e9ed22
https://github.com/me-no-dev/ESPAsyncWebServer#bed4146

#define DEBUG_ESP_WIFI 1 // debug.ino setup calls .setDebugOutput(true);
#define WIFI_SLEEP_MODE WIFI_LIGHT_SLEEP // no difference NONE / MODEM
#define ALEXA_SUPPORT 0         // to avoid network activity besides asyncwebserver
#define NTP_SUPPORT 0           // ^
#define SCHEDULER_SUPPORT 0     // ^
#define HOMEASSISTANT_SUPPORT 0 // ^
#define MQTT_SUPPORT 0          // ^

For example, using `keys`. `AsyncWebSocket.cpp` sections with os_printf / ets_printf are commented out. Console output is filled with queue errors after some point and simple yield does not really help here as message objects are not yet purged.

[159104] [WEBSOCKET] Requested action: dbgcmd
M: 51
W: 0 51
---> client->send() 51 bytes
S: 51 51
[159113] Current settings:
M: 32
[159115] > adminPass => "fibonacci"
M: 43
[159118] > alexaEnabled => "0"
M: 38
[159120] > board => "2"
M: 31
[159122] > boardName => "NODEMCU_LOLIN"
M: 47
[159124] > btnGPIO0 => "0"
M: 34
[159126] > btnRelay0 => "0"
M: 35
[159128] > cfg => "3"
M: 29
[159130] > dns0 => "10.0.0.1"
M: 39
ERROR: Too many messages queued
[159133] > gw0 => "10.0.0.1"
M: 40
ERROR: Too many messages queued
[159139] > hostname => "ESPURNA-35A259"
M: 47
ERROR: Too many messages queued
[159146] > ip0 => "10.0.0.2"
M: 40
ERROR: TA: 53
W: 0 32
---> client->send() 32 bytes
S: 32 32
...etc...

*edit: original assumptions about delay, formatting*

[mcspr]

So I had done second pass at testing this (+ reverting 9f817ae), and it looks like this mostly affects Windows. For example, using Linux machine / Android phone throughput is much higher and filling of ws queue does not happen as quick. Debug works okayish, but messages are still lost. Notable offender is _wsStart(), sending data right from the ws event.

What I'll try is to defer them until loop and add additional functions to the client, so it knows when initial config is not sent and what modules to expect at all (and re-request some if they did not arrive on connect)

As for Windows issue, see: esp8266/Arduino#1577

[mcspr]

Adding to that, using ets_printf() actually slows everything down enough so .send() happens before queue fills up 🤕 Accidentally almost becoming yield.

Regarding delay, info memory consumption is notably less when using delay(0) instead of just optimistic_yield() (~2000byte data, mem is twice that + some). notably slower too, adding 6ms to every debugSend call instead of usual ~1-2ms.

[tve]

Is there no way you can generate the data in the async callbacks of AsyncWebSocket?
In my experience with esp8266 TCP issues windows is worse at ACKing packets promptly than linux, but if your wifi is marginal then they can all suck. The wifi AP and any powersave settings can add to the fun. So unless you generate data in callbacks or have buffering for everything up-front you always risk overflowing. It's a PITA. BTW, I tend to use the low-memory version of LwIP (MSS of 536) 'cause it uses less memory so I can explicitly buffer more...

[mcspr]

Is there no way you can generate the data in the async callbacks of AsyncWebSocket?

Can you elaborate please? I am blanking here.

It sure does eat a lot memory with Windows when using current builds even when using OK WiFi, without sleep mode. Queue being unlimited adds to that and flashstrings malloc'ed twice in a row too.

I will try low-mem lwip version + buffer, that seems like a obvious way to avoid Windows assumptions about acking and allow sending more data. I wonder if cpu speed will affect this too.

edit: As a start, testing sending out _wsStart data in response to client's message seems successful.
e.g. have no _wsStart and adding this in wsParse:

    if (root.containsKey("callback")) {
        const uint8_t i = root.get<uint8_t>("callback");
        if (i >= _ws_on_send_callbacks.size()) return;
        wsSend(client_id, _ws_on_send_callbacks[i]);
        return;
    }

Then, client sends out batch of requests:

callback_size.forEach((_, n) => websock.send(JSON.stringify({"callback": n})))

Two Win10 clients with and without ACK delay fix (from issue mentioned above) work fine.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[mcspr]

Immediate issue fixed.
Next TODO:
fix-up ESPAsyncWebServer, avoid locking ws buffer queue
implement delivery status for each wsSend call, avoid thinking about ack's altogether (drop workaround).

[zhivko]

Can you ceate pull request to ESPAsyncWebServer? I see similar issues.