[Q] _poll(): rx timeout 4

[judge2005]

Description

My application uses the SPP bluetooth classic profile, as well as running a web server using web sockets.
Occassionally I get these messages on the console:

[ 18343][D][AsyncTCP.cpp:1131] _poll(): rx timeout 4

With this platformio.ini file it doesn't matter, everything keeps working (which is an improvement over the me-no-dev
async stack, which would just become unresponsive to network traffic):

platform = espressif32 @ 6.9.0
board = esp32-pico-devkitm-2
framework = arduino
platform_packages = framework-arduinoespressif32 @ 3.20016.0

However I noticed you are going to be end-of-lifing this, so I tried using this config:

platform = https://github.com/pioarduino/platform-espressif32/releases/download/53.03.10/platform-espressif32.zip
board = esp32-pico-devkitm-2
framework = arduino

instead (i.e. ESP-IDF 5.3.2 and arduino-esp32 3.1.0), but this brings me back to the server becoming unresponsive. In fact mDNS also stops working, and I suspect sntp does too. SPP keeps working fine.

Link:
Well its a complicated application. It runs BT SPP, ASyncWebServer and web sockets so probably also needs a client to make it happen, so at this point if you have suggestions about how I might narrow down the issue, I don't mind getting my hands dirty.

Edit: The code for the entire application is here: https://github.com/judge2005/TimeFliesBridge/blob/main/src/main.cpp

Board
esp32-pico-devkitm-2

Stack trace

No stack trace, just an unresponsive network stack.

BTW, thanks for keeping this project going - at this point I wouldn't have anything that worked reliably if you hadn't.

[mathieucarbou]

Well its a complicated application. It runs BT SPP, ASyncWebServer and web sockets so probably also needs a client to make it happen, so at this point if you have suggestions about how I might narrow down the issue, I don't mind getting my hands dirty.

Hello @judge2005 ,

AsyncTCP and ESPAsyncWebServer in this org are used by really heavy duty apps that are doing websocket message push at a rate of 3 big messages (graphs points) per second. Plus, rest API calls.

Although we can support bugs related to the projects, we cannot spend time helping users improving or looking at their code for correctness / improvement.

Anyway, now, you should first switch your application to Arduino 3.1.1 with:

platform = https://github.com/pioarduino/platform-espressif32/releases/download/51.03.05/platform-espressif32.zip

and make sure your app runs with 3.1.1.

Try also to look at the console logs, put your logs in verbose mode, see if you have some deadlocks, a missing watchdiog, look for the recommended flags, make sure you use the right lib versions and repos, etc

[judge2005]

The release notes for 51.03.05 indicate it uses Arduino 3.0.5. stable indicates it uses 3.1.1, so I've configured a test project with that. This code initializes BT SPP, connects to WiFi and creates a web server. The server serves a large .html.gz file the FS partition, which opens a websocket back to the server and sends a message. This causes a message to be sent back to the browser.

If I hammer the refresh button in the browser I eventually get either the poll timeout above, or an ack timeout, and the server no longer accepts any request. Usually take 10 or 20 refreshes.

If I don't run BT SPP, I don't get any issues.
AsyncTest.zip

[mathieucarbou]

could it be a task priority issue, meaning that BT SPP has higher priority, and has also a lot of things to do, so it gets more allocated cpu than async_tcp task ? did you try to check the bt spp priority ? I see in the code that its priority is 24: xTaskCreatePinnedToCore(_spp_tx_task, "spp_tx", 4096, NULL, configMAX_PRIORITIES - 1, &_spp_task_handle, 0); so far more than async_tcp task which is 10 by default.

I thought about that because in an app, I am using ESPAsyncWS with AsyncUDP, which is called 3 times per second to send a udp packet. And it happens sometimes that the app is longer to load also and if I disable UDP sending, all goes back to normal. But in my case, UDP sending is more important than the app itself, so I leave it like that.

[judge2005]

Interesting - it never occurred to me to try to find what SPP was doing. Yes, that seems like a ridiculously high priority. OTH it is running in core 0 and I had pinned the asynctcp task to core 1. I did try bumping the asynctcp task priority to 24. At first that game me panics instead of lockups, but not consistently.

My actual app reproduces the issue much more reliably, however I have since discovered that if I drop the asynctcp stack size from the default to 4096, it becomes much more reliable - in fact I haven’t had a lockout since. So on the face of it this looks like a memory issue, but according to the stats page on my full app, I have plenty of heap, IRAM etc., the heap low water mark is also very high and largest block size also very large. So maybe it is a corruption issue and I have just moved it by reducing the stack size.

[vortigont]

as I remember esp32 does not work well with BT and WiFi enabled at the same time. Not sure if something has changed recently in this area?

[judge2005]

Yes, me too. I wrote another app several years ago that does Bluetooth audio and has a web interface. On that I could initialize both but only run one at a time. When I started to design this current app I saw articles about co-existence and people saying they could run both simultaneously so I thought I would try it and see. The upshot is that getting it all to be reliable has been tricky. I seem to have got there (see other comments above), but I’m not sure how fragile this solution will prove to be.

[judge2005]

The application is pretty stable now, however it will usually lose connectivity with about 24 hours. I usually get either the RX timeout in ASyncTCP, or sntp can. O longer contact a NTP server and some time after that I can no longer connect to the web server.

I note that the lwip and Bluetooth tasks both run on core 0. Lwip is configured for a priority of 17, while Bluetooth is configured for 23. Sadly I can’t change either of those things without building my own esp-idf, and I’m not convinced it would make any difference anyway. It’s a shame. It seems like lwip ought to be able to recover.

I also note that lwip is now built with locking to keep it thread safe - while I was playing with where I initialized my NTP client, I discovered that I had to claim/release lwip if I move the initialization to after the web server initialization, if I initialize my NTP client before then, I don’t have to claim/release the locks. I’m a little concerned that maybe ASyncTCP is deadlocking.

I really want this to work, but I’ve ordered a HC-05 module to offload the BT SPP.