Logs: the serial console you cannot see, as a searchable stream by giovanni-guidini · Pull Request #8 · getsentry/sentry-micro

giovanni-guidini · 2026-08-20T15:25:03Z

Implements the Logs feature (SDK-1419): a ring buffer of console-style log
lines, serialized into a log envelope item, correlated to whatever trace
was active when each line was recorded.

What's here

Buffer depth (SDK-1413): the shared offline NVS buffer grows from 8 to
16 slots in both examples, with sizing guidance added to the README. No
priority tier — one ring, oldest evicted first, across every envelope type.
Logs core: sentry_log() / sentry::log(), a fixed SENTRY_MICRO_MAX_LOGS-entry
ring and its envelope writer. Each line remembers the trace active when it
was recorded, not whatever is active at flush time — the same way a
breadcrumb attaches to what was actually happening. A line recorded while
idle still gets sent, just without that attachment.
Truncation: computed from vsnprintf()'s real return value rather than
predicted at compile time, surfaced as sentry_logs_truncated_count() and a
per-line t7d attribute. Finding the right shape for that attribute
surfaced a real, pre-existing capacity bug — a full ring of realistic-length
lines didn't fit in SENTRY_MICRO_ENVELOPE_BUFFER_BYTES even before
truncation existed. Fixed by abbreviating attribute keys, making them (and
the whole attributes object) conditional, and lowering
SENTRY_MICRO_MAX_LOGS from 8 to 6 — verified against the actual worst case
with a dedicated regression test.
wifi_basic wired up end to end: a wifi-connect transaction and a
demo-crash transaction (deliberately never finished — the trace it leaves
active is what the crash reporter joins to on the next boot), with
sentry_log() calls riding both, plus one log recorded before any trace
exists.
Two real bugs found only by testing on actual hardware, not host tests:
1. loop()'s only sentry_flush() call was gated on
  sentry_buffered_count() > 0, which tracks the offline retry buffer only
  — logs/metrics accumulate independently of it and were never actually
  flushing in the common case of nothing landing in that buffer.
2. Holding a live sentry::Transaction open across a WiFi/TLS send
  overflows Arduino's default 8 KB loop task stack. -D CONFIG_ARDUINO_LOOP_STACK_SIZE=<n> looks like the fix but does nothing —
  sdkconfig.h redefines that macro after the command line and wins.
  Fixed by overriding Arduino-ESP32's own getArduinoLoopTaskStackSize()
  weak hook instead.
Logs and Metrics are now compile-time optional: SENTRY_MICRO_LOGS_ENABLED=0
and SENTRY_MICRO_METRICS_ENABLED=0 (default 1) remove the log ring /
metrics table entirely, matching the existing SENTRY_MICRO_WIFI_TLS=0
pattern — disabled functions are not declared at all, so a build that
turns a feature off and still calls it fails to compile rather than
silently doing nothing. Measured on esp32dev (a build that never calls
either API): 832 B RAM / 1,496 B flash for logs, 272 B RAM / 1,140 B flash
for metrics, 1,104 B RAM / 3,056 B flash with both off. README gains a new
"Logs" section (previously undocumented) with its own cost table.
CHANGELOG updated for all of the above.

Verification

162 host tests pass (pio test -e native -e native_cxx).
All four default chip variants (esp32dev, esp32-s2, esp32-s3,
esp32-c3) build clean, with and without -D SENTRY_DEMO_CRASH=1, and at
the default (both features enabled).
Confirmed the disabled-but-still-called case fails to compile rather than
silently linking, for both toggles independently and combined.
Flashed to a real ESP32 (esp32dev) against the live cloud ingest: the
wifi-connect transaction and log lines deliver over TLS with HTTP 200,
and show up correlated by trace in Explore → Logs and Traces.

Linear: SDK-1419

