rootfs: strace in the image, built from source and pinned by checksum

[tamnd]

The M1 row is "The rootfs recipe, with busybox, strace and our own tools". Busybox and our own tools have been in since M0. strace was the missing third.

What it is for

A function graph tape says what the kernel did once it was inside a call, and how long each frame took. It does not say what the program asked for. The arguments, the file descriptors, the flags and the errno on the way back are not in a tape, and no amount of reading one recovers them, because the tracer records entry and exit and those values live in registers it never samples.

Those are the first questions anybody has. Here is writebyte, one of the three programs already in the image, taken off a real boot:

execve("/bin/writebyte", ["/bin/writebyte", "/tmp/probe"], 0xbffaf98c /* 6 vars */) = 0
open("/tmp/.writebyte-warmup", O_WRONLY|O_CREAT|O_TRUNC, 0600) = 3
write(3, "x", 1)                        = 1
close(3)                                = 0
unlink("/tmp/.writebyte-warmup")        = 0
open("/tmp/one-byte", O_WRONLY|O_CREAT|O_TRUNC, 0600) = 3
open("/sys/kernel/tracing/tracing_on", O_WRONLY) = 4
write(4, "1\n", 2)                      = 2
write(3, "x", 1)                        = 1
write(4, "0\n", 2)                      = 2
close(4)                                = 0
close(3)                                = 0
write(1, "wrote 1 byte to /tmp/one-byte\n", 30) = 30
exit(0)                                 = ?
+++ exited with 0 +++

Everything rootfs/README.md claims about that program is visible on that page. The warmup runs the whole sequence once and throws it away. The file is opened before the window rather than inside it. Between the two writes to tracing_on there is exactly one write, which is the claim all three programs are built on and which nothing was checking until this binary went in.

Errno comes back named, which is the other half of what a tape cannot show:

open("/proc/nope", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)

Built, not downloaded

Busybox is an upstream binary and pin.toml explains that as a deliberate trade. strace goes the other way for a duller reason than any argument: there is no static i686 strace to download. So it is built from the release tarball, in the same container the kernel is built in, and the tarball is what the checksum pins.

Two costs, both measured rather than estimated.

Size. It is about a megabyte compressed, which more than doubles the initramfs.

What is in it	Compressed
busybox, three small programs, abba.ko	712410 bytes (696 KiB)
the same plus strace 7.2	1737376 bytes (1.66 MiB)

Most of that megabyte is a static glibc plus the tables that turn a syscall number and six longs into a line somebody can read, and those tables are the entire feature. Alongside A-full a reader now fetches 4.91 MiB instead of 3.93 MiB, a quarter more. That is the same trade B-btf-external exists to price and it has the same honest answer: everything measured here is served from 127.0.0.1, so this cannot settle it. What it does settle is the other half, which is that the boot did not get slower. Under node the box still reaches a shell in 6.3 seconds and all eleven checks pass.

Build time. Thirty seven minutes on an arm laptop, where almost all of it is qemu translating x86 one instruction at a time. Configure alone was twenty five of those minutes, because it compiles and runs a few dozen small programs to decide things about the target. On an x86 machine it is a couple of minutes. Either way the binary is cached beside busybox, so it happens once, and the caching is why the number is bearable rather than a reason to skip the tool.

The build is reproducible in the way that matters here: two runs from the same tarball in two fresh containers produced a binary with the same sha256.

Three things it will not do, said up front

strace -k needs libunwind and there is none, so strace -V reports Optional features enabled: (none).

The seconds column of strace -c is emulated time and means nothing, the same as every other duration in the box. The counts are real and the counts are what it is for:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 33.52    0.001104         157         7           close
 25.87    0.000852         121         7           write
 18.34    0.000604         201         3           open
 15.36    0.000506         506         1           unlink
  6.92    0.000228         114         2           pipe
  0.00    0.000000           0         1           execve
------ ----------- ----------- --------- --------- ----------------
100.00    0.003294         156        21           total

And attaching to a process stops it twice per system call, so a tape taken while strace is attached is a tape of ptrace doing its job, which is a real trace of something nobody asked about.

The tidy up underneath

build.sh had three pin readers that were the same function with a different section name in the middle, and strace was about to make it four. There is one now that takes the section as an argument, plus a fetch helper that downloads once and refuses to hand back a file whose sha256 does not match. Both things that come off the network go through it.

That helper is also what made three tests worth writing, because every step of this build is now a key in a TOML file and a key spelled wrong is a KeyError out of a heredoc partway through, which for strace means thirty seven minutes in on the machine most likely to be running it.

def test_the_rootfs_build_only_asks_for_keys_the_pin_has():
    pin = tomllib.loads(ROOTFS_PIN.read_text(encoding="utf-8"))
    for section, key in sorted(asked_for(BUILD_SH.read_text(encoding="utf-8"))):
        assert section in pin, f"build.sh reads a [{section}] section the pin has not got"
        assert key in pin[section], f"build.sh reads {section}.{key} and the pin has not got it"

Two calls reach the pin, read_pin strace url and read_strace url through a one line helper, so the reader that finds them has its own test with a fixture rather than being trusted. The third asserts that everything with a url in the pin also has a 64 character sha256, an https URL and a date saying when the checksum was taken.

Checked

headless.js smoke has an eleventh entry now, and it goes through ptrace rather than the tracer, so a kernel that loses PTRACE_ATTACH or a binary built against the wrong libc fails on its own line while everything above it still passes.

booted in 6.3s
  pass  shell     hello
  pass  proc      Linux version 7.2.2 (kxbox@kxbox) (i686-linux-gnu-gcc (Debia
  pass  kallsyms  50787
  pass  tracefs   /sys/kernel/tracing/current_tracer
  pass  tracers   function_graph wakeup_dl wakeup_rt wakeup irqsoff function n
  pass  dmesg     [    2.941537]     TERM=linux
  pass  write
  pass  readback  one
  pass  modules
  pass  touchpage touched 0xb7fa6000
  pass  strace    1

all 11 checks passed

sh kxbox/rootfs/build.sh was then run once more with the cached binary deleted, so the fetch, the checksum, the container build and the pack were all exercised from nothing, and it came out at 1737376 bytes with the same strace inside it.

Every gate locally: ruff check and format over 190 files, 1490 pytest tests with 7 skipped, 63 node tests, lintprose over 37 files, and the check runs of diagrams, nbbuild, sitebuild, kxbox, vendor, baseline, claimledger, coverage, bpc, kconfig, refcheck, lintnb and kxmanim.

What is deliberately not here

No strace capture is committed. corpora/BASELINE.toml requires that every line of every committed artefact is accounted for by a reader that claims it, and there is no kxray.strace, so a capture dropped into corpora/ would be a file nothing has ever opened. The output above is in the PR and in rootfs/README.md instead.

That is the right size for this row. A lesson can already do box.sh("strace -o /tmp/x.txt prog") and box.read("/tmp/x.txt") and print it, which is the whole of the Tourist use. A parser is what you need to diff two of them or draw one, and that is a kxray question rather than a rootfs question.