Logging and crash recovery · xv6, line by line

1warm-upChoose one

balloc has just set a bit in the bitmap buffer and calls log_write on it. What has happened on the disk by the time log_write returns?

kernel/log.c

223void
224log_write(struct buf *b)
225{
int i;
227
acquire(&log.lock);
if (log.lh.n >= LOGBLOCKS)
  panic("too big a transaction");
if (log.outstanding < 1)
  panic("log_write outside of trans");
233
for (i = 0; i < log.lh.n; i++) {
  if (log.lh.block[i] == b->blockno) // log absorption
    break;
}
log.lh.block[i] = b->blockno;
if (i == log.lh.n) { // Add new block to log?
  bpin(b);
  log.lh.n++;
}
release(&log.lock);
244}

Nothing. log_write only records the block number in the in-memory header and pins the buffer; the disk is written later, by the commit.The block has been copied into the next free log block on disk.The log header on disk now lists the block, so the change is already committed.The block has been written to its home location, and its number added to the log so recovery can undo it.

2warm-upClick the line

In commit, click the line whose disk write is the moment the transaction becomes durable: if the power fails before this write completes, the transaction never happened; after it, the next boot will finish it.

kernel/log.c

202static void
203commit()
204{
205  if (log.lh.n > 0) {
206    write_log();      // Write modified blocks from cache to log
207    write_head();     // Write header to disk -- the real commit
208    install_trans(0); // Now install writes to home locations
209    log.lh.n = 0;
210    write_head(); // Erase the transaction from the log
211  }
212}

Your pick: none yet (click a line in the code)

3warm-upPut in order

The last end_op of a group commits it. Put these events in the order they happen.

kernel/log.c

152// called at the end of each FS system call.
153// commits if this was the last outstanding operation.
154void
155end_op(void)
156{
157  int do_commit = 0;
158
159  acquire(&log.lock);
160  log.outstanding -= 1;
161  if (log.committing)
162    panic("log.committing");
163  if (log.outstanding == 0) {
164    do_commit = 1;
165    log.committing = 1;
166  } else {
167    // begin_op() may be waiting for log space,
168    // and decrementing log.outstanding has decreased
169    // the amount of reserved space.
170    wakeup(&log);
171  }
172  release(&log.lock);
173
174  if (do_commit) {
175    // call commit w/o holding locks, since not allowed
176    // to sleep with locks.
177    commit();
178    acquire(&log.lock);
179    log.committing = 0;
180    log.ncommit += 1;
181    wakeup(&log);
182    release(&log.lock);
183  }
184}
185
186// Copy modified blocks from cache to log.
187static void
188write_log(void)
189{
190  int tail;
191
192  for (tail = 0; tail < log.lh.n; tail++) {
193    struct buf *to = bread(log.dev, log.start + tail + 1); // log block
194    struct buf *from = bread(log.dev, log.lh.block[tail]); // cache block
195    memmove(to->data, from->data, BSIZE);
196    bwrite(to); // write the log
197    brelse(from);
198    brelse(to);
199  }
200}
201
202static void
203commit()
204{
205  if (log.lh.n > 0) {
206    write_log();      // Write modified blocks from cache to log
207    write_head();     // Write header to disk -- the real commit
208    install_trans(0); // Now install writes to home locations
209    log.lh.n = 0;
210    write_head(); // Erase the transaction from the log
211  }
212}

end_op clears committing, increments ncommit, and wakes sleepers on &log
end_op sets log.committing = 1 under log.lock, then releases the lock
write_head again, with n = 0: erase the transaction
write_log: copy each logged block from the cache into the log area
write_head: write the header with n and the block list (the commit point)
install_trans(0): copy each block to its home location and unpin it

4warm-upType a number

The log is empty (log.lh.n = 0) and no commit is running. Processes keep calling begin_op and none of them has reached end_op yet. How many of them are admitted before the next one has to sleep?

kernel/log.c

