Web interface drops out, pings work

[bscholer]

What happened?

The Issue

On two different ESP32's I have, I've been running into a bug where I'm unable to load the web interface. When I plug the devices in, I have no issue connecting to them for about 10-30s (although this time varies), but then it cuts out and I just get errors in my browser. Periodically (very roughly every 5-10 minutes), I'm able to reconnect to the devices for 10s or so. In all, it's just really intermittent connection issues.

What I've Tried

• My first thought was that the devices were crashing and rebooting, however, this is not the case as the light patterns continue uninterrupted.
• Next thought was that it was the internet connection, however, I'm able to ping the devices (even up to every 0.05s) very reliably with no issue. Additionally, audio-reactive UDP broadcast continues to work with no issue, both sending and receiving. One of these problematic devices is a QuinLED DigQuad with ethernet.
• I've been running into this same issue on the following versions (both plain, ethernet, and audio-reactive versions):
  • v0.13.3
  • v0.14.0
  • v0.15.0-b2
  • MoonModules v0.14.1-b30
• It seemed like this somewhat coincided with adding devices to Home Assistant, and when I removed the devices, it did seem to get a bit better (the devices would stay on for longer), however, the issue is still very present.
• Connecting from multiple computers, through the Android app, and through a quick Python script I wrote to make a GET request to the home page every 5s to more scientifically test this specific issue
• Watched network traffic with Wireshark, which shows a light amount of net traffic going to/from the devices

To Reproduce Bug

For me, this bug seems to happen on any new WLED devices, and I haven't been able to find a common thread between them. I have ~15 other WLED devices in my house on the same network that have been working well with no issues. These are mostly running v0.15.0-b2.

Expected Behavior

I should be able to connect to the devices continually with no interruption.

Install Method

Binary from WLED.me

What version of WLED?

v0.13.3, v0.14.0, v0.15.0-b2, MoonModules v0.14.1-b30

Which microcontroller/board are you seeing the problem on?

ESP32

Relevant log/trace output

No response

Anything else?

No response

Code of Conduct

• I agree to follow this project's Code of Conduct

[blazoncek]

Please upload a debug build and monitor serial connection.
Post debug output when you are not able to connect.
Please also consider lowering HA polling frequency or remove HA integration entirely.

[bscholer]

@blazoncek here is the binary with WLED_DEBUG enabled that I'm using.

Looking at the debug output, there doesn't seem to be anything out of the ordinary. Logs below.

These devices are no longer in Home Assistant, and aren't being polled by them. The issue occurs even when my Home Assistant VM is shut down.

esp32dev_audioreactive.bin.zip

Logs

Started capturing these, refreshed the page ~5 times or so every couple seconds, and then just before the last logs included below were printed, it stopped responding. It seems to have no idea that it's missing the requests.

