Repository navigation
ESP32-S3: Watchdog timer expired running polling loop #9460
Description
Adafruit CircuitPython 9.1.1 on 2024-07-22; Adafruit-Qualia-S3-RGB666 with ESP32S3
Board ID:adafruit_qualia_s3_rgb666
I have a script to explore working with SSE. It «seems to» work. I can connect and disconnect browser sessions. However, if I then just leave it running with no connections, and come back later (maybe an hour), the app is frozen. ctrl+c in the serial window aborts and gives:
192.168.20.105 -- "GET /sse" 360 -- "200 OK" 101 -- 126ms
192.168.20.105 -- "GET /favicon.ico" 390 -- "404 Not Found" 90 -- 18ms
client ('192.168.20.105', 8332) went away: code 32
client ('192.168.20.108', 47266) went away: code 32
client ('192.168.20.108', 11392) went away: code 32
Adafruit CircuitPython 9.1.1 on 2024-07-22; Adafruit-Qualia-S3-RGB666 with ESP32S3
>>>
>>>
soft reboot
Auto-reload is off.
Running in safe mode! Not running saved code.
You are in safe mode because:
Internal watchdog timer expired.
Press reset to exit safe mode.
The first part of that is the final log messages while it was running. This has occurred several times with different versions of the code. Including (I think) the httpserver_sse.py example in the repo that I started from. I don't know if it it total run time, or total idle time that triggers this.
Adafruit CircuitPython 9.1.1 on 2024-07-22; Adafruit-Qualia-S3-RGB666 with ESP32S3
Board ID:adafruit_qualia_s3_rgb666
Here is code that 'almost' matches what produced the above log. Almost, because the sequence has been: run the script, do some testing, then edit the offline version. In this case, the edit was cleanup to remove some debug messages, tweak the remaining, then start working on a more full html file. Got called away for awhile, when returned, found it locked up. again. Some of those lockup resulted in CIRCUITPY becoming read only. I had to do the file system erase to get it back.
# SPDX-FileCopyrightText: 2024 H Phil Duby
# SPDX-License-Identifier: MIT
"""
HTTP Server with SSE request handling for ambient environment data
"""
from time import monotonic_ns
try:
# not used at runtime, useful for IDE and documentation
from typing import NoReturn, Dict, Tuple
except ImportError:
pass
import microcontroller #type:ignore
import socketpool #type:ignore
import wifi #type:ignore
from adafruit_httpserver import FileResponse, Request, Route, Server, SSEResponse, GET
class AmbientHTTPServer:
"""Serve ambient environment information to clients"""
def __init__(self):
print('Initializing server...') # TRACE
pool = socketpool.SocketPool(wifi.radio)
self.server = Server(pool, debug=True)
self.sse_response: Dict[Tuple[str, int], SSEResponse] = {}
self.next_event_time_ns = monotonic_ns()
self.setup_routes()
def client(self, request: Request) -> FileResponse:
"""Return HTML page that initiates SSE communication"""
print(f'Serving HTML to {request.client_address}') # DEBUG
return FileResponse(request, 'index.html', '/client')
def sse_client(self, request: Request) -> SSEResponse:
"""Establish SSE communication with client"""
if request.client_address in self.sse_response:
raise NameError(f'Client {request.client_address} already connected')
print(f'Connecting client {request.client_address}') # DEBUG
response = SSEResponse(request)
self.sse_response[request.client_address] = response
print(f'SSE response created for {request.client_address}') # DEBUG
return response
def setup_routes(self) -> None:
"""Create web server routes for application"""
self.server.add_routes([
Route('/client', GET, self.client),
Route('/sse', GET, self.sse_client)
])
def send_event_to_clients(self) -> None:
"""Send fresh data to all connected SSE clients"""
if self.sse_response and self.next_event_time_ns < monotonic_ns():
cpu_temp = round(microcontroller.cpu.temperature, 2)
for client_id, client in list(self.sse_response.items()):
# print(f'Sending event {cpu_temp} to client {client_id} for {client._request}') # DEBUG pylint:disable=protected-access
try:
client.send_event(str(cpu_temp)) # send data to client
except BrokenPipeError as be:
print(f'Client {client_id} disconnected: code {be}')
del self.sse_response[client_id]
self.next_event_time_ns = monotonic_ns() + 1000000000 # 1 second
def start(self) -> NoReturn:
"""Start the application web server"""
self.server.start(str(wifi.radio.ipv4_address))
# Except: RuntimeError: Cannot start server on None:5000
# Except: gaierror: (-2, 'Name or service not known')
while True:
self.server.poll() # watch for new connection or page requests
self.send_event_to_clients()
if __name__ == "__main__":
instance = AmbientHTTPServer()
print('Server instantiated') # TRACE
instance.start()When it locks up, the only thing it is doing is polling, because self.sse_response is empty.
The index.html file referenced is:
<html lang="en">
<head>
<title>Server-Sent Events Client</title>
</head>
<body>
<p>CPU temperature: <strong>-</strong>°C</p>
<script>
const eventSource = new EventSource('/sse');
const cpuTemp = document.querySelector('strong');
eventSource.onmessage = event => cpuTemp.textContent = event.data;
eventSource.onerror = error => cpuTemp.textContent = error;
</script>
</body>
</html>I'm not setup to create a debug version of circuitpython, but with a little guidance, I probably could add some logging (with timestamps) to a local copy of HTTPServer.Server
Activity
michalpokusa commentedon Jul 25, 2024
I think I can help with logging inside the library, I authored most of the code.
Although it seems to me like the issue might be in CircuitPython itself rather than the library.
dhalbert commentedon Jul 25, 2024
This is almost certainly a core CircuitPython. I am transferring this issue to the circuitpython repo.
[-]Watchdog timer expired running polling loop[/-][+]ESP32-S3: Watchdog timer expired running polling loop[/+]mMerlin commentedon Jul 25, 2024
Can I help tracking it down? I don't know what it will take to reliably reproduce the failure. I'm a programmer, but not really set up to do debug builds. Main environment is Fedora. I can spin up a VM if other environment (not Windows or Mac) is better for building.
Any idea how long the watchdog timer is? Knowing that I would have an idea about how long to wait before checking if it had triggered. Assuming that it needs 'idle' time to trigger it.
dhalbert commentedon Jul 25, 2024
The "internal watchdog timer" that was triggered happens because something was taking far too long, blocking other operations (for example, a tight infinite loop). It reflects a bug, not just a timeout that's too short.
If you can reduce your program to the smallest example that still shows the problem, that would be great. We'll have to let it sit for a while to trigger the error, it seems like.
mMerlin commentedon Jul 28, 2024
I did some more testing. I have sample code that reliably triggers a non-responsive httpserver, and most of the time safe mode on restart. My initial pointer to .poll() is back in the mix. I tried a couple of variations. When I use server.server_forever(…), I do not see the failures. Change that do start plus while True and server.poll() triggers the problem. Idle time is also part of the mix. If I do a fresh request every 5 minutes, the error does not trigger … until I leave it idle for about 15 minutes.
Smaller code fails, but this keeps enough instrumentation/logging to match events (when it is still working).
log and browser capture using serve_forever
log and browser capture using poll, 20 minute request interval
log and browser capture using poll, «initial» 5 minute request interval
mMerlin commentedon Jul 29, 2024
It appears that this is not going to affect the project that it was initially encountered in. The problem was seen when doing development and testing of separate sections. With everything (so far) merged together, there is no 'idle time' that is needed to trigger the failure. The project shows the sensor data both on a local display, and on web pages. It seems that the processing needed for the display portion is enough to prevent the watchdog timeout seen in server.poll(). Even with the web server totally idle (no active connections).
Which means that some sort of heartbeat may be a work around. That also could mean that figuring out just what that heartbeat needs could point to where the watchdog is being triggered.
michalpokusa commentedon Jul 29, 2024
Possibly related #9428
Code from this issue also uses
adafruit_httpservermMerlin commentedon Jul 29, 2024
Reading over the code provided in that, this does look like exactly the same case: CP 9.1.1, ESP32-S3, server.poll() that is idle 'long enough', watchdog timer. Smaller code sample here, which could be shrunk further if logging not useful.
1 remaining item
mMerlin commentedon Jul 29, 2024
Here is a bit smaller sketch that can produce the same symptoms. Note that the first cycle had the server stop responding, but on control C abort and control D reload, it restarted successfully. That restart also did not stop responding after a 16 minute idle period, then a 22 minute idle period. It did not respond after a following 27 minute idle period, and the following forced abort and restart showed the watchdog timer expired problem. For most of my previous testing 15 minutes idle time was sufficient to trigger the watchdog timer.
dave4jr commentedon Aug 21, 2024
@mMerlin I'm experiencing the same issue. ESP32-S3 Feather TFT REV, CP 9.1.1.. Basically just connecting to wifi in beginning of script and reading the voltage on A4 inside of a while loop. I go into safemode from the same watchdog timer expiration error after about 20min.
jepler commentedon Aug 29, 2024
I reproduced this once on an Adafruit Feather ESP32-S3 TFT and 9.2.0-alpha.2351-7-g19e5cf3d8f using a very simple test program that eliminates
adafruit_httpserver:I ran this test without even being connected to wifi, and it's also a slightly dubious program because it did not
binda specific port. I paste this into the repl using paste mode. I saw this safe-mode-reset after less than 5 minutes on the first run, but now I haven't seen it again for ~10 minutes:I'm a little conflicted about posting this info since I only saw a WDT reset once -- there may be some other hidden variable. but I think it's good info that MAYBE this simple script is actually a reproducer.
jepler commentedon Aug 29, 2024
I did eventually get a 2nd crash with just about the same code. However, this time it was a Hard fault. That run took almost 1 hour to crash.
Details
jepler commentedon Aug 30, 2024
I didn't find any further useful information during today's debugging session, and I'm not planning to work further on this issue right now.
tannewt commentedon Sep 12, 2024
Moved to 9.x.x because we need a clearer reproducer to debug.
dhalbert commentedon Jun 24, 2026
I tried reproducing the test program in #9460 (comment) on 10.3.0-alpha.3. I tried fetches every 5 minutes and every 1000 seconds (16.67 minutes), and could not reproduce the crash.
Since this is a really old issue, I'm going to close this for now. If you are still seeing this, could you open a new issuer with a reproducer? Thanks.