syzbot: trace reproducers

[FlorentRevest]

Debugging context

More debugging context is always helpful for someone looking at a syzkaller bug. Currently, the context provided is: the syz reproducer, strace logs and the backtrace. When diving into a new subsystem, this often means that the developer needs to figure out how exactly the syscalls are implemented in that subsystem (often, syscalls like read/write are non-descriptive and implemented in different ways depending on the file for example) to understand the lifecycle of the reproducer that leads to the backtrace.

Reproducer tracing

Recently, I've become curious about how automatically tracing reproducers in syzbot could help developers quickly gather context on a syzkaller bug.

• Ftrace has the ability to trace static tracepoints, or a set of (or all) functions or a function call graph, filtered by attributes like pid. For example, trace-cmd start -p function_graph --max-graph-depth 10 -F ./repro gives a reasonable overview of how a reproducer stimulates the kernel. Since https://lore.kernel.org/all/[email protected]/ this even shows return values, which can be very useful to identify corrupt pointers etc...
• eBPF tracing programs have the ability to do deep argument inspection and possibly encode clever wizardry (with BTF type introspection or __ksym resolution) and only log under complicated circumstances. retsnoop is an interesting prior art, it is meant to understand why a syscall returns an error but it's not a long shot to imagine modifying it to understand when a reproducer starts to cause troubles. Another interesting example to look at is ksnoop which leverages BTF to pretty-print arguments and return values.

Reproducibility

Naturally, enabling ftrace or eBPF can prevent some bugs from reproducing so ideally this would be an additional step, after syzbot found a reproducer it could try to trigger it again under tracing and opportunistically report the trace.

What to trace

Of course there's a trade-off between tracing more and potentially drowning signal in noise (and filling trace buffers :)) or tracing less but then potentially missing relevant information (and we need to take more informed decisions about what to log). Some input to the filtering could be:

• kcov coverage (maybe we can isolate the set of functions that are actually relevant to trace ?)
• syz repro (maybe a syscall definition in syzlang could be accompanied with a "relevant functions to trace" annotation?)
• the bug subsystem (maybe a net or block bug would appreciate one of the appropriate bcc snoop trace https://github.com/iovisor/bcc#tools)
• the bug type (a locking bug would trace lock activities for example ?)
• the backtrace (e.g: ksnoop -s can log arguments of functions only in a specific backtrace for example)
• proximity to the bug (just keep the last X function calls before the backtrace)
• specific symbols (with __ksym resolution, one could track specific statically allocated variables across functions)
• key patterns of weirdness/corruption (eg: if a pointer argument is not in the kernel memory range) Deciding on "relevant" things to trace is probably the harder part of this problem, any input is welcome! :)

Logs extraction

One issue with most existing tracers is that they expect the kernel to survive. (typically, logs are regularly consumed from userspace) In our case, we'd want logs as close to the crash as possible.

• /proc/sys/kernel/ftrace_dump_on_oops can instruct ftrace to dump its logging buffer at the time of an oops but this mangles the serial output and could make our lives harder.
• CONFIG_PSTORE_FTRACE=y logs to a pstore but not every pstore drivers support PSTORE_FLAGS_FTRACE. For example, I experimented with a QEMU ACPI ERST to exfiltrate ftrace logs from a crashing VM but this is not supported. When running under GCE, I imagine the pstore is probably quite small and wouldn't contain a large trace. Also it looks like CONFIG_PSTORE_FTRACE configures ftrace itself and doesn't let us choose the kind of tracing we're interested in
• Alternatively, the ftrace buffer should be accessible from a core dump taken in kdump by a fork of the crash utility but as far as I know we do not support kdump yet
• Maybe the core dump could be saved using QEMU monitor instead, for example when a panic is reported by a pvpanic device over the QEMU monitor port (libvirt already has support for this)
• Alternatively, it looks like trace-cmd agent and virtio-trace splice the ftrace ring buffers with the host using shared memory. if this works like I think, it could mean that the buffers would be filled even until the point of a panic.
• With sysctl -w kernel.tracepoint_printk=1, ftrace logs end up on dmesg. For example, in the case of eBPF logs, one could use the bpf_trace_printk() helper, like with its bpftrace wrapper debugf: bpftrace -e 'tracepoint:block:block_rq_issue { debugf("%d %s %d\n", pid, comm, args->bytes); }'. This is probably slow and would most likely mangle the serial output too.

Sharing and visualization

Syzbot could point to a Perfetto link that has the trace loaded such that the reader can inspect the lifecycle of the reproducer directly from the browser. It's unclear how good Perfetto is at visualizing ftrace function graph traces though.

Alternatively, the trace.dat could be provided as an asset so that the user can open it in kernelshark.