Step 1 of 20

The shell opens f before echo even exists

The shell parsed echo hi > f into a redirection wrapped around an echo command, and forked. The child, pid 3, is still running the shell’s code. It closes descriptor 1 and opens f with O_WRONLY|O_CREATE|O_TRUNC (user/sh.c:395), so the new file gets the lowest free descriptor, 1. Only then does it exec echo.

For the disk, this command is three transactions that change the disk (the close, exec and exit calls also open transactions, but they log no blocks). A traced kernel printed them (block numbers in the order log_write first saw them):

This tour cuts the power during transaction 1. That is the interesting one: it changes an inode and a directory, two structures that must agree.

Step 2 of 20

sys_open starts a transaction and creates the file in memory

sys_open calls begin_op and then create (followed step by step in Tour 35: Creating and naming files). By the time create returns, three buffers in the buffer cache have changed:

• Block 34, which holds inodes 16–31: ialloc found inode 24 free, set its type to T_FILE, and create set nlink = 1.
• Block 47, the root directory’s only data block: dirlink wrote the entry {24, "f"} into the first empty slot, at byte offset 384.
• Block 33, which holds inode 1 (the root): writei always ends with iupdate, so the root’s inode block is logged although its bytes did not change.

None of these changes is on the disk yet. Each was handed to log_write, which only writes down the block number. Then the O_TRUNC branch calls itrunc, which logs block 34 again (absorbed: it is already in the list).

So the in-memory log header now reads n = 3, block = {34, 47, 33}, and the disk is exactly as it was before the command.

Step 3 of 20

log_write records a block number, not a write

This is the third distinct block, logged by iupdate of the root inode. At this moment pid 3 holds the root directory’s inode lock, the new inode 24’s lock (which create took before calling dirlink), and the buffer for block 33; log_write adds log.lock.

The loop looks for 33 among the blocks already listed (34 and 47). It is not there, so it is appended at index 2, n becomes 3, and bpin raises the buffer’s reference count.

The pin is what makes the plan work. The changed bytes exist only in this buffer. If the cache recycled it for another block before the commit, the change would be lost, and a later bread of block 33 would fetch the old contents from disk. A pinned buffer has refcnt > 0, and bget never recycles such a buffer.

Step 4 of 20

end_op sees it is the last one out and commits

sys_open finishes its work and calls end_op. Under log.lock (lines 159–172), log.outstanding drops from 1 to 0, so pid 3 is the last operation in the transaction. It sets log.committing = 1 and do_commit = 1, then releases the lock.

Line 177 calls commit without log.lock: committing means waiting for the disk, which means sleeping, and a process must not sleep holding a spinlock. The committing flag takes the lock’s place: it keeps every other process out of the log until the commit is over.

So the commit is done by the system call that happens to finish last, on its own kernel stack. Here that is open, on behalf of a shell that has not yet become echo.

Step 5 of 20

Four stages, and what the disk holds after each

commit is four disk operations in a fixed order. Each one waits for the disk to finish before the next starts. Here is what the disk holds if the power fails during or after each stage:

There is no row with a file half-created. Before the header write, the home blocks are untouched; after it, recovery will finish the job. The single write of block 2 decides which world the disk is in (assuming the header’s sector is written atomically, step 7).

The next four steps take each stage in turn, and for three of them we cut the power for real.

Step 6 of 20

Stage 1: copy the changed blocks into the log

For each listed block, write_log reads the log slot (log.start + tail + 1, so blocks 3, 4, 5), copies the cached block into it, and writes it with bwrite. The cached block 34 goes to log block 3, 47 to 4, 33 to 5.

bwrite returns only when the disk has finished the write. While it waits, pid 3 sleeps holding the two buffers’ sleep-locks: allowed, and the reason buffers have sleep-locks rather than spinlocks.

Cut the power here. We built a copy of the kernel that stops dead at the end of this stage (an infinite loop standing in for a power failure), killed QEMU, and inspected the image: inode 24 has type 0, the root directory ends with console, and the header says n= 0. Booting the unmodified kernel:

$ ls f
ls: cannot open f

The three log blocks hold new data, but nothing points at them. They are garbage that the next transaction overwrites.

Step 7 of 20

Stage 2: one block write is the commit

