Debugging Why StackChan Froze Mid-Blink on M5Stack CoreS3

In the previous post, I set up StackChan to read AI agent task completion notifications aloud.
After leaving it powered on at my desk, I noticed that its face had frozen with its eyes half-open.

The screen was stuck mid-blink, and it did not respond to commands sent over USB serial (serial communication over a USB cable). Rebooting brought it back, but network requests started failing completely after about 40 minutes, and even while idle the eyes visibly paused half-open during blinks.

Test Environment

Item	Environment Details
Device	M5Stack CoreS3 (ESP32-S3, 8 MB external PSRAM), StackChan body
Firmware	ESP-IDF 5.5.4 (ESP32 development framework), arduino-esp32 3.3.10
Voice Server	Voice chat server on a separate PC (setup post)
Log Capture	Python script on the PC reading USB serial with timestamps

Full hardware specifications are on the official M5Stack CoreS3 page. In this build, arduino-esp32 is compiled as an ESP-IDF component (a modular functional unit). StackChan connects to the voice server over Tailscale, using direct UDP when available and falling back to a DERP relay server otherwise.

Mid-Blink Freeze While Idle

The first freeze happened 2 hours and 40 minutes after boot. On ESP-IDF, the Arduino loop() function runs as one task on the FreeRTOS real-time operating system alongside background ESP-IDF tasks. Inside loop(), the firmware updates the face drawing and blinking while also reading the CO2 sensor and printing a log line once per minute. Those per-minute CO2 log lines had stopped, while Tailscale error logs from other ESP-IDF tasks kept printing over serial. Because loop() had stalled while the rest of the chip continued running, the mid-blink frame stayed on screen with the eyes half-open.

In the background, Tailscale was failing every 10 seconds to reconnect to the control server that distributes peer addresses and keys. The error was mbedtls_ssl_setup -0x7F00, the memory allocation failure code (MBEDTLS_ERR_SSL_ALLOC_FAILED) in the mbedTLS encryption library.

JTAG Connection Attempt on CoreS3

When the freeze happened, the PC serial logger script was not connected yet. The firmware already included a watchdog task that prints backtraces (records of which function each task is executing) for all tasks over serial if loop() stops advancing for more than 20 seconds, but it only printed once when the stall first triggered. Connecting the serial logger afterward showed only the ongoing Tailscale errors, not where loop() had stopped.
Because the CoreS3 has a built-in USB JTAG interface for halting the chip externally and inspecting memory and registers, I tried attaching to it while the unit was still frozen.

Running OpenOCD on Windows to talk to JTAG initially failed with libusb_open() failed LIBUSB_ERROR_NOT_FOUND. Although the standard Windows WinUSB driver was bound to the JTAG USB interface, the DeviceInterfaceGUIDs value was missing from the Windows registry. Adding that registry value as administrator allowed OpenOCD to open the device.

When I connected the GDB debugger, the CoreS3 immediately reset itself. With memory protection (CONFIG_ESP_SYSTEM_MEMPROT_FEATURE) enabled in the firmware, OpenOCD prints Memory protection is enabled. Reset target to disable it... upon GDB attachment and resets the target, wiping out the frozen state before I could inspect it.
In case it froze again later, I updated the watchdog task to re-print the backtrace every 60 seconds for as long as loop() remains stalled.

Moving mbedTLS Buffers to PSRAM

After the reboot, the direct UDP connection to the voice server dropped 40 minutes in. Tailscale tried to switch to a DERP relay server, but opening that TLS connection also failed with the same -0x7F00 error, and both voice uploads and notification checks began returning HTTP -1 (connection failed). Checking the voice server from my PC returned HTTP 200, so the server itself was running normally.

Although the ESP32-S3 on the CoreS3 has 8 MB of external PSRAM, ESP-IDF allocates Wi-Fi and mbedTLS buffers from the fast but small internal RAM by default. With this firmware’s settings, each TLS connection allocates a 16 KB receive buffer and a 4 KB transmit buffer to hold data temporarily, so repeated Tailscale reconnection attempts appear to have exhausted internal RAM. The ts_pubip task that checks the device’s public IP at boot had also been failing its TLS connection with the same error on every startup.

I added CONFIG_MBEDTLS_EXTERNAL_MEM_ALLOC=y to the sdkconfig configuration file so mbedTLS allocates its buffers from external PSRAM. After this change, free internal RAM stayed around 96 KB with a minimum since boot of 54 KB, and the ts_pubip connection error at startup stopped appearing.

Offloading Conversation and Idle HTTP Polling to Another Task

When I spoke to StackChan after that, its facial animation stuttered while waiting for a reply. Timing each step inside loop() during a conversation showed that HTTP polling (periodically asking the server whether the reply is ready) took 0.3 to 1.0 seconds per request, pausing loop() the entire time.
I created a separate FreeRTOS task for HTTP polling so loop() only pushes a request into a queue and picks up the result on a later pass, which stopped the stutter during conversations.

