RFC-0038: Tracing Protocol Redesign: validating the firehose on ftrace #6397
Replies: 8 comments
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
-
|
📝 RFC Document Updated View changes: Commit History |
Beta Was this translation helpful? Give feedback.
Uh oh!
There was an error while loading. Please reload this page.
Uh oh!
There was an error while loading. Please reload this page.
-
📄 RFC Doc: 0038-firehose-debundling-smb-compression.md
Tracing Protocol Redesign: validating the firehose on ftrace
Authors: @sashwinbalaji
Status: Draft
RFC-0014 sketches a tracing protocol where the producer becomes a firehose: the
writer dumps full, self-contained events with little producer-side packing
(close to a zero-copy memcpy), and the space optimization moves into traced, in
batches, off the hot path. The bet is that traced recovers most of it with
"batch-based transparent compression using LZ4/ZSTD", leaning far less on
hand-rolled interning; and that RFC-0028's routing lets the writer emit each
event once and tee it to every session that wants it.
This document is the experiment that checks whether that holds on. We picked
ftrace on purpose: it is the highest-volume source and also the most heavily
hand-optimized one (
CompactSchedis columnar, delta-coded and comm-interned),so everything the firehose wants to move off the writer is concentrated in one
place.
The three questions
There are three things to worry about with the firehose. We answer each by
running on a real Android device (a Pixel Fold, Tensor G2):
FtraceEventperTracePacketinstead of a packed bundle. How much bigger does that make the stream?
small shared-memory buffer drained by one reader. How much write-rate increase
can the SMB take before it drops events, and under what device load? (And, read
as concurrent traces, what that means for the routing in RFC-0028.)
moving the squeeze into traced is that a general-purpose compressor recovers
what we stopped doing on the producer. Does it, without regressing what we
upload?
Answer
The data and every experiment behind it live in workbook;
the scripts that produced these numbers are under scripts.
The traces, and what each short name means:
aot_boot): the always-on trace, started once system_serveris ready during boot. This is the stream we replay for the SMB test in part 2;
it began ~26 s into the boot, roughly when system_server came up.
aot): the always-on background trace, triggered when somethinggoes wrong on the device.
cold_start): launching an app cold.first_unlock): the heavy spike right after the firstunlock following a boot.
sys_random): a randomly triggered 30-second capture.battery_long): a day-long, lightweight trace with almost nosched.
1 · How much bigger does de-bundling make ftrace?
Everything here falls out of one fact: only scheduler events are expensive to
un-bundle. Today, ftrace events arrive packed into a per-CPU bundle:
Two independent optimizations live in there, and de-bundling hits them very
differently:
repeated FtraceEvent event). Most events (atraceprint,binder, irq) are already full standalone messages in that array; they just share
the bundle's one cpu and one packet header. De-bundling gives each its own, but
the payload is byte-for-byte identical, about 1.07×. Essentially free.
CompactSched(thecompact_schedfield). Scheduler events (sched_switch,sched_waking), the highest-frequency events, are packed columnar: deltatimestamps,
comminterned, ~8–12 B each versus ~40 B as a full message.De-bundling undoes that (full timestamp, un-interned
comm, rebuiltprev_*),which costs ~3.5–4.7×.
The v2 change itself is small, and it leaves the event payloads untouched
(validated field-for-field against a
compact_sched-disabled capture): kill thebundle, emit one
FtraceEventperTracePacket, and move cpu onto the event.This is exactly the firehose shape from RFC-0014: the writer stops packing and
just dumps full events.
How much bigger the on-the-wire ftrace gets depends entirely on a trace's
scheduler share. Across 12 real captures (6 scenarios × 2, all data-loss-free):
aot)aot_boot)cold_start)first_unlock)sys_random)battery_long)Rolled up, and bracketed two ways (event bytes only, or including the per-event
packet header; the real v2 framing sits between them):
Two things matter here:
byte-share (a clean linear relationship, shown in the workbook).
A trace with no sched is free to de-bundle.
no atrace, nothing but context switches. A sched-only capture on a real Pixel
de-bundles 4.98× / 5.64×, matching a host-built reference. Field traces carry
atrace and mixed events, so they land far lower (~1.5×); 5× is the
ceiling a config can hit.
2 · Can the SMB absorb the bigger de-bundled stream?
De-bundling makes ftrace ~1.5–2.5× bigger (part 1): the real de-bundled stream
peaks at ~13 MB/s (our
aot_bootcapture, started ~26 s into the boot), up from~9 MB/s bundled. That has to flow through the small shared-memory buffer that one
reader, traced, drains. The question reduces to: how many MB/s can the SMB take
before it drops?
The captured corpus is itself loss-free; it is what today's device actually
recorded. Every loss number below comes from replaying those streams, de-bundled,
through the SMB under load, not from the recordings, so it measures what v2 would
drop rather than what today did.
How we apply the load: bigger bursts on the real timeline
We replay the boot's per-CPU ftrace through the actual v2 shared_ring_buffer
prototype and dial the write rate up by duplicating each event at its real
instant: more bytes at the same moments, with the real quiet gaps preserved. That
is exactly what de-bundling does to the stream (bigger events at the same
timestamps), so the x-axis is just MB/s; we swept ~13 → 182 MB/s.
How much the SMB absorbs, across five conditions
512 KB SMB, reader on traced's cores, the answer splits on whether the reader keeps up:
The full sweep, loss % at each write rate, per condition (the de-bundled stream
is ~13 MB/s; de-bundling's 1.5–2.5× boundary is ~20–33 MB/s):
Loss % is the share of ftrace events the producer dropped because the SMB was
full when it went to write, counted exactly from the per-event sequence numbers
in the replay (a missing number is a real drop). So 0.12% means about 1 event in
800 never reached the reader, and never made it into the trace; 0% means nothing
was dropped.
Each cell is the median of 3 repetitions. Values below ~0.01% are at the
measurement noise floor (a few stray events out of millions per run); treat them
as zero, and don't read a trend into them (idle at 13 vs 39 MB/s only differ by
rounding noise).
What this says:
loss: idle, the everyday cold-start, even a whole-device compile.
drops ~0.12% even at its real ~13 MB/s rate, because whole-system contention
starves the reader; the higher ~20–33 MB/s rate pushes that to ~0.1–0.5%.
So boot is the only case that needs the reader-starvation fix below; everywhere
else there is no loss at any realistic rate.
After the initial sweep we re-audited the harness against the live traced (its
cpuset, cpu cgroup and nice all match, so the reader is not over-privileged)
and re-ran boot and first-unlock. The loss numbers reproduced, with boot's median
staying under 1% out to ~65 MB/s. Details are in the workbook.
Why boot is different: the drain-ceiling rule
It all obeys one rule: you lose data only when the write rate crosses the
reader's drain ceiling. Starvation lowers the ceiling; the buffer only smooths
bursts.
traced's reader sits on the little/mid cores (cpuset 0–5) and gets descheduled
under load. Its reader-wait climbs from 21% idle, to ~50% under load, to ~60%+
during a boot, which drops its drain ceiling from ~125 MB/s to well below the
elevated rate. That, not the buffer, is what caps a boot at ~47 MB/s.
The buffer-size sweep proves it. A bigger SMB helps cleanly when the reader keeps
up, and does almost nothing once it's starved:
For the keep-up conditions, 1–2 MB takes even ~130 MB/s to ~0. For a starved
boot, every size loses about the same: memory can't buy back a reader that has
lost the CPU.
Cutting boot loss by lowering the reader's nice
The lever for the boot case is reader scheduling, not buffer size: give traced's
reader a stronger (more negative) nice so it keeps the CPU and drains the SMB
even mid-boot. A strong negative nice (no real-time policy) closes the loss in
the faithful model: emphatically for sustained load, and sharply at the rates
that matter for the spikes. This is the same lever we reached for once before, in
aosp/2743797.
Up to ~91 MB/s,
nice −10takes boot/unlock loss from a few percent to ~0 andwipes out the heavy-compile loss entirely. traced already holds
SYS_NICE, sothis is a one-line ship-fix. And Android won't grant a service
−20anyway, so−10is the realistic target, and it is enough.Reading it as sessions, and why routing helps
That headroom has a second reading: how many concurrent ftrace traces one SMB can
feed, and whether the routing from RFC-0028 changes that.
Without dedup, every extra trace re-emits the same events, so N concurrent traces
cost ~N× the write rate and the SMB scales with the number of traces.
The routing in RFC-0028 removes that: the writer emits each event once (one RID
per ftrace trace point) and traced tees it to every interested trace, so one
emission delivers roughly X traces' worth of content (≈ X × 13 MB/s) while the SMB
stays flat. The bandwidth measured here is therefore a floor, what one SMB
sustains before that win even lands.
3 · Can traced compress it back down?
Yes: use zstd. The chart below compares the final uploaded size, compressed on
both sides, today's actual artifact (the bundled stream after gzip, what we ship
now) against the de-bundled stream after each candidate codec (gzip, lz4, zstd),
across all 12 traces.
today's shipped artifact (bundled + gzip). Anything below the line is smaller
than what we ship now.
What the chart shows:
~1.03×); zstd-3 is roughly break-even at a fraction of the CPU.
stay above the line: bigger than today.
than gzip on the cores traced runs on (see the cost note below).
The table breaks the same comparison down in absolute MB for three representative
trace types. For each: the ftrace window and the rate the de-bundled stream is
produced at (uncompressed), then today's upload (bundled + gzip) against the
de-bundled stream after each candidate codec, as size (× today) and little-core
compression speed (Cortex-A55, the slowest core traced is pinned to). Sizes are
whole-stream and core-independent; speeds are the little-core floor.
Reading the table:
~50–99 MB/s, zstd-6 ~14–29 MB/s).
today, and its best level (lz4-12) shrinks more but collapses to ~3 MB/s,
slower than zstd-6 at a worse ratio.
always-on burst (the ftrace window is short but packed). zstd-3 on the little
core clears that with ~4× to spare; zstd-6 (~14 MB/s on the little core) keeps
pace at the peak and has room to spare on the mid/big cores traced can also use.
after-unlock/t2, is within ~3%) and on all 12 with zstd-12. De-bundling makes
the raw stream bigger; zstd more than pays it back. zstd-3 is break-even at ~⅛
the CPU; zstd-6 is ~10% under.
(
ProcessCapacityHigh, cpus 0–5). zstd-3 clears the ~13 MB/s peak productionrate with ~4× to spare even on the little core; zstd-6 matches the peak on the
little core and has headroom on the mid cores. zstd-3 is the cheap default; step
to zstd-6 when you want ~10% more shrink. Compression is not where traced's CPU
goes.
bigger-than-today at its fast levels and slower-than-zstd at a worse ratio at
its HC levels.
Switching to zstd is a win on-device regardless of de-bundling. (A generic
columnar pass before zstd reduces this further; that's a separate RFC.)
How big should the compression blocks be?
traced won't compress the whole trace in one shot; it compresses each flush as
its own block, the same bundling-and-compress step RFC-0014 describes. Bigger
blocks let zstd see more history before it has to start over, so the ratio climbs
a little as blocks grow, but with clear diminishing returns:
(which we can't actually do while streaming) adds only a few percent beyond
that. So 1–4 MB blocks capture almost all of the available ratio at a fraction
of the memory.
--longmode: it triples the RAM and buys nothingon ftrace, where the repetition that compresses well is all local.
1–4 MB per-flush blocks they are ~1–4% larger.
Can a block ever come out bigger than it went in?
Worth pinning down for sizing buffers in traced: the worry with any compressor is
that incompressible data comes out larger. Strictly, neither gzip nor zstd
promises output ≤ input (by the pigeonhole principle, no lossless codec can), but
both fall back to storing incompressible data in raw/uncompressed blocks, so the
worst case is a few bytes of bookkeeping, not a doubling. For a 1 MB block of
fully incompressible data:
compressBound)ZSTD_COMPRESSBOUND)The two columns mean different things:
header/footer plus a few bytes per raw block.
*_COMPRESSBOUNDmacro hands back,rounded up with cheap bit-shifts so it is trivial to compute and provably safe
across every level and version. This is the one you size the output buffer with.
Two things fall out. zstd's real worst case is actually tighter than gzip's (its
raw blocks are 128 KB versus DEFLATE's 64 KB, so fewer block headers over the same
data), and either way a block can grow by at most a few dozen bytes. Switching to
zstd adds no new expansion risk.
Decompression is cheap too (the read side)
The read/upload path (trace_processor, traceconv) decompresses. On the same
Pixel, zstd versus lz4 at matched levels, on the little core (the slowest read
core), for a dense and a sparse trace:
Even on the little core, zstd decompresses ~180–510 MB/s and lz4 ~490 MB/s–1.1
GB/s (~2–3× faster), both far above the ~14–51 MB/s they compress at and well
above the ~13 MB/s peak production rate. The read side is never the bottleneck, so
it doesn't sway the codec choice.
Why some traces (especially 24h) compress far better than others
Two questions decide whether a trace is cheap or expensive under v2:
when de-bundled.
back.
The 24 h sparse trace and the heaviest load trace sit at the two ends.
Only scheduler data gets bigger. De-bundling re-expands the packed
CompactSchedand leaves everything else about the same (~1.07×), so a trace grows by roughly
however much of it is scheduler data. A trace with no scheduler data doesn't grow
at all; it shrinks:
The sparse trace records almost nothing but suspend/resume events, with
CompactSchedoff, so there's nothing to re-expand. It even shrinks: it flushesonly ~1.6 events at a time, so most of its file was the per-bundle wrapper, and
de-bundling drops that wrapper (~0.97 MB, the whole shrink).
Then zstd wins it back, and that's about repetition. Once compressed, all that
matters is how repetitive the atrace text is:
The sparse trace has just 2 event types (atrace
print+suspend_resume) anda small string vocabulary, so the stream is uniform and compresses easily. Just
225 lines make up half its atrace text, things like:
Long lines repeated that often are exactly what a compressor is good at.
The load trace is the reverse: 28 event types (
print,binder_transaction,sched_blocked_reason,workqueue, and more) and thousands of short, throwawaymarkers (the 7-byte slice-ends of a busy unlock) that give the compressor little
to match, so it reaches about half the ratio.
So the sparse trace is the best case (free to de-bundle, ~0.59× today after zstd)
and a scheduler-heavy load trace is the hard case (grows ~1.76× raw), yet even the
hard case lands about where we are today once compressed. For any new config the
two questions are the same: how much scheduler data, and how repetitive the atrace
text.
So: solving, not regressing, improving
What the firehose makes go away:
CompactSched, the comm intern table, thedelta-timestamp bookkeeping: all of it leaves the producer. The firehose is a
near-zero-copy memcpy, which is exactly the write path RFC-0014 is after.
Where there's no regression versus today:
traces, so the bigger on-wire stream costs nothing in what we actually upload.
core, ~4× the ~13 MB/s peak the stream is produced at.
nothing (~0.12%, and only mid-boot, which the nice fix closes). Because it
absorbs ~90–145 MB/s whenever the reader keeps up, the ~1.5–2.5× de-bundling
increase still sits far inside that, so loss is no worse than today.
Where it is strictly better:
~40% on sparse long ones, before the columnar upside.
traced actually runs on: a win we can take immediately, independent of the
rewrite.
un-deduped concurrent ~13 MB/s traces beyond the de-bundling cost; once routing
lands (RFC-0028) the writer emits once and traced tees, so delivered output
scales without the SMB scaling, and the firehose is what makes that tee-ing
tractable.
Decision log
FtraceEventBundleoutright: oneFtraceEventperTracePacket,cpumoves ontoFtraceEvent. No 1-event-bundle shim.compaction and compression happen in traced, per RFC-0014.
duplication model across five real conditions: the SMB absorbs ~90–145 MB/s
when the reader keeps up and ~47 MB/s during a real boot, versus the de-bundled
stream's ~13 MB/s. Time-warp was the interim proxy and is now superseded.
💬 Discussion Guidelines:
Beta Was this translation helpful? Give feedback.
All reactions