Skip to content

Let the 30-pin ESP32 start the radio for an audio recording - #198

Open
MacNite wants to merge 4 commits into
mainfrom
claude/user-report-investigation-183wqn
Open

MacNite wants to merge 4 commits into
mainfrom
claude/user-report-investigation-183wqn

Conversation

@MacNite

@MacNite MacNite commented Sep 18, 2026 •

Copy link
Copy Markdown
Owner

The report

A field report on 0.30.4 had every record_audio command fail on a 30-pin ESP32 hub, while the same firmware and the same hive recorded fine on an ESP32-C6:

[CMD] Received command 66: record_audio
[HEAP] audio-start: free=91296 largest=63476 min_ever=28084
E NimBLEDevice: esp_nimble_hci_init() failed; err=257
[BLE] stack failed to start (no memory for the controller?)
[HI-AUD] BLE stack would not start ... (free heap 16284, largest block 13812)
...
[HEAP] cycle-end: free=71584 largest=34804 min_ever=1456

err=257 is ESP_ERR_NO_MEM. The node was never contacted, so nothing here is HiveInside's.

Two numbers at the end matter more than the failed recording. ~20 kB never came back (91 kB at audio-start, 71 kB at cycle-end with everything torn down), and the cycle's minimum free heap was 1456 bytes — the command-result POST and the OTA check that follow each open a fresh TLS session on that. The failed recording is the harmless half of this.

What changed

The relay asked for the radio last. Three large allocations have to coexist for a recording — the BT controller, the TLS session, and the staging ring — and only the controller can neither shrink to fit nor be retried. It was bidding behind an open TLS session and the 4 kB upload buffer: of the 91 kB at audio-start, 75 kB had gone before it was asked. A new gattaudio::acquireRadio(), split out of begin(), now runs before the TLS connect, so the order is controller → TLS → ring: hardest constraint to softest, and the ring already halves itself down to 8 KiB to fit.

Only the stack moved. The scan and connect stay below the socket. HiveInside disconnects a connection that has not claimed a service within HIVE_LINK_ARM_TIMEOUT_MS (10 s, link.c), and only the START write cancels that timer — hoisting the connect as well would have spent that window on a TLS handshake whose own budget is 15 s, trading an out-of-memory failure for a mysterious disconnect. Connect-to-START is as tight as it always was.

A failed init stranded its memory. NimBLEDevice::init() brings the IDF controller up before it reaches the host, so a host-layer failure returns false with the controller still holding its allocation — and nothing unwound it: NimBLEDevice::deinit() guards on a flag the failed init never set, and blestack::release() early-returns on s_up. acquire() now unwinds it by hand, guarded on esp_bt_controller_get_status(). Deliberately not esp_bt_controller_mem_release(), which would take BLE away for good and leave the next cycle's measurement scan with no radio.

The mic's I2S channel was held all cycle. shutdownMicsI2s() ran only in the deep-sleep prep — which is why [INMP441] I2S uninstalled prints after [SLEEP] in the report. That is 8 kB of DMA-capable internal RAM, the memory the BT controller wants, resident through the TLS handshake and the BLE init, on top of a heap the 2048-point double-precision FFT has just fragmented (91 kB free, but only 63 kB of it in one piece). It is released as soon as the samples are read; the call in storage_power.cpp stays as a no-op.

Why the C6 never showed it

Three of the four differences are build config, not silicon:

  • config.h forces ENABLE_INMP441_MICS off on the C6, so it pays for neither the DMA buffers nor the FFT's fragmentation.
  • platformio.ini asks esp32dev for 48 NimBLE msys blocks where the C6 takes 24 from its own sdkconfig — and the pool was raised precisely because the classic ESP32 is dual-core and its NimBLE host task competes with the WiFi driver for core 0.
  • The C6 has more, less divided DRAM and a BLE-only rather than dual-mode controller.

MSYS1_BLOCK_COUNT is left at 48 on purpose: lowering it would reintroduce the 0.30.2 seams. It is the knob to trade only if the three fixes above turn out not to buy enough headroom.

Verification

