Debug nos with GDB

By the end of this guide you will be able to stop a running nos in GDB and see where every CPU is, read a panic report, turn up logging for a subsystem, narrow down a failing boot with kernel parameters, and get a log out of a machine that has no serial port.

You need:

• a kernel you built; the GDB scripts load bin/kernel64.elf or bin/kernel-arm64.elf;
• QEMU (see Run nos in QEMU);
• GDB for x86-64. For arm64, a GDB that supports aarch64 (gdb-multiarch or aarch64-elf-gdb), or LLDB.

Attach GDB through QEMU's stub#

x86-64#

qemu.sh, qemu-disk.sh and run.sh all start QEMU with -s, which opens a GDB stub on TCP port 1234. While one of them is running:

./scripts/gdb64.sh

This runs GDB with the commands in scripts/gdb-debug64:

set architecture i386:x86-64
target remote 127.0.0.1:1234
symbol-file bin/kernel64.elf
set print pretty on
set height 20000
thread apply all bt

QEMU presents each virtual CPU to GDB as a thread, so the last command prints a backtrace for every CPU. That's the first thing to look at when a machine stops responding. GDB then leaves you at its prompt with the machine stopped. info threads, thread N, bt, break and continue work as usual, and Ctrl-C stops the machine again. The same without the script:

gdb -ex "symbol-file bin/kernel64.elf" \
    -ex "set architecture i386:x86-64" \
    -ex "target remote :1234"

The C++ is compiled with full debug information (-g3). The Rust staticlib is a release build without it, so in a Rust frame GDB shows the function name but no source line.

To start debugging from the first instruction, add QEMU's -S next to -s: QEMU then waits for GDB before running anything. qemu.sh doesn't take extra arguments, so run its QEMU command yourself:

qemu-system-x86_64 -smp 2 -cdrom nos.iso -serial file:nos.log -s -S

arm64#

qemu-arm64.sh passes its arguments on to QEMU:

./scripts/qemu-arm64.sh -s -S

Then, in another terminal:

./scripts/gdb-arm64.sh

The script runs gdb-multiarch, or aarch64-elf-gdb if that's what you have, with scripts/gdb-debug-arm64. That file does the same as the x86-64 one, with bin/kernel-arm64.elf. Type continue to start the kernel. If neither GDB is installed, the script says so and suggests LLDB instead:

lldb bin/kernel-arm64.elf

At LLDB's prompt, connect with gdb-remote 1234.

Read a panic#

A panic report goes to the serial port and the screen, and also to the netconsole and the disk log when they're on. The CPU that panicked stops the other CPUs, and the machine then stays stopped with the report on its console, unless it was booted with panic=N: that resets it N seconds (1–3600) after the report has gone out. Here is the shape of the report, line by line as kernel/panic.cpp prints it:

PANIC:<function>():<file>,<line>: <message>
CPU: <index>
Task: pid <pid> name <task>
Backtrace:
  [0] 0x<address> <function>+0x<offset>
  [1] 0x<address> <function>+0x<offset>
Modules: <name> 0x<base>+0x<size>
Cpu <index> backtrace:
  [0] 0x<address> <function>+0x<offset>

• The first line says where the panic happened and why. A broken invariant caught by BugOn says BUG. A CPU exception shows what the CPU reported: EXC: PageFault cr2 0x... rip 0x... rsp 0x... err 0x... cr3 0x... on x86-64, or sync exception: ... (esr 0x... ec 0x... iss 0x...) far 0x... elr 0x... on arm64. A Rust panic starts with RUST PANIC: panicked at <file>:<line>:<column>:, followed by its message.
• Backtrace is the panicking CPU's stack. The kernel resolves the names itself, from a symbol table built into the image, so you don't need a symbol file. Each frame is a return address, named after the call that precedes it.
• A frame in a module's code ends with the module's name in brackets. The Modules: line, printed when any module is loaded, gives each module's address range, which places a frame nothing else could name.
• On x86-64 the kernel asks the other CPUs for their stacks with an NMI. Each answer follows as Cpu N backtrace:, and a CPU that doesn't answer is named (Cpu N did not answer the NMI).
• A frame printed as a bare address lies outside the kernel's code and every loaded module.

An example from Backtraces:

