Grub setup race condition?

I am using vmbuilder to setup so lucid vms and have run into an odd issue. Grub was not being installed in my vms and looking at the logs I saw this.

2010-10-01 16:02:35,947 DEBUG : ['chroot', '/tmp/tmpotW34T', 'grub', '--device-map=/tmp/vmbuilder-grub/device.map', '--batch']
2010-10-01 16:02:35,947 DEBUG : stdin was set and it was a string: root (hd0,0)
setup (hd0)
EOT
2010-10-01 16:02:37,759 DEBUG :
2010-10-01 16:02:37,759 DEBUG : [ Minimal BASH-like line editing is supported. For
2010-10-01 16:02:37,759 DEBUG : the first word, TAB lists possible command
2010-10-01 16:02:37,759 DEBUG : completions. Anywhere else TAB lists the possible
2010-10-01 16:02:37,759 DEBUG : completions of a device/filename. ]
2010-10-01 16:02:37,759 DEBUG : grub> root (hd0,0)
2010-10-01 16:02:37,760 DEBUG : grub> setup (hd0)
2010-10-01 16:02:37,760 DEBUG : Checking if "/boot/grub/stage1" exists... no
2010-10-01 16:02:37,760 DEBUG : Checking if "/grub/stage1" exists... no
2010-10-01 16:02:37,760 DEBUG :
2010-10-01 16:02:37,760 DEBUG : Error 15: File not found
2010-10-01 16:02:37,760 DEBUG : grub> EOT

After mounting the drive and looking in there the files are there so I was confused. So I added the line
        run_cmd('ls', '-l', '%s%s' % (chroot_dir, tmpdir))
to /usr/share/pyshared/VMBuilder/plugins/ubuntu/distro.py
at line #209 in the latest code, right after
self.suite.install_grub(chroot_dir)
and before
self.run_in_target('grub', '--device-map=%s' % devmapfile, '--batch', stdin='''root %s

On my next run it worked debug output showed the ls followed by
2010-10-01 16:12:44,314 DEBUG : ['chroot', '/tmp/tmp4SF9IC', 'grub', '--device-map=/tmp/vmbuilder-grub/device.map', '--batch']
2010-10-01 16:12:44,314 DEBUG : stdin was set and it was a string: root (hd0,0)
setup (hd0)
EOT
2010-10-01 16:12:47,337 DEBUG :
2010-10-01 16:12:47,337 DEBUG : [ Minimal BASH-like line editing is supported. For
2010-10-01 16:12:47,337 DEBUG : the first word, TAB lists possible command
2010-10-01 16:12:47,337 DEBUG : completions. Anywhere else TAB lists the possible
2010-10-01 16:12:47,337 DEBUG : completions of a device/filename. ]
2010-10-01 16:12:47,337 DEBUG : grub> root (hd0,0)
2010-10-01 16:12:47,337 DEBUG : grub> setup (hd0)
2010-10-01 16:12:47,338 DEBUG : Checking if "/boot/grub/stage1" exists... yes
2010-10-01 16:12:47,338 DEBUG : Checking if "/boot/grub/stage2" exists... yes
2010-10-01 16:12:47,338 DEBUG : Checking if "/boot/grub/e2fs_stage1_5" exists... yes
2010-10-01 16:12:47,338 DEBUG : Running "embed /boot/grub/e2fs_stage1_5 (hd0)"... failed (this is not fatal)
2010-10-01 16:12:47,338 DEBUG : Running "embed /boot/grub/e2fs_stage1_5 (hd0,0)"... failed (this is not fatal) 2010-10-01 16:12:47,338 DEBUG : Running "install /boot/grub/stage1 (hd0) /boot/grub/stage2 p /boot/grub/menu.lst "... succeeded
2010-10-01 16:12:47,338 DEBUG : Done.
2010-10-01 16:12:47,338 DEBUG : grub> EOT

I thought that was odd so I removed my debug line and it failed again. I added it back in and it worked again. Is there some sort of odd race condition going on? Is the copy of the grub files not being waited on?
I got pulled off on a different task before getting a chance to look into it more.