Even while sitting idle without anyone speaking to it, the eyes still paused briefly during blinks. I had added instrumentation that logs any step inside loop() taking 300 ms or longer, and the log showed repeated entries for notify_tick, which polls the server every 7 seconds for completed agent notifications.

16:14:05.156 slow: notify_tick 321 ms (chat=0 play=0)
16:14:12.890 slow: notify_tick 304 ms (chat=0 play=0)
16:14:41.538 slow: notify_tick 415 ms (chat=0 play=0)

Here chat=0 play=0 indicates that the device was idle, neither in a conversation nor playing audio. In the previous post I had shortened the HTTP timeout for notification polling to 1.5 seconds, but even normal responses took 0.3 to 0.4 seconds, so whenever a check overlapped with a blink, the face paused with eyes half-open for about 0.3 seconds.
Routing notification checks through the same background polling task eliminated notify_tick stalls over 0.3 seconds.

Breakdown of Time Spent in power_tick

Even after moving notification checks off loop(), other steps still occasionally stalled for 0.3 to 1.6 seconds. Across the log up to that point, the most frequent slow entry was power_tick, which runs M5Unified’s M5.update() (touch, button, and power-IC updates, logged as m5upd), reads the head touch sensor (head), checks the power button (btn), and updates the battery display (pow).

I split power_tick into individual measurements to see which part was taking the time.

21:13:16.954 power_tick: m5upd=104 head=352 btn=0 pow=0 ms
21:13:23.167 power_tick: m5upd=281 head=178 btn=0 pow=0 ms
21:15:05.225 power_tick: m5upd=328 head=2 btn=0 pow=0 ms

The slow part shifted between m5upd and head from one stall to the next, while btn and pow stayed at 0 ms. Both m5upd and head read sensor values over the internal I2C bus connecting the chips.

Tasks Using the CPU While loop() Stalled

The ESP32-S3 has two CPU cores, and FreeRTOS schedules tasks across them (loop() runs on Core 1). I enabled FreeRTOS run-time statistics in sdkconfig and called uxTaskGetSystemState() to record cumulative execution time per task.

CONFIG_FREERTOS_USE_TRACE_FACILITY=y
CONFIG_FREERTOS_VTASKLIST_INCLUDE_COREID=y
CONFIG_FREERTOS_GENERATE_RUN_TIME_STATS=y

At the start of each loop() iteration, the firmware snapshots every task’s cumulative run time, and if the iteration takes 0.3 seconds or longer, it prints the top five tasks by elapsed CPU time during that window.

21:31:19.752 slow: power_tick 489 ms (chat=0 play=0)
21:31:19.752 cpu: 491 ms: tiT(c-1 p18)=480 IDLE0(c0 p0)=456 ts_derp_rx(c-1 p5)=13 wifi(c0 p23)=13 motion_task(c0 p10)=12

In this log line, c is the pinned core (-1 means unpinned), p is the task priority (higher values take precedence), and the number after = is the execution time in milliseconds during that window. Out of the 491 ms stall, 480 ms went to tiT, the ESP-IDF lwIP TCP/IP stack task at priority 18. Because Tailscale’s WireGuard implementation hooks into lwIP as a virtual network interface, packet encryption and decryption also run inside tiT. The remaining tasks in the line are Core 0’s idle task IDLE0, Tailscale’s DERP relay receive task ts_derp_rx, the Wi-Fi driver task wifi, and the head-servo task motion_task.

Because uxTaskGetSystemState() does not break down execution time by core, I worked out which core tiT used by subtraction. During those 491 ms, Core 0 spent 456 ms in IDLE0 and 25 ms in the Core 0-pinned wifi and motion_task tasks. That leaves only about 10 ms on Core 0 for tiT, so almost all of its 480 ms appears to have executed on Core 1, where loop() runs.

In ESP-IDF, tiT has no core affinity by default (CONFIG_LWIP_TCPIP_TASK_AFFINITY_NO_AFFINITY). Whenever priority-18 tiT lands on Core 1, priority-1 loop() has to wait.

In 15 minutes of logs, power_tick reached 0.3 seconds or longer 18 times.

Task	Count	Stall Duration
tiT (lwIP)	17	0.30–0.57 s
ts_pubip (Tailscale public IP check)	1	0.61 s

Whenever loop() yielded Core 1 to wait for an I2C transfer inside power_tick, tiT took over Core 1. During the same 15 minutes, the initial CO2 sensor read after boot and one notification audio download also exceeded 0.3 seconds, with IDLE0 accounting for almost the entire wait while the CPU sat idle.

Pinning the lwIP Task to Core 0

