Re: [PATCH v9 00/19] index-helper/watchman

[Dennis Kaarsemaker <dennis@kaarsemaker.net>]

On di, 2016-05-10 at 19:28 +0200, Dennis Kaarsemaker wrote:
> On ma, 2016-05-09 at 15:32 -0700, Junio C Hamano wrote:
> > 
> > Junio C Hamano <gitster@pobox.com> writes:
> > 
> > > 
> > > 
> > > David Turner <dturner@twopensource.com> writes:
> > > 
> > > > 
> > > > 
> > > > On Mon, 2016-05-09 at 14:40 -0700, Junio C Hamano wrote:
> > > > > 
> > > > > 
> > > > > Hmmm, I seem to be getting
> > > > > 
> > > > >     $ cat t/trash*7900*/err
> > > > >     fatal: Already running
> > > > > 
> > > > > after running t7900 and it fails at #5, after applying
> > > > > "index-helper: optionally automatically run"
> > The symptom looks pretty similar to $gmane/293461 reported earlier.
> > Here is how "t7900-index-helper.sh -i -v -x -d" ends.
> > 
> > 
> > expecting success:
> >         test_when_finished "git index-helper --kill" &&
> >         rm -f .git/index-helper.sock &&
> >         git status &&
> >         test_path_is_missing .git/index-helper.sock &&
> >         test_config indexhelper.autorun true &&
> >         git status &&
> >         test -S .git/index-helper.sock &&
> >         git status 2>err &&
> >         test -S .git/index-helper.sock &&
> >         test_must_be_empty err &&
> >         git index-helper --kill &&
> >         test_config indexhelper.autorun false &&
> >         git status &&
> >         test_path_is_missing .git/index-helper.sock
> > 
> > + test_when_finished git index-helper --kill
> > + test 0 = 0
> > + test_cleanup={ git index-helper --kill
> >                 } && (exit "$eval_ret"); eval_ret=$?; :
> > + rm -f .git/index-helper.sock
> > + git status
> > On branch master
> > Untracked files:
> >   (use "git add <file>..." to include in what will be committed)
> > 
> >         err
> > 
> > nothing added to commit but untracked files present (use "git add"
> > to
> > track)
> > + test_path_is_missing .git/index-helper.sock
> > + test -e .git/index-helper.sock
> > + test_config indexhelper.autorun true
> > + config_dir=
> > + test indexhelper.autorun = -C
> > + test_when_finished test_unconfig  'indexhelper.autorun'
> > + test 0 = 0
> > + test_cleanup={ test_unconfig  'indexhelper.autorun'
> >                 } && (exit "$eval_ret"); eval_ret=$?; { git index-
> > helper --kill
> >                 } && (exit "$eval_ret"); eval_ret=$?; :
> > + git config indexhelper.autorun true
> > + git status
> > error: last command exited with $?=141
> > not ok 5 - index-helper autorun works
> > #
> > #               test_when_finished "git index-helper --kill" &&
> > #               rm -f .git/index-helper.sock &&
> > #               git status &&
> > #               test_path_is_missing .git/index-helper.sock &&
> > #               test_config indexhelper.autorun true &&
> > #               git status &&
> > #               test -S .git/index-helper.sock &&
> > #               git status 2>err &&
> > #               test -S .git/index-helper.sock &&
> > #               test_must_be_empty err &&
> > #               git index-helper --kill &&
> > #               test_config indexhelper.autorun false &&
> > #               git status &&
> > #               test_path_is_missing .git/index-helper.sock
> > #
> Here are the relevant bits of a strace, pid 22200 is the second git
> status, 222197 is the index helper. 22122 is the test script
> 
> 22200 socket(PF_LOCAL, SOCK_STREAM, 0)  = 7
> 22200 connect(7, {sa_family=AF_LOCAL, sun_path=".git/index-
> helper.sock"}, 110 <unfinished ...>
> 22197 <... poll resumed> )              = 1
> 22197 accept(7, 0, NULL)                = 8
> 22197 fcntl(8, F_GETFL)                 = 0x2 (flags O_RDWR)
> 22197 fcntl(8, F_SETFL, O_RDWR)         = 0
> 22197 read(8,  <unfinished ...>
> 22200 <... connect resumed> )           = 0
> 22200 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,
> 0x7fcc463fdd40}, {SIG_DFL, [PIPE], SA_RESTORER|SA_RESTART,
> 0x7fcc463fdd40}, 8) = 0
> 22200 write(7, "000fpoke 22200 ", 15 <unfinished ...>
> 22197 <... read resumed> 0x7ffc4e4b9b20, 4) = 4
> 22197 read(8, 0x7ffc4e4b9c70, 11)       = 11
> 22197 write(8, 0x18b08b0, 6)            = 6
> 22197 close(8)                          = 0
> 22197 poll([?] 0x7ffc4e4b9b80, 1, 600000 <unfinished ...>
> 22200 <... write resumed> )             = 15
> 22200 write(7, "0000", 4)               = -1 EPIPE (Broken pipe)
> 22200 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=22200,
> si_uid=1000} ---
> 22200 rt_sigaction(SIGPIPE, {SIG_DFL, [PIPE], SA_RESTORER|SA_RESTART,
> 0x7fcc463fdd40}, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,
> 0x7fcc463fdd40}, 8) = 0
> 22200 tgkill(22200, 22200, SIGPIPE)     = 0   
> 22200 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_TKILL, si_pid=22200,
> si_uid=1000} ---
> 22200 +++ killed by SIGPIPE +++
> 22122 <... wait4 resumed> [{WIFSIGNALED(s) && WTERMSIG(s) ==
> SIGPIPE}], 0, NULL) = 22200 
> 22122 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED,
> si_pid=22200, si_status=SIGPIPE, si_utime=0, si_stime=0} ---
> 
> Looks like the index helper closes the socket, but git status still
> wants to write to it. The index-helper also doesn't seem to read all
> data from the socket.

This dodgy hack to make the index helper read that empty pkt-line
before closing the socket seems to work around the issue enough to make
the test pass

diff --git a/index-helper.c b/index-helper.c
index 9743481..fa072de 100644
--- a/index-helper.c
+++ b/index-helper.c
@@ -385,6 +385,8 @@ static void loop(int fd, int idle_in_seconds)
                         * close up.
                         */
                }
+               bytes_read = packet_read(client_fd, NULL, NULL, buf,
+                                        sizeof(buf), flags);
                close(client_fd);
        }
 
And this even dodgier hack breaks the race on a physical machine, so
the test reliably fails everywher:

diff --git a/read-cache.c b/read-cache.c
index e8593bc..848a1fe 100644
--- a/read-cache.c
+++ b/read-cache.c
@@ -1836,6 +1836,7 @@ static int poke_and_wait_for_reply(int fd)
 
        strbuf_addf(&buf, "poke %d %s", getpid(), requested_capabilities);
        packet_write(fd, buf.buf, buf.len);
+       sleep(5);
        packet_flush(fd);
 
        /* Now wait for a reply */

But at this point I'll have to claim ignorance on whether reading the
empty pkt-line is a fix or just hiding the problem.

-- 
Dennis Kaarsemaker
www.kaarsemaker.net