Built all three configurations locally with the pinned toolchain. No warnings in any changed file (the only warnings are pre-existing ones in Adafruit's INA219):

Build Result Flash
esp32dev (default) SUCCESS 85.3%
esp32dev with ENABLE_INMP441_MICS=1 SUCCESS 86.9%
xiao_esp32c6 SUCCESS 90.9%

The mic-enabled build is the only one that compiles the sensors.cpp change, since the default config has ENABLE_INMP441_MICS 0.

Not verified: whether a 30-pin hub now completes a recording — that needs the reporter's hardware. On 0.30.6, [HI-AUD] session started in place of BLE stack would not start is the confirmation, and min_ever at cycle-end should no longer collapse toward zero even if the recording still fails for another reason.

Also in this PR

  • Firmware version bumped to 0.30.6.
  • docs/audio-recording.md: new "Why this is a 30-pin ESP32 problem" section; the "BLE stack would not start" troubleshooting row now points at it.

Update: failure reporting (0.30.8, e85e9db)

Field test of 0.30.7: the TLS error is gone, but the recording now ends as "the hub started uploading but no audio arrived", and the backend logs a ClientDisconnect traceback. Traefik shows the hub closing the upload after 207 ms (499). The BLE session most likely failed to start straight after the socket opened. The hub's single command-result POST then evidently failed as well, so the 5-minute sweep's generic message replaced the real reason.

This commit does not make audio work on the 30-pin board. It makes the failure visible, so the memory fix can be chosen from real numbers:

  • Server: stream_recording handles the hub disconnecting early. It stores the bytes that arrived and logs one warning instead of a traceback. A failed command result that arrives after the sweep now replaces the sweep's message (never a /finalize verdict).
  • Firmware: the audio result POST is retried once. If the retry also fails, the result is held in RTC memory and delivered on the next cycle (at most 3 tries). A session that fails to start now carries [heap free …, largest …, min …] in its message.
  • Tests: added regression checks for the disconnect and for the late result. The server suite and firmware host tests pass, and esp32dev and xiao_esp32c6 build.
  • Next: flash 0.30.8 on the 30-pin hub, run a recording, and read the reason and heap numbers from the dashboard.

🤖 Generated with Claude Code

https://claude.ai/code/session_01Jj45DVh6TKdwJ5LyYawqQx


Generated by Claude Code

A field report on 0.30.4 had every record_audio command fail on a classic
ESP32 hub, while the same firmware and the same hive recorded fine on a C6:

    [HEAP] audio-start: free=91296 largest=63476 min_ever=28084
    E NimBLEDevice: esp_nimble_hci_init() failed; err=257
    [HI-AUD] BLE stack would not start ... (free heap 16284, largest 13812)

err=257 is ESP_ERR_NO_MEM. Three things are wrong here, and the failed
recording is the least of them.

The relay asked for the radio LAST. Three large allocations have to coexist
for a recording — the BT controller, the TLS session and the staging ring —
and only the controller can neither shrink to fit nor be retried. It was
bidding behind an open TLS session and the 4 kB upload buffer, on whatever
they left: 75 kB of the 91 kB had gone before it was asked. It now goes
first, via a new gattaudio::acquireRadio() split out of begin(), and the two
that can bend take what is left (the ring already halves itself to 8 KiB).

Only the STACK moves. The scan and the connect stay below the socket because
HiveInside disconnects a connection that has not claimed a service within
HIVE_LINK_ARM_TIMEOUT_MS (10 s, link.c), and only the START write cancels
that timer; hoisting the connect as well would have spent that window on a
TLS handshake whose own budget is 15 s, trading an out-of-memory failure for
a mysterious disconnect. Connect-to-START is as tight as it always was.

A failed init also stranded its memory. NimBLEDevice::init() brings the IDF
controller up before it reaches the host, so a host-layer failure returns
false with the controller still holding its allocation, and nothing unwound
it: NimBLEDevice::deinit() guards on a flag the failed init never set, and
blestack::release() early-returns on s_up. In the log above that cost ~20 kB
for the rest of the cycle (91 kB at audio-start, 71 kB at cycle-end with
everything torn down) and took the cycle's minimum free heap to 1456 bytes —
the command-result POST and the OTA check that follow each open a fresh TLS
session on that. acquire() now unwinds the controller by hand, guarded on
its actual state. Not mem_release(): that would take BLE away for good and
the next cycle's measurement scan would find no radio.

The mic's I2S channel was held all cycle. shutdownMicsI2s() ran only in the
deep-sleep prep, which is why "[INMP441] I2S uninstalled" prints after
"[SLEEP]" in the report. That is 8 kB of DMA-capable internal RAM — the
memory the BT controller wants — resident through the TLS handshake and the
BLE init, on top of a heap the 2048-point double-precision FFT has just
fragmented (91 kB free but only 63 kB in one piece). It is released as soon
as the samples are read; the call in storage_power.cpp stays as a no-op.

Why the C6 never showed it: config.h forces ENABLE_INMP441_MICS off there,
so it pays for neither the DMA buffers nor the FFT's fragmentation; it takes
24 NimBLE msys blocks from its own sdkconfig where platformio.ini asks
esp32dev for 48; and it has more, less divided DRAM and a BLE-only rather
than dual-mode controller. MSYS1_BLOCK_COUNT is left at 48 deliberately —
lowering it would reintroduce the 0.30.2 seams, and it should only be traded
if the three fixes above turn out not to buy enough headroom.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Jj45DVh6TKdwJ5LyYawqQx
…tead

0.30.6 reordered the audio relay to ask for the BLE stack BEFORE opening its
upload socket, on the reasoning that the BT controller is the one allocation
on that path which can neither shrink to fit nor be retried, so it should get
first refusal. A 30-pin hub in the field disproved that in one cycle:

    id | relay_duration  | message
    76 | 00:00:01.281127 | TLS connect to the backend failed

1.28 s from claimed_at to completed_at, against a 15 s connect timeout — and
that window also contains a SUCCESSFUL TLS handshake to the same host, the one
that reported the failure after cleanup() released the radio. So the failed
connect consumed essentially no time at all: an allocation that gave up before
it reached the network, not a slow link, not coexistence, not DNS.

The radio fix worked. It just moved the failure to the other side.

The mis-ranking was about WHICH constraint binds. The controller needs a large
total in many pieces. mbedtls needs CONTIGUITY, and this framework asks for a
lot of it: CONFIG_MBEDTLS_SSL_MAX_CONTENT_LEN is 16384 with
CONFIG_MBEDTLS_ASYMMETRIC_CONTENT_LEN unset, so a session wants two 16 kB
contiguous record buffers and neither may be the small one. Contiguity is the
first thing fragmentation destroys, so whichever of the two goes second,
mbedtls suffers far worse for it. The original 0.30.4 log had already said so
and nobody read it that way: once the controller took its share, `largest` had
collapsed to 13812 — under one record buffer.

So the socket goes first again, the controller takes what is left, and the ring
stays last as the only one of the three that can shrink and still produce a
recording. relayAudioSession() and begin() are back to their pre-0.30.6 control
flow; the long comments at both sites record the evidence so this is not
rediscovered by reordering it a third time.

Both allocations still have to fit, which is a matter of lowering the peak
rather than reordering it. Two things do that, and the first was already
right in 0.30.6:

  * the mic I2S channel is freed at the measurement instead of at deep sleep
    (~8 kB of DMA-capable internal RAM, esp32dev only) — unchanged here;
  * CONFIG_BT_NIMBLE_MSYS1_BLOCK_COUNT on esp32dev goes 48 -> 24, giving back
    ~6 kB. That reverses part of 0.30.2, whose note read "costs 12 kB of heap
    while the stack is up, on a board with ~260 kB free" — true at boot, and
    badly wrong at the moment that matters, where the same hub is at ~91 kB
    with a 63 kB largest block. Seams in a recording beat no recording. 24 is
    still twice NimBLE's own default and matches what the C6 takes from its
    sdkconfig, and the other two causes of the 0.30.2 seams (three TLS records
    per chunk, a ring that could not absorb a stalled write) were fixed in
    code and are untouched.

The 0.30.6 failure had to be diagnosed from backend command timestamps because
the firmware printed no number anywhere on that path. Fixed:

  * "[HEAP] audio-radio-up" logs free/largest/min_ever with BOTH the TLS
    session and the controller resident — the reading every question here
    turns out to need;
  * the "TLS connect to the backend failed" line now carries free heap and
    largest block, so a repeat is legible from a serial log alone.

Kept from 0.30.6 unchanged: the failed-init unwind in blestack::acquire(),
which is what stopped ~20 kB stranding for the rest of the cycle and the
minimum free heap reaching 1456 bytes.

Built clean on esp32dev (default and with ENABLE_INMP441_MICS=1) and on
xiao_esp32c6.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Jj45DVh6TKdwJ5LyYawqQx
Field test of 0.30.7 on a 30-pin ESP32: the recording ended as "the hub
started uploading but no audio arrived", and the backend logged an
unhandled ClientDisconnect traceback. Traefik shows the upload POST closed
by the hub after 207 ms (499): the BLE session failed to start straight
after the socket opened, the hub closed the body and left, and its single
command-result POST evidently failed on the exhausted heap too. With no
result, the five-minute sweep wrote its generic message and the real
reason was lost. This does not make audio work on that board; it makes
the failure visible so the memory problem can be fixed from real numbers.

Server:
- stream_recording catches ClientDisconnect, still stores the bytes that
  arrived, and logs one warning. Behind Traefik even a complete body
  arrives this way when the hub does not wait for the response. The row's
  error is left for the hub's own result to fill.
- A late failed command result replaces the stale-sweep message (only a
  sweep message, never a /finalize verdict).

Firmware (0.30.8):
- postCommandResult returns whether it got a 2xx.
- The audio relay's result is retried once after 1.5 s; if that fails it
  is held in RTC memory and delivered at the top of the next cycle (at
  most three tries).
- A session that fails to start carries free heap, largest block and
  minimum-ever heap in its message, so the dashboard shows the numbers
  without a serial cable.

Tests: regression checks for the disconnect (fail without the fix) and the
late-result replacement. esp32dev and xiao_esp32c6 build; host tests and
the server suite pass.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01AQa7TMjkrHCnKhfkWnN4GK
Field test of 0.30.8 on a 30-pin ESP32: the BLE stack and the TLS socket
both came up this time, and the session failed one step later:

    out of memory for the audio buffer (needed at least 8 kB)
    [heap free 9608, largest 6900, min 4324]

runUploadCycle() kept the measurement JsonDocument and its serialised
String alive until the function returned, so both were resident through
checkCommands() and therefore through the audio relay. Scope them to the
measurement/upload block so they are freed before any command runs. This
returns their memory and closes the holes they leave in the heap, at the
point where the relay is short of a few kilobytes.

Not built here: the PlatformIO registry is blocked from this environment.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LtgySqvo41PbZ4N5GkVPgf

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants