6.828/2018 Homework: xv6 log

This is the last xv6 homework. Tomorrow I will be doing IJCTF, and after that, I will start doing Lab5.

---

Our first mission is to generate a crash. By changing commit() into:

#include "mmu.h"
#include "proc.h"
void
commit(void)
{
  int pid = myproc()->pid;
  if (log.lh.n > 0) {
    write_log();
    write_head();
    if(pid > 1)            // AAA
      log.lh.block[0] = 0; // BBB
    install_trans();
    if(pid > 1)            // AAA
      panic("commit mimicking crash"); // CCC
    log.lh.n = 0; 
    write_head();
  }
}

We panic the kernel in the middle of commit() on purpose. If we boot xv6 and do echo hi > a in the shell:

cpu0: starting 0
sb: size 20000 nblocks 19937 ninodes 200 nlog 30 logstart 2 inodestart 32 bmap start 58
init: starting sh
$ echo hi > a
lapicid 0: panic: commit mimicking crash
80102e2e 80105126 80104929 801
058e5 801056ff 0 0 0 0 0

Where did we crash? The log, including header, should already been written to the disk. However, install_trans() was done with the corrupted log header in memory (see line BBB) so that the first block in the log was written to block 0, instead of where it should be. The echo hi > a command in the shell should first create a file named a before letting echo to write() hi to it, so the first block in the log should contain the inode of a (issued in ialloc(), called by create(), which in turn called by sys_open()). Here we did something nasty so that the update to this inode block was lost.

Luckily, however, this transaction has already been committed, since the log has already been written to the disk. So ideally when we reboot xv6, recover_from_log() will be called in initlog, notice the committed-but-not-installed-yet log, call install_trans(), this time copying all the log blocks to the right places.

However, if we change recover_from_log() as well like this: 🙂

static void
recover_from_log(void)
{
  read_head();      
  cprintf("recovery: n=%d but ignoring\n", log.lh.n);
  // install_trans();
  log.lh.n = 0;
  // write_head();
}

This will prevent it from doing the real work. So if we try to access file a after the reboot:

cpu0: starting 0
sb: size 20000 nblocks 19937 ninodes 200 nlog 30 logstart 2 inodestart 32 bmap start 58
recovery: n=2 but ignoring
init: starting sh
$ cat a
lapicid 0: panic: ilock: no type
80101807 801050d8 80104929 801058e5 801056ff 0 0 0 0 0

namex() finds a record with name a in the current directory, then it tries to ilock() it. ilock() loads the block, which supposed to be containing the inode of a, but it will never find it, since the update when we were creating it was written to block 0. Therefore, ilock() panic()s:

    if(ip->type == 0)
      panic("ilock: no type");

However the committed-but-not-installed-yet blocks are still in the log region of the disk. So if we fix recover_from_log() back to normal:

static void
recover_from_log(void)
{
  read_head();
  cprintf("recovery: n=%d\n", log.lh.n);
  install_trans(); // if committed, copy from log to disk
  log.lh.n = 0;
  write_head(); // clear the log
}

Then reboot:

cpu0: starting 0
sb: size 20000 nblocks 19937 ninodes 200 nlog 30 logstart 2 inodestart 32 bmap start 58
recovery: n=2
init: starting sh
$ cat a
$

It did not crash! recover_from_log() completed the transaction and created the inode of a for us.

Why was the file empty, even though you created it with echo hi > a?

Homework: xv6 log

This question actually took me for quite a while to think about. I still can’t tell for sure yet, but I believe this is because when we did echo hi > a, the shell first open()ed (and create()ed) a, then it executed echo to call printf(), which finally write() our hi message to a. Since whenever log.outstanding == 0 (currently no syscall is writing to the log), end_op() calls commit(), chances are the panic happened after a was create()d but before echo got a chance to write() anything to it yet. I added some cprintf()s to test my theory:

commit!
commit!
commit!
write!
$commit!
write!
commit!
echo hello > a
commit!
lapicid 0: panic: commit mimicking crash
80102e0e 80105196 80104999 80105955 8010576f 0 0 0 0 0

See? There’s no write()s before the panic. That’s why the recovered a was empty.

Our one last task is to make the commit() more efficient:

Since the modified block 33 is guaranteed to already be in the buffer cache, there’s no need for install_trans() to read block 33 from the log. Your job: modify log.c so that, when install_trans() is called from commit(), install_trans() does not perform the needless read from the log.

Homework: xv6 log

Before commit()ing, the updated block 33 is the only copy (in this world) which contains the update. log_write() has set the B_DIRTY flag of it to prevent its “eviction”. So why bother reading from the disk? I added a parameter to install_trans() and modified it like this:

// Copy committed blocks from log to their home location
static void
install_trans(int recover_from_log)
{
  int tail;

  for (tail = 0; tail < log.lh.n; tail++) {
    struct buf *dbuf = bread(log.dev, log.lh.block[tail]); // read dst

    if (recover_from_log) {
      struct buf *lbuf = bread(log.dev, log.start+tail+1);  // read log block
      memmove(dbuf->data, lbuf->data, BSIZE);  // copy block to dst
      brelse(lbuf);
    }

    bwrite(dbuf);  // write dst to disk
    brelse(dbuf);
  }
}

We can’t do the same thing for recover_from_log(), of course, since by the time it calls install_trans(), there’s no such modified blocks being cached in the memory, at all.