From: Junio C Hamano <hidden> Date: 2016-06-16 02:19:16
Junio C Hamano [off-list ref] writes:
David Turner [off-list ref] writes:
quoted
On Mon, 2016-05-09 at 14:40 -0700, Junio C Hamano wrote:
quoted
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
#
:
From: David Turner <hidden> Date: 2016-06-16 02:19:16
On Mon, 2016-05-09 at 15:32 -0700, Junio C Hamano wrote:
Junio C Hamano [off-list ref] writes:
quoted
David Turner [off-list ref] writes:
quoted
On Mon, 2016-05-09 at 14:40 -0700, Junio C Hamano wrote:
quoted
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
I think that's a SIGPIPE on the first git status. Weird, since I just
added sigpipe-avoidance code (in v8). Does anyone have any idea why
the sigchain stuff isn't doing what I think it is?
From: Ramsay Jones <hidden> Date: 2016-06-16 02:19:16
On 10/05/16 00:12, David Turner wrote:
On Mon, 2016-05-09 at 15:32 -0700, Junio C Hamano wrote:
quoted
Junio C Hamano [off-list ref] writes:
quoted
David Turner [off-list ref] writes:
quoted
On Mon, 2016-05-09 at 14:40 -0700, Junio C Hamano wrote:
quoted
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
I think that's a SIGPIPE on the first git status. Weird, since I just
added sigpipe-avoidance code (in v8). Does anyone have any idea why
the sigchain stuff isn't doing what I think it is?
Sorry for a late report (I've been a bit busy last couple of days), but
I've been seeing exactly the same on v8 of this series.
Note that the above 'git status' is actually the second git-status in the
test.
I haven't been able to debug it too much, but I can tell you that it is
not failing at exactly the same place every time (so it may be time
sensitive). However, it often fails in poke_and_wait_for_reply() at the
first packet_flush() (which in turn calls write_or_die() which calls
check_pipe() with an EPIPE(32)). At other times it fails when issuing
a flush after a refresh packet. For example, on one run with packet
tracing enabled, I got this for the trace:
trace: built-in: git 'status'
packet: git> poke 3221
packet: git> 0000
packet: git< OK
packet: git> refresh
packet: git> 0000
So, its getting the EPIPE for the refresh in this case, even though
the index-helper is still running, the unix socket is in .git/
(and so is a shm-* file BTW).
I didn't get any further than that I'm afraid.
ATB,
Ramsay Jones
On Tue, May 10, 2016 at 6:12 AM, David Turner [off-list ref] wrote:
I think that's a SIGPIPE on the first git status. Weird, since I just
added sigpipe-avoidance code (in v8). Does anyone have any idea why
the sigchain stuff isn't doing what I think it is?
SIGPIPE code works. I tested with and without --detach (suspecting
fork causing problems). I even logged all sigchain_push() calls to see
if anybody else is interfering (none did, at least without watchman).
Problem is elsewhere.
There are two problems with logging code in index-helper though. The
redirecting std{out,err} to /dev/null should only be done when
--detach is given (and I' m quite sure daemonize() already takes care
of that). If --detach is used, log_warning() can't cover die(),
warning() or error(), most importantly die() for example because of
bugs. I think you can call set_die_routine() and similar, just be
careful not lead to recursive calls (die() is protected, but I dont
think error and warning are).
--
Duy
On Tue, May 10, 2016 at 7:45 PM, Duy Nguyen [off-list ref] wrote:
If --detach is used, log_warning() can't cover die(),
warning() or error(), most importantly die() for example because of
bugs.
A case for redirecting warning() is because watchman-support.c uses
it. But because this file is only used by index-helper, you have
another option, simply convert it to using log_warning().
--
Duy
From: Dennis Kaarsemaker <hidden> Date: 2016-06-16 02:19:17
On ma, 2016-05-09 at 15:32 -0700, Junio C Hamano wrote:
Junio C Hamano [off-list ref] writes:
quoted
David Turner [off-list ref] writes:
quoted
On Mon, 2016-05-09 at 14:40 -0700, Junio C Hamano wrote:
quoted
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.
--
Dennis Kaarsemaker
www.kaarsemaker.net
From: Dennis Kaarsemaker <hidden> Date: 2016-06-16 02:19:17
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:
quoted
Junio C Hamano [off-list ref] writes:
quoted
David Turner [off-list ref] writes:
quoted
On Mon, 2016-05-09 at 14:40 -0700, Junio C Hamano wrote:
quoted
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
@@ -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:
@@ -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