Task watchdog on ESP32 after a long receive stall: sync task starves the main loop while catching up

Aperta
  • Qualcosa non va?
#223 3 commenti 0 reazioni 0 assegnatari Vedi su GitHub

I maintainer di solito rispondono entro 1 giorno

@Boisti13 ci sta già lavorando.

Dal 3/11/2026.

  • #224 di @Boisti13 — aperta

Valutazione

Difficoltà
4/5
Tempo stimato
3-5 giorni
Idoneità per principianti
35/100
Tipo di issue
Bug
Chiarezza
Abbastanza chiara
Stato di attività
Ferma
Stack tecnologico
cpp
Ambito
audio-video-rtc, embedded-iot

Direzione di ricerca

Start with src/sync_task.cpp around SyncTask::process_playback_progress() and the inner loop in SyncTask::thread_entry(), then inspect src/platform/shadow_slot.h and decode_chunk()'s load-time skip behavior. Reproduce a long receive stall with ESP32 watchdog logging and determine whether backlog processing prevents lower-priority tasks from running. Done means a change prevents watchdog resets while preserving correct playback; linked PR #224 is already open.

Scritto dal modello di indicizzazione a partire dal testo della issue.

Descrizione

Summary

An ESP32 Sendspin player (ESPHome) gets restarted by the task watchdog on core 1 shortly after a long receive stall. The crashed task is SsSync. It looks like the sync task works through the backlog that arrives after the stall without blocking, and at its priority (6, above ESPHome's loopTask at 1) it starves the main loop past the 5 s task-watchdog timeout.

Setup

  • AI-Thinker ESP32-A1S audio kit (ESP32-WROVER, 8 MB PSRAM, ES8388), CPU at 240 MHz
  • ESPHome 2026.10.1, sendspin-cpp 0.9.3 (pulled in by ESPHome)
  • sendspin: task_stack_in_psram: false, media_source: - platform: sendspin, buffer_size: 2500000
  • I2S speaker, 48 kHz, buffer_duration: 100ms
  • Server: Music Assistant 2.10.8; Wi-Fi around -50 to -65 dBm, but the player regularly gets no data for 4–15 s

What happened (2026-11-03, local time)

  • 13:00:35 Music Assistant (aiosendspin) logs Slow send_bytes: 11581.6ms ... role=player
  • ~13:01:05 the player restarts: reset reason task watchdog
  • 13:01:10 server logs WebSocket closed, close_code=1006; the player is back at 13:01:14

Crash record:

Reason: Task wdt
Crashed core: 1
PC: 0x400D7EDA
BT: 0x400D7ED7 0x400D840D 0x400E6FBD 0x400F8A21 0x400F92A7 0x401BEB8B 0x401B0501 0x400D82B4

Decoded with the ELF of that exact build:

pthread_mutex_lock_internal            pthread.c:716
pthread_mutex_lock                     pthread.c:746
std::mutex::lock()                     std_mutex.h:113
sendspin::ShadowSlot<sendspin::PlaybackProgress>::take(...)   src/platform/shadow_slot.h:54
sendspin::SyncTask::process_playback_progress(...)            src/sync_task.cpp:879
sendspin::SyncTask::thread_entry(void*)                       src/sync_task.cpp:1035
std::thread ... execute_native_thread_routine / pthread_task_func

What I think is going on (not verified)

The program counter sits in the playback-progress mutex, which is most likely just where SsSync happened to be when the watchdog fired, not a deadlock: process_playback_progress() runs on every pass of the inner loop. The inner loop only blocks in take_item() (15 ms) when the inbound ring is empty, and in the sink write. After a long stall the ring refills quickly, so LOAD_CHUNK → (skip or decode) → SYNCHRONIZE_AUDIO → LOAD_CHUNK can run back to back. decode_chunk() does skip chunks that are late against new_audio_client_playtime before decoding them, but per #198 that estimate is stale after the sink starves, so after the stall the backlog may still be decoded (and then dropped or played late) rather than skipped. At priority 6 on the main loop's core, a few seconds of that is enough for the 5 s task watchdog. I haven't confirmed which branch the task was looping in.

An earlier variant on the same device (v0.7.0 of my firmware, stacks in PSRAM, 160 MHz) crashed the same way but with the PC in the protocol task's decryption during buffer refills; moving stacks to internal RAM and going to 240 MHz made that one go away.

https://github.com/esphome/esphome/issues/18789 looks like the same pattern on the same board (FLAC decode inside the sync task, task wdt, after Lost sync warnings on weak Wi-Fi).

#198 (in 0.9.4+) changes how the hard sync is measured after the sink starves; I have not tested whether it avoids the long late-drop run.

Possible fixes

  • Block briefly (e.g. vTaskDelay(1); std::this_thread::yield() doesn't help lower-priority tasks) after N inner-loop passes that didn't block, so the main loop gets CPU while a backlog is worked off.
  • Check whether #198's floored estimate also lets the load-time skip in decode_chunk() discard the post-stall backlog without decoding it (the PR deliberately keeps the unfloored estimate there).
  • Make the sync task priority configurable from ESPHome, or run it below the main loop when the core is shared.

Happy to test a build. This report was put together with the help of an AI assistant (Claude); the logs and backtrace are from the device.

Lingua principale
C++
Stelle
32
Fork
19
Merge medio
14h 54m
PR unite (30g)
49

Preparare l'ambiente

Come iniziare

  1. Leggi tutta la issue e poi la guida ai contributi del progetto.
  2. Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
  3. Fai un fork del repository e lavora su un branch.
  4. Apri una pull request che faccia riferimento al numero della issue.

Altre issue di Sendspin/sendspin-cpp

Tutte le issue di Sendspin/sendspin-cpp

Issue simili

Altre issue su C++

Ricevi le nuove issue nella tua casella

Un breve riepilogo di issue GitHub adatte ai principianti.