127// called at the start of each FS system call.
128void
129begin_op(void)
130{
acquire(&log.lock);
while (1) {
  if (log.committing) {
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  } else if (log.lh.n + (log.outstanding + 1) * MAXOPBLOCKS > LOGBLOCKS) {
    // this op might exhaust log space; wait for commit.
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  } else {
    log.outstanding += 1;
    release(&log.lock);
    break;
  }
}
150}

decimal, 0x hex or 0b binary

5solidPut in order

The machine crashed with a committed transaction still in the log. Put the steps of the next boot’s file-system start-up in order.

write_head writes n = 0, clearing the log
ireclaim scans the inodes for orphans (allocated, nlink == 0) and frees them
fsinit reads the superblock (block 1) and checks its magic number
read_head copies n and the block list from the header block into log.lh
install_trans(1) copies each log block to its home block, printing recovering tail …

6warm-upChoose one

Inside one transaction, writei changes block 1006 and calls log_write; a moment later the same transaction changes block 1006 again and calls log_write a second time. What does the second call do?

kernel/log.c

223void
224log_write(struct buf *b)
225{
int i;
227
acquire(&log.lock);
if (log.lh.n >= LOGBLOCKS)
  panic("too big a transaction");
if (log.outstanding < 1)
  panic("log_write outside of trans");
233
for (i = 0; i < log.lh.n; i++) {
  if (log.lh.block[i] == b->blockno) // log absorption
    break;
}
log.lh.block[i] = b->blockno;
if (i == log.lh.n) { // Add new block to log?
  bpin(b);
  log.lh.n++;
}
release(&log.lock);
244}

It writes the first version to disk immediately to make room for the second.It adds a second entry for 1006, so the commit writes both versions in order.It panics, because a block may be logged only once per transaction.It finds 1006 already in log.lh.block[], adds nothing, and does not pin the buffer again.

7warm-upChoose one

Three processes are inside transactions (log.outstanding = 3). They call end_op one after another. Which call runs commit?

kernel/log.c

152// called at the end of each FS system call.
153// commits if this was the last outstanding operation.
154void
155end_op(void)
156{
int do_commit = 0;
158
acquire(&log.lock);
log.outstanding -= 1;
if (log.committing)
  panic("log.committing");
if (log.outstanding == 0) {
  do_commit = 1;
  log.committing = 1;
} else {
  // begin_op() may be waiting for log space,
  // and decrementing log.outstanding has decreased
  // the amount of reserved space.
  wakeup(&log);
}
release(&log.lock);
173
if (do_commit) {
  // call commit w/o holding locks, since not allowed
  // to sleep with locks.
  commit();
  acquire(&log.lock);
  log.committing = 0;
  log.ncommit += 1;
  wakeup(&log);
  release(&log.lock);
}
184}

None of them; a kernel thread commits the log in the background every few ticks.The first one, since its transaction finished first.The third one, the call that brings outstanding to 0; it commits all three processes’ changes together.Each of them commits its own changes, one after another.

8warm-upMatch the pairs

echo hi > f is creating f (blocks 34, 47 and 33 are logged). Match each moment of power failure with what the disk shows after the next boot.

during write_logjust after the first write_head completesduring install_trans, after block 34 but before 47 reached homeafter the second write_head (n = 0) completes

9solidChoose one

Why does log_write call bpin when it adds a new block to the transaction?

kernel/log.c

223void
224log_write(struct buf *b)
225{
int i;
227
acquire(&log.lock);
if (log.lh.n >= LOGBLOCKS)
  panic("too big a transaction");
if (log.outstanding < 1)
  panic("log_write outside of trans");
233
for (i = 0; i < log.lh.n; i++) {
  if (log.lh.block[i] == b->blockno) // log absorption
    break;
}
log.lh.block[i] = b->blockno;
if (i == log.lh.n) { // Add new block to log?
  bpin(b);
  log.lh.n++;
}
release(&log.lock);
244}

To tell the disk driver to write the buffer at the next commit.The changed bytes exist only in that cached buffer; the pin keeps refcnt above 0 so bget cannot recycle the buffer for another block before the commit.Because bwrite panics if it is called on a buffer whose refcnt is 0.To keep other processes from reading or modifying the block until the transaction commits.