write_head copies the in-memory header into block 2 (n = 3, then 34, 47, 33) and writes it. When this bwrite completes, the transaction is committed: no matter what happens next, f will exist after the next boot.

Why can one write decide? Because it is assumed to be all-or-nothing. The header’s meaningful bytes (4 for n, 4 per block number: 16 here, at most 124) sit in the first 512-byte sector of the block. xv6 assumes, without saying so in the code, that the disk writes such a sector all-or-nothing; the other sector of block 2 holds nothing that matters, so its tearing is harmless. Real disks generally give this guarantee for a single sector; QEMU plus a host file gives it only as far as the host’s write path does.

In QEMU, by the time the device reports a write complete, QEMU has written it into fs.img, so killing QEMU cannot lose it. xv6 also leaves VIRTIO_BLK_F_FLUSH unnegotiated (xv6 commit 0024d4b); under the virtio spec (§5.2.6.2) that obliges the device to make each write stable before reporting it complete, and QEMU does so by running the disk in writethrough mode. Whether “stable” survives a crash of the host computer depends on the host OS and drive; this tour only simulates a crash of the guest machine.

Cut the power right after this write. The image now holds the old home blocks (inode 24 still free, no f in the root directory) and a header reading n= 3 (34, 47, 33). Rebooting the unmodified kernel prints:

recovering tail 0 dst 34
recovering tail 1 dst 47
recovering tail 2 dst 33
init: starting sh
$ ls f
f              2 24 0

Step 8 of 20

Stage 3: install the blocks at home

install_trans with recovering = 0 writes each block to its real place. It reads the log copy and the home block, copies one onto the other, and writes the home block. Both are normally still in the cache (the log blocks were just written by write_log), so normally no disk reads happen. bunpin then drops the pin that log_write added: the buffer may be recycled again.

This stage is the dangerous one if there were no log. Cut the power after the first home write (block 34) and look at the image:

• inode 24: type 2 (file), nlink 1, size 0;
• the root directory: still ends with console. No entry names inode 24.

That is an inode marked in use that no path reaches. Without a log it would be lost for good, and note that ireclaim could not save it either, because it looks only for nlink == 0. But the header still says n = 3, so the next boot installs all three blocks again, and ls f shows f 2 24 0 exactly as before.

Installing block 34 a second time is harmless. The log holds whole new block contents (a “redo” log), so writing them again gives the same result: recovery is idempotent. It can even crash and be rerun.

Step 9 of 20

Stage 4: erase the transaction, and let the others in

With every block at home, the log is no longer needed. log.lh.n = 0 and a second write_head put n = 0 on disk.

This write must come after installation and before the next transaction writes the log. If the header still said n = 3 when the next commit overwrote log blocks 3–5 with other data, a crash at that point would make recovery install the wrong contents into blocks 34, 47 and 33.

Then commit returns to end_op, which takes log.lock, clears log.committing, counts the commit in log.ncommit and wakes everyone sleeping on &log (kernel/log.c:181).

The bill for creating one file: 3 log writes, 2 header writes, 3 home writes, eight synchronous disk writes, where a file system without a log would do three. That is the price of never having a half-created file.

Step 10 of 20

The power cut, as test-xv6.py does it

There is no power switch on QEMU, but there is something just as abrupt: killing it. crash() finds QEMU (the child of make qemu) and sends it SIGKILL. QEMU gets no chance to finish anything. The disk image file keeps exactly the writes that QEMU had already made to it, which is the state a real disk would be in after a power failure.

For the experiments in the previous steps we did the same thing by hand, after making a modified copy of the kernel stop at a chosen line of commit. (On macOS, crash() fails as written: its ps --ppid is a Linux option that macOS’s ps lacks. Change that call to pgrep -P in your copy of the script.)

Everything in the kernel’s memory is now gone: the buffer cache, the inode table, log.lh, the processes. Only the 2000 blocks of fs.img remain.

Step 11 of 20

The next boot, in the first process

Recovery does not happen in main. It happens the first time any process runs: the very first process (pid 1), in forkret, before it becomes /init.

The source comment gives the reason. Reading the disk means waiting for it, and waiting means sleep, which needs a process to put to sleep. main runs on hart 0’s boot stack with no process at all.