Raised both examples' NVS-backed offline buffer from 8 to 16 slots, and documented in the README how to size that number: sentry_storage_nvs() already accepts any count up to SENTRY_NVS_MAX_SLOTS (64), so a smaller firmware can and should pass a smaller one — 16 is just these examples' own choice against the stock 20 KB partition, not a ceiling the SDK imposes. One shared ring across every envelope type, oldest evicted first, with no priority between categories and no separate buffer per category. Deliberately not solving this with reserved slots for crash reports: logs are opt-in, more connected context on one event can be worth more than a duplicate event with less, and the real fix for reliable delivery is a transport that keeps delivering, not triage over whose envelope keeps its slot. Also added an NTP time sync in wifi_basic after WiFi comes up and before the first send attempt, since the example never set the clock otherwise and an ESP32 has no battery-backed RTC. 133 host tests pass; both examples build clean for esp32dev.

sentry_log(level, fmt, ...) records one console line into a fixed 8x81 ring (src/core/sentry_log.c/.h), mirroring Application Metrics: recording never sends, so it is safe to call from a hot path a transaction cannot afford to trace. Unlike a metric, each line keeps its own trace_id, captured when it was recorded rather than resolved once for the whole batch — a line written during a real operation stays attached to it even if the operation has ended by the time the ring flushes. An idle-recorded line gets a fallback trace_id minted locally for that one envelope, never written to the device's active trace. Every line also carries device_id as an attribute, the correlation axis that is always available regardless of trace state. flush_logs() is called from sentry_flush() only, same as flush_metrics() — not from every trace transition as first built. That would have turned sentry_trace_adopt()/start()/release(), which wrap every request, into occasional blocking network calls; per-entry trace_id capture already makes correctness independent of when the ring happens to flush, so the extra call sites bought nothing but the regression. sentry_logs_dropped_count() is backed by a persistent g_state.logs_dropped counter, incremented from sentry_log_ring_push()'s new bool return (true on eviction), the same split metrics uses between its own reset-per-flush table counter and its lifetime g_state.metrics_dropped — the ring's internal `dropped` field alone would have reset on every successful flush. 15 new host tests (17 after the audit below), plus test_filter wiring in platformio.ini. Verified against the real firmware, not just the host suite: pio test -e native never compiles sentry_micro.c at all (build_src_filter = +<core/>), so the flush wiring was only checked by building all four default chip variants directly. Reviewed with review-work + test-audit before this commit: - Fixed the dropped-count and blocking-hot-path issues above. - Corrected a stale test comment (wrong eviction count in a comment). - Added a doc note against putting secrets in a log body. - Added tests for the previously-unasserted eviction return value, the timestamp derivation's two underflow clamps, and the envelope writer's size-probing/truncation-safety contract. - Filed, but did not fix here, a pre-existing flush_metrics()/ sentry_trace_start() bug that now also affects log trace attribution (SDK-1418) — logs sidestep it by not reusing sentry_trace_start() for their own fallback, but the root cause is unmodified, already-shipped code out of scope for this change.

