Subject: Re: t7006 sometimes hangs in cronjobs on OS X

From: Thomas Rast <[email-masked]>
Date: Wed, 9 Feb 2011 21:22:19 +0100

Thomas Rast wrote:
> I'll have to put off the more involved experimentation somewhat :-(

Or not.

Anyway, I managed to load the relevant parts of t7006 in an
interactive shell, and used

  i=0
  while test_terminal git --no-pager log >out.$i 2>&1; do
    i=$(($i+1))
    echo $i
  done

to trigger the race.  With

  test_terminal () {
    sudo "$PERL_PATH" "$TEST_DIRECTORY"/test-terminal.perl "$@"
  }

which is the closest to dtruss I can get without actually using it, I
hit the race very quickly, usually in ~5 runs.  But using either one
of

  test_terminal () {
    sudo dtruss "$PERL_PATH" "$TEST_DIRECTORY"/test-terminal.perl "$@"
  }

  test_terminal () {
    sudo dtruss -f "$PERL_PATH" "$TEST_DIRECTORY"/test-terminal.perl "$@"
  }

slows down things so much that it did not hit the race in useful time
(about 100 runs).  I also tried running 'dtruss -n perl' in another
terminal and hoping it will hit a wall eventually, which does run a
bit faster but also got nowhere in about 350 runs.

Running 'dtruss -n git' instead did hit the issue, and I have the
output saved away, but I'm not sure what I'd be looking for.  After
all, the git process becomes a zombie:

  47606 s006  S+     0:00.13 /usr/bin/perl /Users/trast/git/t/test-terminal.perl git --no-pager log
  47607 s006  Z+     0:00.00 (git)
  47608 s006  Z+     0:00.00 (perl5.10.0)

The output for pid 47607 ends in:

  47607/0x1f7fec5:  write_nocancel(0x1, "Author: A U Thor <[email-masked]>\n\0", 0x26)                 = 38 0
  47607/0x1f7fec5:  write_nocancel(0x1, "Date:   Thu Apr 7 15:13:13 2005 -0700\n\0", 0x26)                 = 38 0
  47607/0x1f7fec5:  write_nocancel(0x1, "\n\0", 0x1)               = 1 0
  47607/0x1f7fec5:  write_nocancel(0x1, "    initial\n\0", 0xC)            = 12 0
  47607/0x1f7fec5:  fstat64(0x1, 0x7FFF5FBFE8A0, 0x0)              = 0 0
  47607/0x1f7fec5:  fstat64(0x1, 0x7FFF5FBFEF60, 0x0)              = 0 0
  47607/0x1f7fec5:  close_nocancel(0x1)            = 0 0

Which seems rather unsurprising really :-(

Finally, attaching dtruss after hitting the race gives no output when
I finally kill it.

-- 
Thomas Rast
trast@{inf,student}.ethz.ch