So when userinit has made pid 1 runnable, whichever hart’s scheduler picks it up first lands here, releases p->lock (taken by the scheduler), and, because first is 1, calls fsinit. Interrupts are still off: the scheduler acquired p->lock with interrupts already disabled, so release does not turn them back on, and nothing on the way to /init does either. Pid 1 cannot be preempted by a timer while it repairs the disk; disk-completion interrupts are taken by a hart sitting in its scheduler loop, including this one while pid 1 sleeps. Only after the disk is repaired does kexec("/init") read anything from it.

The stack is part of that reason (The stacks of xv6). To sleep, a thread must leave its call chain somewhere that survives while the hart does other work. A process has such a place, its kernel stack; main’s boot stack is the hart’s own and becomes the scheduler stack, which the hart needs while pid 1 sleeps. Pid 1’s kernel stack, KSTACK(0), was empty when the scheduler’s swtch loaded p->context.sp, set to the top of that page by allocproc (kernel/proc.c:147), and “returned” into forkret through context.ra. So forkret is the bottom frame. There is no usertrap below it: pid 1 has never been in user mode.

Step 12 of 20

fsinit checks the superblock, then repairs, then reclaims

fsinit reads block 1, the superblock, into the global sb, and refuses to go on if its magic number is wrong. The superblock tells the kernel where everything is: logstart = 2, inodestart = 33, bmapstart = 46, ninodes = 200.

Then, in this order:

1. initlog: set up the log and recover it.
2. ireclaim: free inodes orphaned by the crash.

The order matters. ireclaim reads inode blocks to decide which inodes are orphans. Before recovery those blocks may be stale, like block 34 in the stage 2 experiment, which still showed inode 24 as free. And ireclaim itself runs transactions, which must not start while an old committed transaction is still sitting in the log.

Step 13 of 20

initlog reads the header

initlog (kernel/log.c:55) records where the log starts and calls recover_from_log, which calls read_head: read block 2 and copy n and the block numbers into log.lh.

In the “power cut after stage 1” experiment, this reads n = 0, and recovery does nothing. In the stage 2 and stage 3 experiments, it reads n = 3 and the list 34, 47, 33, the very list that pid 3’s log_write calls built in memory before the crash. The in-memory header died; its copy on disk survived. That is why the header on disk holds block numbers and not only a flag.

Step 14 of 20

install_trans, in recovery mode

The same function that ran as stage 3 of the commit runs again, with recovering = 1. Two differences:

• It prints a line per block. These are the lines you saw after the stage 2 cut: recovering tail 0 dst 34 and so on.
• It skips bunpin. The pins were taken by log_write in the previous boot; in this boot’s freshly initialized cache nothing was ever pinned, and unpinning would drive refcnt below its true value.

Here, unlike in a normal commit, the bread calls really go to the disk: the cache is empty after a boot. So recovery of n blocks costs 2n reads and n writes.

Each of those disk operations parks pid 1 on its kernel stack, exactly as cat was parked in Tour 29: A disk read, end to end, but with a different bottom:

pid 1's kernel stack (KSTACK(0)), sleeping during recovery
  top ─► forkret
         fsinit · initlog (recover_from_log is inlined into it) · install_trans
         bread or bwrite · virtio_disk_rw · sleep · sched   ← p->context.sp

Because pid 1 runs with interrupts off, no kernelvec frame is ever pushed onto this stack: every disk interrupt during recovery lands on some hart’s scheduler stack.

Step 15 of 20

Clear the log, and the disk is consistent again

After installing, log.lh.n = 0 and write_head erase the transaction, just as stage 4 of a normal commit does. If the power fails during recovery itself, the next boot finds the same header and installs the same blocks again. Idempotence, from step 8, is what makes that safe.

Look at what ls f printed after the stage 2 cut: f 2 24 0. The file exists, but it is empty. The hi was going to be written by transactions 2 and 3, which never started. The log promises atomicity (each transaction entirely or not at all), not that the last thing you typed survives. A program that needs its data on disk must wait for its own transaction to commit; sync (sys_sync) is the system call that waits for that.

Step 16 of 20

How an orphan is made, on purpose

The log keeps each system call atomic, but some states are perfectly consistent and still wasteful after a crash. forphan builds one. It creates file0 (inode 24 on a fresh disk), then unlinks it while the descriptor is still open.