10solidChoose one

end_op releases log.lock before calling commit (line 172, then 177). What would happen if it called commit() while still holding log.lock?

kernel/log.c

152// called at the end of each FS system call.
153// commits if this was the last outstanding operation.
154void
155end_op(void)
156{
int do_commit = 0;
158
acquire(&log.lock);
log.outstanding -= 1;
if (log.committing)
  panic("log.committing");
if (log.outstanding == 0) {
  do_commit = 1;
  log.committing = 1;
} else {
  // begin_op() may be waiting for log space,
  // and decrementing log.outstanding has decreased
  // the amount of reserved space.
  wakeup(&log);
}
release(&log.lock);
173
if (do_commit) {
  // call commit w/o holding locks, since not allowed
  // to sleep with locks.
  commit();
  acquire(&log.lock);
  log.committing = 0;
  log.ncommit += 1;
  wakeup(&log);
  release(&log.lock);
}
184}

Disk interrupts would be lost, because log.lock blocks the disk interrupt handler.Nothing bad; it would only make the commit a little slower.Other harts’ begin_op would spin forever, but the committing process would finish normally.The kernel would panic with “sched locks” at the first disk operation that waits (a bread miss or the first bwrite), because commit sleeps waiting for the disk while a spinlock is held.

11solidType a number

One transaction is running (log.outstanding = 1, log.committing = 0). A second process calls begin_op. What is the largest value of log.lh.n for which it is admitted without sleeping?

kernel/log.c

127// called at the start of each FS system call.
128void
129begin_op(void)
130{
acquire(&log.lock);
while (1) {
  if (log.committing) {
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  } else if (log.lh.n + (log.outstanding + 1) * MAXOPBLOCKS > LOGBLOCKS) {
    // this op might exhaust log space; wait for commit.
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  } else {
    log.outstanding += 1;
    release(&log.lock);
    break;
  }
}
150}

decimal, 0x hex or 0b binary

12deepType a number

A process writes 2000 bytes at offset 0 to an empty regular file (no data blocks yet). The log was empty and no other transaction runs. The filewrite chunk is one transaction. How many distinct blocks are in log.lh.block[] when end_op commits?

decimal, 0x hex or 0b binary

13solidChoose all that apply

Which of these situations make begin_op put the caller to sleep?

kernel/log.c

127// called at the start of each FS system call.
128void
129begin_op(void)
130{
acquire(&log.lock);
while (1) {
  if (log.committing) {
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  } else if (log.lh.n + (log.outstanding + 1) * MAXOPBLOCKS > LOGBLOCKS) {
    // this op might exhaust log space; wait for commit.
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  } else {
    log.outstanding += 1;
    release(&log.lock);
    break;
  }
}
150}

log.outstanding is greater than 0log.lh.n + (log.outstanding + 1) * MAXOPBLOCKS is greater than LOGBLOCKSAnother process holds the inode lock of the file this process will writelog.committing is 1log.lh.n is greater than 0

14warm-upTrue or false, and why

True or false: in this kernel, once a write() to a regular file has returned to user space, its data is on the disk.

TrueFalse

Why?

Its end_op may not have been the last one out; the group commit then happens later, in another process’s end_op.write() never touches the disk; only sync() writes file data.The data stays in the buffer cache until the buffer is evicted, which can take minutes.

15solidChoose one

install_trans calls bunpin only when recovering == 0. Why does it skip the unpin during crash recovery?

kernel/log.c

66// Copy committed blocks from log to their home location
67static void
68install_trans(int recovering)
69{
int tail;
71
for (tail = 0; tail < log.lh.n; tail++) {
  if (recovering) {
    printk("recovering tail %d dst %d\n", tail, log.lh.block[tail]);
  }
  struct buf *lbuf = bread(log.dev, log.start + tail + 1); // read log block
  struct buf *dbuf = bread(log.dev, log.lh.block[tail]);   // read dst
  memmove(dbuf->data, lbuf->data, BSIZE); // copy block to dst
  bwrite(dbuf);                           // write dst to disk
  if (recovering == 0)
    bunpin(dbuf);
  brelse(lbuf);
  brelse(dbuf);
}
85}