--- Terminal on /dev/cu.usbserial-1140 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
---DEBUG INFO---
Runtime: 360240
Unix time: 360,241
Free heap: 171012
Wifi state: 3
State time: 0
NTP last sync: 999000000
Client IP: 192.168.1.222
Loops/sec: 492
Loop time[ms]: 24/166
UM time[ms]: 0/110
Strip time[ms]: 1/164
Segments: 7 -> 3336B
Modes: 4*187=748B
Data: 4*187=748B
Map: 2*0=0B
Buffer: 3*1068=3204B
send NTP
WS FileRead: /index.htm
Loop took 32ms.
Usermods took 0ms.
Strip took 31ms.
WS client disconnected.
Not-Found HTTP call:
URI: /skin.css
WS FileRead: /skin.css
Loop took 33ms.
Usermods took 0ms.
Strip took 10ms.
JSON buffer locked. (17)
JSON buffer size: 7907 for request: 6
JSON content length: 5302
JSON buffer released. (17)
Slow effects.
Slow strip.
Loop took 42ms.
Usermods took 0ms.
Strip took 40ms.
JSON buffer locked. (17)
JSON buffer size: 4801 for request: 8
JSON content length: 2184
JSON buffer released. (17)
Loop took 41ms.
Usermods took 0ms.
Strip took 11ms.
JSON buffer locked. (17)
JSON buffer size: 6214 for request: 3
JSON content length: 3639
JSON buffer released. (17)
Loop took 37ms.
Usermods took 20ms.
Strip took 11ms.
Not-Found HTTP call:
URI: /presets.json
WS FileRead: /presets.json
Loop took 109ms.
Usermods took 0ms.
Strip took 31ms.
WS FileRead: /index.htm
Slow effects.
Slow strip.
Loop took 40ms.
Usermods took 0ms.
Strip took 37ms.
Loop took 32ms.
Usermods took 0ms.
Strip took 12ms.
Not-Found HTTP call:
URI: /skin.css
WS FileRead: /skin.css
Slow strip.
Loop took 40ms.
Usermods took 0ms.
Strip took 40ms.
JSON buffer locked. (17)
JSON buffer size: 7907 for request: 6
JSON content length: 5302
JSON buffer released. (17)
Loop took 46ms.
Usermods took 1ms.
Strip took 12ms.
JSON buffer locked. (17)
JSON buffer size: 4801 for request: 8
JSON content length: 2184
JSON buffer released. (17)
Slow effects.
Slow strip.
Loop took 34ms.
Usermods took 0ms.
Strip took 34ms.
JSON buffer locked. (17)
JSON buffer size: 5852 for request: 3
JSON content length: 3327
JSON buffer released. (17)
Loop took 40ms.
Usermods took 1ms.
Strip took 11ms.
Not-Found HTTP call:
URI: /presets.json
WS FileRead: /presets.json
Slow effects.
Slow strip.
Loop took 160ms.
Usermods took 0ms.
Strip took 158ms.
Loop delayed more than 5ms.
WS client connected.
JSON buffer locked. (12)
JSON buffer size: 5659 for WS request (3327).
heap 168756
Sending WS data Slow strip.
Loop took 41ms.
Usermods took 1ms.
Strip took 40ms.
to a single client.
JSON buffer released. (12)
WS FileRead: /index.htm
Slow effects.
Slow strip.
Loop took 33ms.
Usermods took 1ms.
Strip took 30ms.
WS client disconnected.
Not-Found HTTP call:
URI: /skin.css
WS FileRead: /skin.css
Loop took 45ms.
Usermods took 0ms.
Strip took 41ms.
JSON buffer locked. (17)
JSON buffer size: 7907 for request: 6
JSON content length: 5302
JSON buffer released. (17)
Slow effects.
Slow strip.
Loop took 43ms.
Usermods took 0ms.
Strip took 41ms.
JSON buffer locked. (17)
JSON buffer size: 4801 for request: 8
JSON content length: 2184
JSON buffer released. (17)
Slow effects.
Slow strip.
Loop took 34ms.
Usermods took 0ms.
Strip took 33ms.
JSON buffer locked. (17)
JSON buffer size: 5852 for request: 3
JSON content length: 3327
JSON buffer released. (17)
Loop took 33ms.
Usermods took 0ms.
Strip took 11ms.
send NTP
Not-Found HTTP call:
URI: /presets.json
WS FileRead: /presets.json
Slow strip.
Loop took 161ms.
Usermods took 0ms.
Strip took 160ms.
Loop delayed more than 6ms.
WS client connected.
JSON buffer locked. (12)
JSON buffer size: 5659 for WS request (3327).
heap 168768
Sending WS data to a single client.
JSON buffer released. (12)
Loop took 43ms.
Usermods took 1ms.
Strip took 25ms.
send NTP

[blazoncek]

I don't see any NTP replies.

[softhack007]

... plus this

WS FileRead: /presets.json 
Slow strip. 
Loop took 161ms. 
Usermods took 0ms. 
Strip took 160ms. 
Loop delayed more than 6ms. 
WS client connected.

How may LEDs do you have? Which type are they ? What effect do you run? How many presets (roughly) do you have?

What kind of router? In case you have a FritzBox or Unify router, there are known (and unsolved) problems with connection loss and esp32 restarts.

[bscholer]

@softhack007 I had it configured for ~1500 WS2812b LEDs I believe, distributed fairly evenly across 3 pins. This had worked great for a while, but I started having problems with it at one point a while ago, not sure what caused it. My other controller similarly has ~2300 WS2812b LEDs across 4 pins.