Backtrace:
  [0] 0xFFFF800012DA1C40 mod_hello::init::{closure#0}+0x3c [hello]
  [1] 0xFFFF80000104A2F1 Kernel::Cmd::DispatchDynamic+0xd1
...
Modules: hello 0xFFFF800012DA0000+0x5000

Some hangs are turned into panics so that they get reported. A spinlock held too long panics with Spinlock 0x... stuck, held ... ns. A TLB shootdown that gets no answer within ten seconds panics and names the CPUs that didn't answer.

To see a panic report on a throwaway VM, the shell has panic (a direct panic), panic pf (a page fault) and panic ud (an invalid instruction).

When a task is alive but stuck, ps lists the tasks, and bt <pid> prints one task's backtrace, using an IPI to ask the CPU it runs on. stacks shows the deepest point every stack has reached.

Read the kernel log and raise trace levels#

Every trace line has the form level:seconds.microseconds:function(),file,line: message. It goes to the kernel log, the serial port, and the netconsole and disk log when they're on. Once the shell is running, trace lines no longer reach the console. Read them with dmesg [lines] [filter], for example dmesg 40 or dmesg 100 virtio.

A line is printed when its level is at most the current trace level, which runs from 0 to 5 and defaults to 1. You can change the level in two ways:

• loglevel=N on the kernel command line. It's the only way to get more detail from the boot itself.
• loglevel N in the shell, on a running kernel. Run loglevel alone to see the current level. The command works over the UDP shell and SSH too, which matters on a machine with no other console.

The levels of the noisier subsystems are constants at the top of src/cpp/kernel/trace.h:

To see one subsystem without the rest, lower its constant and rebuild. Rust code traces with trace!(level, ...), on the same scale.

Bisect a failing boot#

Where you set the kernel command line depends on how you boot:

Nothing on the command line stops a boot: the kernel logs an unknown key or value and skips it, and the line is limited to 255 characters. Take things out of the boot path one at a time:

1. smp=off: the boot CPU alone. If the kernel boots this way, the problem is in bringing up the other CPUs.
2. maxcpus=2: the boot CPU and one more, then more. This keeps SMP while limiting how many CPUs come up.
3. loglevel=4: everything the boot does, allocations included.
4. Then the subsystems, one by one:
   • usb=off (x86-64): skips xHCI bring-up;
   • its=off (arm64): turns off the GICv3 ITS; PCIe MSI degrades, and virtio-mmio doesn't need it;
   • hwrng=off: ignores the CPU's random-number instruction;
   • rc=off: skips /etc/rc, which gets you past a line in it that keeps the machine from coming up;
   • dhcp=off: turns DHCP off entirely;
   • console=serial or console=vga: keeps the shell on one console only.

On x86-64, a boot that fails before any console exists prints ERR: and a digit on the screen. That means one of the early checks in boot64.asm failed: the Multiboot, CPUID or long-mode check.

All parameters are listed in Kernel parameters, and Boot explains what happens between the markers.

Get the log off a machine with no serial port#

On a laptop, a cloud VM or a dedicated server, there's often no serial port to read. nos offers these alternatives:

• Netconsole, for a boot that gets as far as its network. Boot with netconsole=ip:port dhcp=auto nctail=64, and run python3 scripts/netconsole.py -o boot.log on the receiving machine. nctail=64 makes a machine with little time left after its link comes up spend it on the newest lines. The log arrives from the first line of the boot, and includes a panic report if the collector's MAC address is already known. Setup is in Connect to a running nos.

• The disk log, for a boot that stops before its network is up. Under Linux on that machine, prepare a log area on a spare partition, boot nos with disklog=on, then read the log back at the next Linux boot:

  sudo ./scripts/disklog.py format /dev/nvme0n1p1
  sudo ./scripts/disklog.py read /dev/nvme0n1p1

  format refuses a device that still looks like it holds a filesystem, a RAID member or swap. Without disklog=on, nos doesn't even read any disk for this. With it but without a prepared area, the boot logs DiskLog: disklog=on, but no prepared area on any disk and carries on. The disklog shell command shows what it found.

• The screen. trace=vga (x86-64) shows the boot log on the screen as well as the serial port. On a machine with no UART that's already the default.

• panic=N. A machine whose only console is the network comes back N seconds after a panic, instead of staying stopped where nobody can see it.

Real hardware describes how these tools were used on the three machines nos runs on.

Build with undefined-behaviour checks#

A boot that hangs in some unrelated place, on one architecture only, can be undefined behaviour showing up far from its cause. Build with the checks on and boot the same way:

make nocheck UBSAN=1 RUSTUB=1
./scripts/smoke-test.sh --skip-build

The first undefined operation in the C++, or the first unsafe precondition that core finds violated in the Rust, panics and names its site. With ubsan=warn on the command line, the kernel prints every C++ report of the boot, each site once with a backtrace, instead of stopping at the first. For more, see Build nos.

Run the boot self-tests#

The self-tests run on every boot, from Test() in src/cpp/kernel/test.cpp, and a failing one panics with Self test failed. To run just one, edit Test() to call only that function, then rebuild, boot and watch nos.log.

Troubleshooting#

• target remote fails. QEMU isn't running with -s, or another QEMU already holds port 1234; only one can use it at a time.
• gdb-arm64.sh prints No aarch64 GDB found. Install gdb-multiarch or aarch64-elf-gdb, or use LLDB as shown above.
• bin/kernel-arm64.elf is missing. Building the x86-64 ISO deletes and recreates bin/. The same ELF is in the repository root, so copy it back: cp kernel-arm64.elf bin/.
• GDB's symbols don't match what's running. Load the ELF from the same build as the image you booted. After a rebuild, restart both QEMU and GDB.
• loglevel 4 floods everything. It traces every allocation, and every line also goes out the serial port. Run loglevel 1 to return to the default.
• The panic report never reached the netconsole. During a panic the report goes out only if the collector's MAC address is in the ARP cache. Also boot with disklog=on and a prepared area, or use panic=N to get the machine back.

Next steps#

• Run the gates: a check for each subsystem, for the failures a boot can't notice
• Connect to a running nos: the UDP shell, SSH and netconsole in detail
• Run nos in QEMU
• The full references: Debug, Kernel parameters, Profiler