Setting CONFIG_LWIP_TCPIP_TASK_AFFINITY_CPU0=y in sdkconfig pinned tiT to Core 0, which eliminated stalls caused by tiT.
Continuing to run the device still produced two pauses of 1.0 second and 1.5 seconds.

21:49:26.657 cpu: 1002 ms: ts_pubip(c-1 p4)=994 IDLE0(c0 p0)=653 tiT(c0 p18)=254 ...
21:50:19.641 cpu: 1462 ms: ts_ctrl(c-1 p5)=1450 IDLE0(c0 p0)=979 tiT(c0 p18)=328 ...

The top tasks were Tailscale’s public-IP check ts_pubip and control-server task ts_ctrl, both of which run cryptographic operations at priority 4 to 5 without core affinity. During the first stall, IDLE0 ran for 653 ms on Core 0, so most of ts_pubip’s 994 ms of CPU time also executed on Core 1.

A 22-Second Stall in loop()

Just as I was about to pin the Tailscale tasks to Core 0 as well, the face froze for 21.5 seconds. The serial log had a gap of the same length, and because the stall exceeded the 20-second threshold, the updated watchdog task printed a backtrace.

Converting the backtrace addresses for the loop() task (loopTask) into function names and line numbers with addr2line showed where it was waiting.

prvSendAcquireGeneric  esp_ringbuf/ringbuf.c:823
xRingbufferSend        esp_ringbuf/ringbuf.c:1058
HWCDC::write           arduino-esp32/cores/esp32/HWCDC.cpp:590
Print::printf          arduino-esp32/cores/esp32/Print.cpp:85
loop()                 main.cpp (line logging the CO2 reading once per minute)

On the CoreS3, Arduino’s Serial uses the ESP32-S3’s built-in USB serial peripheral (HWCDC in arduino-esp32), which writes outgoing bytes into a transmit ring buffer until the host PC reads them. In the backtrace, Serial.printf on the per-minute CO2 log line had called HWCDC::write and blocked waiting for buffer space. When the PC stops reading and the buffer fills up, HWCDC::write in arduino-esp32 3.3.10 retries in 100 ms steps up to 20 times, blocking for roughly 2 seconds per write.

Because loop() prints multiple log lines in a single pass, waiting nearly 2 seconds on each write added up to the 21.5-second iteration. The logger script was running on the PC at the time, and why the PC stopped reading USB serial for those 22 seconds remains unclear.

Non-Blocking USB Serial Writes and Tailscale Core Pinning

Before Serial.begin(), I set the transmit timeout to 0.

Serial.setTxTimeoutMs(0);
Serial.begin(115200);

With a timeout of 0, Serial discards new log bytes as soon as the transmit buffer is full. Previously, leaving the USB cable plugged into the PC with the logger script stopped meant nothing had the serial port open, which filled the buffer and stalled loop() the same way.

In the Tailscale component, tailscale_esp32.c, tailscale_derp.c, and tailscale_pubip.c spawn the tasks for ts_ctrl, DERP relay traffic, and ts_pubip. Because those files call xTaskCreate directly without a sdkconfig option for core affinity, I added a #define macro at the top of each file to redirect xTaskCreate to xTaskCreatePinnedToCore on Core 0.

#define xTaskCreate(fn, name, stack, arg, prio, handle) \
    xTaskCreatePinnedToCore(fn, name, stack, arg, prio, handle, 0)

Blink Stall Counts After the Fixes

Besides running at the start of loop(), power_tick also runs alongside blink and mouth updates while downloading audio or recording speech. The interval between power_tick executions therefore matches how long the face goes without a frame update.
To track stalls even when serial logs are discarded while the logger is stopped, I added the count of power_tick intervals reaching 0.3 seconds or longer during the past minute and the cumulative maximum interval since boot to the per-minute CO2 log line. The firmware resets that maximum at the end of setup() after boot initialization finishes.

During post-fix testing, the PC side again stopped reading USB serial for about five and a half minutes, leaving a truncated line in the log. When logging resumed, the cumulative maximum since boot was 0.68 seconds; because that peak is retained across minutes, the stall count during the unlogged window is at least 1. The first row of the table records the duration of a single power_tick call before the fixes, while the two rows after the fixes record the interval between power_tick executions.

Condition	Stalls ≥ 0.3 s	Maximum
Before fixes (15 min before pinning tiT)	18	0.61 s
After fixes, logger stopped for ~5 min	1 or more	0.68 s
After fixes, logger running for 8 min	0	0.23 s

During the 8 minutes with the logger running after the fixes, StackChan downloaded a notification audio clip that took 1.6 seconds end to end. Because blinking and power_tick continued updating during the download, the longest interval between power_tick executions was 0.23 seconds, with zero stalls of 0.3 seconds or longer.