sentry_log() now captures vsnprintf()'s return value (previously discarded) to know exactly when a line was cut short, rather than predicting it. A compile-time per-argument size-checking C++ wrapper was designed and deliberately rejected in favor of this: it's exact instead of a conservative worst-case bound, it works for runtime format strings too, and it avoids introducing this codebase's first real template metaprogramming for a failure mode (a shortened log line) that vsnprintf already makes memory-safe on its own. Each entry now carries its own `truncated` bool, ORed with the ring's own defensive truncation of an oversized body (so a caller that bypasses sentry_log()'s vsnprintf and calls the ring API directly still gets a correct answer). Surfaced two ways: sentry_logs_truncated_count(), mirroring sentry_logs_dropped_count(), and a per-line attribute so Explore -> Logs shows which specific line was shortened. Wiring that attribute in surfaced a real, pre-existing capacity bug: a full ring of realistic-length log lines already didn't fit in SENTRY_MICRO_ENVELOPE_BUFFER_BYTES before this attribute ever existed (2290 bytes needed against a 2048 budget, for 8 entries at max body length). flush_logs() silently refuses to send over budget and never resets the ring, so a device in that state would get stuck indefinitely. Nothing caught it because every prior test used short bodies, never a full ring at realistic length. Fixed with three changes together, since renaming alone measured short: - SENTRY_MICRO_MAX_LOGS: 8 -> 6. - Attribute keys abbreviated (truncated -> t7d, device_id -> d_id). - Both attributes conditional -- t7d only when true, d_id only when given, and `attributes` itself omitted rather than written empty when neither applies. Worst case (6 entries, max-length bodies, all truncated, device_id present) now measures 1944 bytes against the 2048 budget. Added test_a_full_ring_of_worst_case_entries_fits_the_envelope_budget as a regression test for exactly this scenario. Also adds a plain (non-templated) sentry::log(...) C++ forwarding wrapper in sentry_micro.hpp. 153 host tests pass (20 in test_log.c); all four default chip variants build clean.

Adds three sentry_log() lines and two sentry::Transaction traces to make the Logs feature visible end to end on real hardware, not just in host tests: - One line recorded before any trace exists this boot (right after print_sentry_state()), landing in Sentry with no trace_id — the idle case sentry_log()'s own doc describes. - connect_wifi() itself gains two lines, one per outcome, with no trace object threaded through it: they inherit whatever trace is active on the call stack, which is exactly what a new "wifi-connect" transaction wrapping the call in setup() provides. sentry_transaction_start() mints that trace itself since none exists yet. - A third line, level FATAL, right before the demo crash under SENTRY_DEMO_CRASH, wrapped in its own "demo-crash" transaction that is deliberately never finished — the device is about to end the boot, so there is no operation left to time. What the transaction leaves behind is a trace that is still active when the crash happens, which sentry_event_attach_coredump() picks up on the next boot and joins the recovered event to, the same way a request handler's trace would join a crash that happened while it was running. Getting this right took three real fixes along the way, not just adding the calls: - The wifi-connect transaction needs a synced clock to keep itself at all (sentry_transaction_finish() drops a transaction with none), and the very WiFi connection it traces is what makes that sync possible — reordered so sync_time() runs, and the transport is registered, before the transaction tries to finish rather than after. - sentry_transaction_finish() ends a transaction but not the trace it rode. Left active, the wifi-connect trace would have silently welded the boot report and the demo-crash trace to an unrelated WiFi connection. Released explicitly once the transaction is done. - loop()'s only sentry_flush() call was gated on sentry_buffered_count(), which tracks the offline retry buffer only. Metrics and logs accumulate independently of that buffer and were never being flushed at all in the common case of nothing ever landing in it — this predates the Logs feature but nothing exercised the gap until now. Also added an explicit flush before the demo crash itself, since loop() never runs again to do it on its own interval. 153 host tests pass; all four chip variants build clean, with and without -D SENTRY_DEMO_CRASH=1.

Confirmed on real hardware (esp32dev): holding a sentry::Transaction open across the wifi-connect send overflows Arduino's default 8 KB loop task stack every time, deterministically, right inside the TLS handshake's entropy gathering. A sentry_transaction_t plus sentry_transaction_finish()'s 2 KB envelope buffer sit on setup()'s stack frame the whole time WiFiClientSecure is also using several KB of its own for mbedtls_ctr_drbg_seed() — nothing in this example ever exercised that combination before, since the only prior sends came from capture_message(), with no transaction alive at the same time. -D CONFIG_ARDUINO_LOOP_STACK_SIZE=<n> looked like the fix but silently does nothing: sdkconfig.h #defines that macro unconditionally, after the command line runs, and wins. Verified this the hard way — objdump on the built ELF showed getArduinoLoopTaskStackSize() still returning 8192 with the flag set, and the crash persisted identically even after doubling the requested size. Overriding the weak getArduinoLoopTaskStackSize() symbol that cores/esp32/main.cpp declares specifically for this is the documented, actually-effective path — confirmed via nm/objdump that the override links as the sole strong definition and returns 16384. Confirmed fixed on real hardware: the wifi-connect transaction, and the sentry_log() lines riding the boot-start and connect_wifi() logs, now deliver over WiFi/TLS without crashing, both when the clock syncs before the transaction tries to finish and (that case being timing-dependent) the documented drop when it does not.

Covers the work already committed on this branch: the offline buffer growing to 16 slots, the Logs feature itself (ring, truncation, the t7d/d_id byte-budget fix), tracing added to wifi_basic, the periodic-flush gate bug that fix exposed, and the loop-task stack-size fix needed to hold a transaction open across a real TLS send.

linear-code · 2026-08-20T15:25:07Z

SDK-1419

cursor

Cursor Bugbot has reviewed your changes and found 1 potential issue.

^{❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.}

Want reviews to match your repository better? Bugbot Learning can learn team-specific rules from PR activity. A team admin can enable Learning in the Cursor dashboard.

^{Reviewed by Cursor Bugbot for commit a66e207. Configure here.}

cursor · 2026-08-20T15:28:10Z

+    if (needed == 0 || needed >= sizeof(envelope)) {
+        debug_log("logs need %u bytes, envelope buffer is %u", (unsigned)needed,
+            (unsigned)sizeof(envelope));
+        return;


Escaped logs can stall the ring

High Severity

A full ring of max-length bodies is sized as if body copies 1:1 into JSON, but sentry_json escapes quotes, backslashes, and control characters. The budget already has only a few dozen bytes of slack, so ordinary console text with quotes or \ pushes needed over SENTRY_MICRO_ENVELOPE_BUFFER_BYTES. flush_logs() then returns without resetting the ring, so later flushes retry the same oversized batch and logs stop shipping.

Additional Locations (2)

test/test_log/test_log.c#L115-L138

src/core/sentry_log.c#L122-L130

^{Reviewed by Cursor Bugbot for commit a66e207. Configure here.}

Good catch — confirmed. The regression test I added sizes the worst case by length only (memset with 'x'), but write_escaped() expands "/\/control characters, so a body full of quotes or backslashes can push a full ring's encoded size past the envelope budget even though the raw bytes fit. And since flush_logs() doesn't reset the ring when the batch is oversized, that would retry the same batch forever instead of failing once.

Not fixing this in this PR — picking it up as a follow-on so it gets a proper fix (likely: drop an oversized batch rather than retry it forever, the same way the offline buffer already handles an unreadable entry) plus a test that actually maximizes escaped size, not just length.

Both the log ring and the metrics table were permanent g_state fields with no way to get the RAM back, unlike a transaction's spans: a metric or a log line has to survive across flushes rather than living on a caller's stack for one operation, so neither was ever caller-owned. Nothing else in this SDK reserves storage a build cannot opt out of. SENTRY_MICRO_LOGS_ENABLED and SENTRY_MICRO_METRICS_ENABLED (both default 1) follow the exact SENTRY_MICRO_WIFI_TLS precedent already in this codebase: setting either to 0 removes the field, the recording functions, the dropped- count getters and flush_logs()/flush_metrics(), rather than turning them into no-ops. A build that disables a feature and still calls into it fails to compile, the same way set_ca_cert() disappears under SENTRY_MICRO_WIFI_TLS=0 -- silently doing nothing would be a worse failure mode than a build error. Measured on esp32dev, a wifi_basic build that never calls either API: RAM Flash Logs 832 B 1,496 B Metrics 272 B 1,140 B Both 1,104 B 3,056 B README gains a "Logs" section (previously undocumented despite the feature existing) with its own "What it costs" table alongside Spans' and Metrics', and both toggles are cross-referenced from each other. 162 host tests pass; the core log/metrics rings these gate are untouched -- test_log.c/test_metrics.c exercise them directly and never go through the gated sentry_micro.c wiring. All four wifi_basic chip variants build clean at the default (both enabled), and the disabled-but-still-called case was confirmed to fail to compile rather than silently link.

flush_metrics() and flush_logs() both delivered through sentry_send_envelope(), which buffers any failure worth_retrying() calls retryable -- and SENTRY_SEND_UNAVAILABLE is on that list. sentry_transport_send() returns it for a NULL transport, WiFiTransport returns it when WiFi is down. So a device with no route wrote a metrics envelope to flash on every flush interval, plus a logs envelope. Found integrating against ChromaBay, which is disconnected most of its life: a healthy board wrote to LittleFS every 5 minutes, and logs at a 20s cadence would have been 15x that. Flash wear is the smaller half. The offline buffer is one shared ring, oldest-out with no priority between categories, so a routeless device fills it with heap gauges and console lines until the eviction takes out the one envelope in there that actually has nowhere else to live -- the crash report, which is gone from RAM the moment it is built. The thing this SDK exists to deliver was losing to a heap gauge. Neither category belongs in that buffer. Both are still in RAM and both already have a policy for accumulating across flushes. Both flushes now return early when sentry_transport_is_available() is false, leaving their in-RAM state untouched. That probe already existed in core and is implemented meaningfully by WiFiTransport (WiFi status), RelayTransport (host_ready()) and AutoTransport (select() != nullptr), so the disconnected case is detected accurately. It defaults to true for a transport that does not implement it, which makes the early return a fast path rather than a guarantee -- so both also now deliver via deliver() instead of sentry_send_envelope(), and nothing they produce can reach the buffer even when the probe lies. The obvious version of this fix -- bypass the buffer, keep everything else -- would have been a silent regression for logs. flush_logs() reset the ring unconditionally after the send, which was only safe *because* the buffer caught the envelope on failure. Bypassing without touching the reset would serialise the ring, fail to send, and clear it anyway, losing every line for the whole disconnected period. Metrics genuinely regenerate; log lines do not. So the result now decides the ring's fate three ways: OK reset worth_retrying hold -- the ring's own oldest-out eviction bounds how far behind it falls, and no flash is touched REJECTED drop, because holding something ingest will never accept is the same forever-retry wedge SDK-1420 just fixed, arrived at from the other direction A rejected metrics batch is deliberately *not* counted in sentry_metrics_dropped_count(): the public header defines that as distinct names that did not fit the table, and folding a batch drop in would make one number mean two unrelated things. README had two claims this invalidates. It documented gating the periodic flush on `sentry_buffered_count() > 0`, which tracks only the retry buffer -- so on a healthy device that never fails a send, the count stays zero, the flush never runs and neither metrics nor logs are ever delivered at all. That exact bug was fixed in wifi_basic during #8 but the README kept teaching it. It also told readers to size `slots` against metrics evicting crash reports, which is no longer a thing that can happen. Verification is honest about its limits: the native env compiles only src/core/ (build_src_filter = +<core/>), so neither flush function has a host test and this change is covered by construction and by compiling into firmware. Hardware verification is batched with SDK-1390. 154 native and 9 native_cxx tests pass; esp32dev builds clean, +480 B flash, no RAM. Fixes SDK-1421. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

giovanni-guidini added 6 commits August 20, 2026 16:26

cursor Bot reviewed Aug 20, 2026

View reviewed changes

giovanni-guidini merged commit b21d3e7 into main Aug 20, 2026
20 checks passed

giovanni-guidini deleted the gio/sdk-1419-logs-the-serial-console-you-cannot-see-as-a-searchable-stream branch August 20, 2026 15:58

Navigation Menu

Uh oh!

Logs: the serial console you cannot see, as a searchable stream - #8

Logs: the serial console you cannot see, as a searchable stream#8
giovanni-guidini merged 7 commits into
mainfrom
gio/sdk-1419-logs-the-serial-console-you-cannot-see-as-a-searchable-stream

giovanni-guidini commented Aug 20, 2026 •

edited

Loading

Uh oh!

linear-code Bot commented Aug 20, 2026

Uh oh!

cursor Bot left a comment

Uh oh!

cursor Bot Aug 20, 2026

Uh oh!

giovanni-guidini Aug 20, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Uh oh!

Conversation

giovanni-guidini commented Aug 20, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

What's here

Verification

Uh oh!

linear-code Bot commented Aug 20, 2026

Uh oh!

cursor Bot left a comment

Choose a reason for hiding this comment

Uh oh!

cursor Bot Aug 20, 2026

Choose a reason for hiding this comment

Escaped logs can stall the ring

Uh oh!

giovanni-guidini Aug 20, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

giovanni-guidini commented Aug 20, 2026 •

edited

Loading