sys_unlink removes the directory entry and drops nlink to 0, all in one committed transaction. But the inode is not freed: the open file still holds a reference, and iput frees an inode only when the last reference and the last link are gone (Tour 33: The life of an inode). On a running system that happens at close or exit.

forphan never closes. Kill QEMU now, and the disk holds inode 24 with type 2, nlink 0: allocated, reachable by no name, and with no process left to close it. user/dorphan.c does the same with a directory: it chdirs into dd and unlinks it as ../dd, so its current-directory reference is the last one.

Step 17 of 20

ireclaim scans every inode for orphans

ireclaim reads every inode, 1 to 199, from the 13 inode blocks. An inode with type != 0 and nlink == 0 is an orphan: allocated, but no directory entry names it. After the forphan crash, the boot prints

ireclaim: orphaned inode 24
init: starting sh

and ls file0 finds nothing, as before; the inode and its blocks are free again. The dorphan crash produces the same line for its directory, also inode 24.

Notice the order on lines 397–399: iget takes a reference (no disk access), then brelse releases block 34, and only then does the next step lock the inode. ilock will read block 34 itself, and a process that tried to take a buffer sleep-lock it already holds would wait for itself forever.

Step 18 of 20

The orphan gets the close it never had

For each orphan, ireclaim opens a transaction and replays a final close: ilock (which reads the inode, so valid = 1), iunlock, iput.

In iput, ref == 1, valid == 1 and nlink == 0, so last is true. It locks the inode, itrunc frees its data blocks in the bitmap (file0 never had any), then ref drops to 0 and ifree sets the on-disk type to 0. All of that is in one transaction, committed by end_op at kernel/fs.c:405. If the power fails during ireclaim, the next boot finds the orphan either untouched (and reclaims it again) or fully freed.

One detail of iput is unusual: line 362 calls acquiresleep while still holding the spinlock itable.lock (noff 2 inside it, 3 for a moment in its myproc()). That is legal only because ref == 1 means nobody else can hold the inode’s lock, so it never sleeps (Locks and interrupt state).

This is the same code path a normal close of a deleted file takes. Recovery does not need special repair code: it re-creates the missing event.

Step 19 of 20

The test that does all of this twenty times

./test-xv6.py crash automates the experiment. crash_log builds a fresh image, runs logstress f0 f1 f2 f3 f4 f5 (six processes, each trying to write 250 × 2000 bytes to its own file, more than an xv6 file can hold, but the kill comes long before that) and kills QEMU after 2 seconds. recover_log boots again and passes if a recovering line appears. A kill only catches a committed-but-not-cleared log some of the time, so test_log retries up to 20 times. Our run (3 harts) needed three tries:

kill 33894
log attempt  1
kill 35387
log attempt  2
kill 36439
recovering tail 0 dst 1176
recovering tail 1 dst 46
…
recovering tail 13 dst 1186
f5             2 29 20000
OK

Fourteen blocks from several processes’ writes, data blocks and the bitmap together: one group-committed transaction. The orphan tests then look for ^ireclaim. In our run the harness’s monitor('wait') in forphan() (test-xv6.py:152) timed out (its re.match is anchored at the start of a line), because the program’s message arrived on the same line as the shell prompt ($ wait for kill…); running the same steps by hand gave the ireclaim: orphaned inode 24 shown in step 17.

Step 20 of 20

What it cost, and what it bought

Step back and count. Every transaction writes each changed block twice (log, then home) and the header twice, all synchronously, in order. Creating f cost eight disk writes for three blocks’ worth of change. A boot after a crash costs one header read, then 2n reads and n + 1 writes, then a scan of all 13 inode blocks.

What that buys is a short list of facts that hold whenever the power fails:

• Each transaction is on disk entirely or not at all. The decision is one block write, the header, whose meaningful bytes all lie in one sector that is assumed to be written atomically.
• Nothing reaches a home block before its transaction is committed (the log_write pin keeps it in memory), so recovery only ever has to redo, never undo.
• Redoing is idempotent, so a crash during recovery is harmless.
• Files deleted while open are reclaimed at boot by ireclaim, by replaying the missing final iput.

What it does not buy: system calls that had not finished when the power failed, and ones whose shared transaction had not yet committed because other calls were still in it. A call that runs alone is committed before it returns; when other calls keep the transaction open, sync (sys_sync) waits for the next commit.