In any case, I just reduced the first controller it down to only have 60 LEDs, and the problem persists. Logs still indicate Slow Strip. It is not actually plugged into any LEDs, and is just in the enclosure I designed for it, however, when I do plug in lights, it does not seem to make a difference.

I have an AT&T router. However, given that I'm able to ping it reliably every 0.05s while testing, and that it still is able to send audio data over UDP even when the web interface is down, this makes me think that it isn't internet related.

Additionally, I have around 15 other ESP32s in the house, all working with no issues. It wouldn't have something to do with the number of other WLED devices on the network, would it?

[willmmiles]

I've been chasing down internal issues in the web server library used by WLED, particularly as they apply to various forms of load or stress. If you're up for trying something adventurous, this is the first build that's passed my stress test script. It's a bit of a long shot, though - I can't say it's been thoroughly tested, and I haven't seen any pattern of failure similar to yours that ever recovers on its own (except by full on crashing and rebooting). That said, I've definitely been able to hang the web server on the release branch while still leaving ICMP and UDP working, and this build has all the fixes to prevent every flavor of that I've seen so far.

The base here is from the 0_15 branch, using the new v6.3.2 Arduino core, WLED debugging enabled, the audioreactive and autosave usermods, and beta builds of AsyncWebServer with a load limiting queue, plus fixes to the underlying AsyncTCP library to avoid some potential deadlocks under load, fix some races and ensure graceful handling of resource limits.

WLED_0.15.0-b3_esp32_new_ar_ws_queue.zip

[bscholer]

@willmmiles thanks! I think I may have solved the issue by not specifying a static IP address, but I need to test further. Reflashed and just connected it to Wi-Fi, and it has been super reliable.

Do you have a branch? I'd like to build a version with Ethernet if possible.

[willmmiles]

Not one that pulls all the pieces together as an integrated build, yet - it's a bit of a pain to patch the packaging metadata in 3 different projects to reference WIP branches. I can put something together tomorrow.

[bscholer]

@willmmiles no worries, I actually got both working by removing the static IP address, so I don't think I'll be able to test it.

@blazoncek any ideas why a static IP address appears to be causing this issue? Even the controller with 2300 LEDs is running like clockwork now with DHCP.

[blazoncek]

@bscholer ethernet is used from the core system. There is nothing particular to WLED.

[softhack007]

reminds me of some troubles that @troyhacks ran into when experimenting with W5500/SPI ethernet on -S3.

It could be that in newer framework versions, the "ARDUINO" ethernet events must be use, as the "old" SYSTEM event names did not trigger any more.

• SYSTEM_EVENT_ETH_CONNECTED --> ARDUINO_EVENT_ETH_CONNECTED
• SYSTEM_EVENT_ETH_DISCONNECTED --> ARDUINO_EVENT_ETH_DISCONNECTED
• SYSTEM_EVENT_ETH_START --> ARDUINO_EVENT_ETH_START, ARDUINO_EVENT_ETH_GOT_IP (and maybe ARDUINO_EVENT_WIFI_STA_GOT_IP)

[troyhacks]

@softhack007 Yeah, I'm chasing a similar bug where my ESP32 boards (not S3) with well-supported ethernet won't get an IP in IDF v4.x but they work fine with v3.x.

I hacked in my W5500 network manager code with the new events and I get more detail, but it still doesn't work (yet!):

Connected! IP address: 192.168.8.184 <-- this is the correct ethernet IP
Network Event: ARDUINO_EVENT_ETH_DISCONNECTED = ETH Disconnected. Forcing reconnect <-- why?!?!
Forcing reconnect.
Network Event: ARDUINO_EVENT_WIFI_STA_DISCONNECTED = No action
Network Event: ARDUINO_EVENT_WIFI_STA_STOP = No action
Network Event: ARDUINO_EVENT_WIFI_READY = No action
Network Event: ARDUINO_EVENT_WIFI_STA_START = No action
Access point disabled (init).
Connecting to Tarna / ********* ...
Network Event: ARDUINO_EVENT_WIFI_STA_DISCONNECTED = No action
Network Event: ARDUINO_EVENT_WIFI_STA_CONNECTED = No action
Network Event: ARDUINO_EVENT_WIFI_STA_GOT_IP = WiFi Connected. No ETH
Connected! IP address: 192.168.8.181 <-- this is the correct WiFi IP