Because bunpin takes bcache.lock, which cannot be acquired before the scheduler starts.The pins were taken by log_write in the previous boot; in this boot’s fresh buffer cache nobody pinned these buffers, so unpinning would push refcnt below its true value.Because during recovery the blocks are written with bwrite, which unpins automatically.To keep the recovered blocks in the cache permanently for faster booting.

16deepChoose all that apply

At the end of a commit, end_op calls wakeup(&log) (line 181). Which of these sleeping processes can it wake?

A process in sys_sync waiting for ncommit to advanceA process waiting in bread for a buffer that the committing process holdsAn earlier end_op caller of the same group, waiting for its data to reach the diskA process in begin_op that found too little room in the logA process in begin_op that found log.committing setA process in virtio_disk_rw waiting for its own read to complete

17solidChoose one

Crash recovery runs from forkret in the first process (pid 1), not from main. Why?

kernel/proc.c

512void
513forkret(void)
514{
extern char userret[];
static int first = 1;
struct proc *p = myproc();
518
// Still holding p->lock from scheduler.
release(&p->lock);
521
if (first) {
  first = 0;
524
  // File system initialization must be run in the context of a
  // regular process (e.g., because it calls sleep), and thus cannot
  // be run from main().
  fsinit(ROOTDEV);
529
  // We can invoke kexec() now that file system is initialized.
  // Put the return value (argc) of kexec into a0.
  p->trapframe->a0 = kexec("/init", (char *[]){"/init", 0});
  if (p->trapframe->a0 == -1) {
    panic("exec");
  }
}

So that recovery runs on every hart in parallel and finishes faster.Because the log can only be read after /init has been loaded.Recovery reads and writes the disk, and every disk operation sleeps; sleeping needs a process, and main runs on a boot stack with no process.Because main runs in machine mode, which cannot access the virtio disk.

18solidChoose all that apply

Which of these run inside a transaction (begin_op … end_op) in this kernel?

19solidDecode the bits

After a crash, gdb shows the first 16 bytes of block 2 (the log header, struct logheader, little-endian 32-bit ints) as 03 00 00 00 22 00 00 00 2f 00 00 00 21 00 00 00. sb.logstart is 2. Decode it.

Value: 03000000 22000000 2f000000 21000000

nblock[0], the home of the first logged blockWhich log block holds the new contents for home block 47 (0x2f)?Was this transaction committed before the crash?What does the next boot do?

20solidClick the line

While a commit is running, log.lock is not held. Click the line in end_op that keeps new transactions from starting during the commit.

kernel/log.c

152// called at the end of each FS system call.
153// commits if this was the last outstanding operation.
154void
155end_op(void)
156{
int do_commit = 0;
158
acquire(&log.lock);
log.outstanding -= 1;
if (log.committing)
  panic("log.committing");
if (log.outstanding == 0) {
  do_commit = 1;
  log.committing = 1;
} else {
  // begin_op() may be waiting for log space,
  // and decrementing log.outstanding has decreased
  // the amount of reserved space.
  wakeup(&log);
}
release(&log.lock);
173
if (do_commit) {
  // call commit w/o holding locks, since not allowed
  // to sleep with locks.
  commit();
  acquire(&log.lock);
  log.committing = 0;
  log.ncommit += 1;
  wakeup(&log);
  release(&log.lock);
}
184}

Your pick: none yet (click a line in the code)

21deepFill in the machine state

The machine is booting after a crash. pid 1 is in install_trans during recovery, executing line 78 (the memmove from the log block’s buffer to the home block’s buffer). Both buffers are held. What is the state of the hart running it?

kernel/log.c

66// Copy committed blocks from log to their home location
67static void
68install_trans(int recovering)
69{
int tail;
71
for (tail = 0; tail < log.lh.n; tail++) {
  if (recovering) {
    printk("recovering tail %d dst %d\n", tail, log.lh.block[tail]);
  }
  struct buf *lbuf = bread(log.dev, log.start + tail + 1); // read log block
  struct buf *dbuf = bread(log.dev, log.lh.block[tail]);   // read dst
  memmove(dbuf->data, lbuf->data, BSIZE); // copy block to dst
  bwrite(dbuf);                           // write dst to disk
  if (recovering == 0)
    bunpin(dbuf);
  brelse(lbuf);
  brelse(dbuf);
}
85}

Privilege modeActive stackPage table (satp)Interrupts (sstatus.SIE)noffintena

22deepChoose one

commit reads log.lh.n and log.lh.block[] without holding log.lock, although log_write changes them under that lock. Why is this not a race?

kernel/log.c

202static void
203commit()
204{
205  if (log.lh.n > 0) {
206    write_log();      // Write modified blocks from cache to log
207    write_head();     // Write header to disk -- the real commit
208    install_trans(0); // Now install writes to home locations
209    log.lh.n = 0;
210    write_head(); // Erase the transaction from the log
211  }
212}

It is a race, but harmless, because absorption hides duplicate entries.Because log.lh is only ever changed by the committing process itself.Because commit runs with interrupts disabled, so no other code can run.committing is 1 and outstanding is 0: begin_op admits nobody, so no process can be inside a transaction to call log_write.

23deepChoose one

Suppose commit omitted line 210 (it still sets log.lh.n = 0 in memory, but no longer writes the empty header). The disk header would keep saying n = 3: 34, 47, 33 after this commit. What could go wrong?

kernel/log.c

202static void
203commit()
204{
205  if (log.lh.n > 0) {
206    write_log();      // Write modified blocks from cache to log
207    write_head();     // Write header to disk -- the real commit
208    install_trans(0); // Now install writes to home locations
209    log.lh.n = 0;
210    write_head(); // Erase the transaction from the log
211  }
212}

The next commit’s write_log overwrites log blocks 3, 4, 5 with new, uncommitted data; a crash then makes recovery copy that data into blocks 34, 47 and 33.begin_op would refuse all new transactions, because it reads n from the disk header.Nothing; replaying an old transaction is harmless because the redo log is idempotent.The next boot would panic in read_head because n is not 0.

24deepChoose one

A process calls sync() while log.committing = 0, log.outstanding = 2 and log.ncommit = 5. When does sys_sync return?

kernel/log.c

246uint64
247sys_sync(void)
248{
acquire(&log.lock);
if (log.committing || log.outstanding > 0) {
  int n = log.ncommit + 1;
  while (log.ncommit < n) {
    sleep_prepare(&log);
    release(&log.lock);
    sleep();
    acquire(&log.lock);
  }
}
release(&log.lock);
return 0;
261}

Immediately, since no commit is in progress.After ncommit reaches 6, that is, once outstanding has dropped to 0 and the commit including the two running transactions has finished.After sync itself commits the log by calling commit().Once the two running transactions call end_op, even before any disk write.

25solidType a number

A commit finds log.lh.n = 4. How many disk writes does commit issue in total? (Count writes only, not reads.)

kernel/log.c

186// Copy modified blocks from cache to log.
187static void
188write_log(void)
189{
190  int tail;
191
192  for (tail = 0; tail < log.lh.n; tail++) {
193    struct buf *to = bread(log.dev, log.start + tail + 1); // log block
194    struct buf *from = bread(log.dev, log.lh.block[tail]); // cache block
195    memmove(to->data, from->data, BSIZE);
196    bwrite(to); // write the log
197    brelse(from);
198    brelse(to);
199  }
200}
201
202static void
203commit()
204{
205  if (log.lh.n > 0) {
206    write_log();      // Write modified blocks from cache to log
207    write_head();     // Write header to disk -- the real commit
208    install_trans(0); // Now install writes to home locations
209    log.lh.n = 0;
210    write_head(); // Erase the transaction from the log
211  }
212}

decimal, 0x hex or 0b binary