t5541: Bad file descriptor

t5541: Bad file descriptor

[Brian Gernhardt]

I haven't had a lot of time to track down it down until today, but I've been getting failures in t5541-http-push-.sh.  Several tests fail with the error "fatal: write error: Bad file descriptor".

I have bisected this to "73776dc: 
Merge branch 'js/maint-1.6.6-send-pack-stateless-rpc-deadlock-fix' into js/maint-send-pack-stateless-rpc-deadlock-fix"

Full test output follows:

$ ./t5541-http-push.sh -v
Initialized empty Git repository in /Users/brian/dev/git/t/trash directory.t5541-http-push/.git/
expecting success: 
	cd "$ROOT_PATH" &&
	mkdir test_repo &&
	cd test_repo &&
	git init &&
	: >path1 &&
	git add path1 &&
	test_tick &&
	git commit -m initial &&
	cd - &&
	git clone --bare test_repo test_repo.git &&
	cd test_repo.git &&
	git config http.receivepack true &&
	ORIG_HEAD=$(git rev-parse --verify HEAD) &&
	cd - &&
	mv test_repo.git "$HTTPD_DOCUMENT_ROOT_PATH"

Initialized empty Git repository in /Users/brian/dev/git/t/trash directory.t5541-http-push/test_repo/.git/
[master (root-commit) 0c973ae] initial
 Author: A U Thor <author@example.com>
 0 files changed, 0 insertions(+), 0 deletions(-)
 create mode 100644 path1
/Users/brian/dev/git/t/trash directory.t5541-http-push
Cloning into bare repository test_repo.git...
done.
/Users/brian/dev/git/t/trash directory.t5541-http-push
ok 1 - setup remote repository

expecting success: 
	# In the URL, add a trailing slash, and see if git appends yet another
	# slash.
	cd "$ROOT_PATH" &&
	git clone $HTTPD_URL/smart/test_repo.git/ test_repo_clone &&

	sed -e "
		s/^.* \"//
		s/\"//
		s/ [1-9][0-9]*\$//
		s/^GET /GET  /
	" >act <"$HTTPD_ROOT_PATH"/access.log &&

	# Clear the log, so that it does not affect the "used receive-pack
	# service" test which reads the log too.
	#
	# We do this before the actual comparison to ensure the log is cleared.
	echo > "$HTTPD_ROOT_PATH"/access.log &&

	test_cmp exp act

Cloning into test_repo_clone...
remote: Counting objects: 3, done.        
remote: Total 3 (delta 0), reused 0 (delta 0)        
Unpacking objects: 100% (3/3), done.
ok 2 - no empty path components

expecting success: 
	rm -rf test_repo_clone &&
	git clone $HTTPD_URL/smart/test_repo.git test_repo_clone

Cloning into test_repo_clone...
remote: Counting objects: 3, done.        
remote: Total 3 (delta 0), reused 0 (delta 0)        
Unpacking objects: 100% (3/3), done.
ok 3 - clone remote repository

expecting success: 
	cd "$ROOT_PATH"/test_repo_clone &&
	: >path2 &&
	git add path2 &&
	test_tick &&
	git commit -m path2 &&
	HEAD=$(git rev-parse --verify HEAD) &&
	git push &&
	(cd "$HTTPD_DOCUMENT_ROOT_PATH"/test_repo.git &&
	 test $HEAD = $(git rev-parse --verify HEAD))

[master 9d498b0] path2
 Author: A U Thor <author@example.com>
 0 files changed, 0 insertions(+), 0 deletions(-)
 create mode 100644 path2
Counting objects: 3, done.
Delta compression using up to 2 threads.
Compressing objects: 100% (2/2), done.
Writing objects: 100% (2/2), 240 bytes, done.
Total 2 (delta 0), reused 0 (delta 0)
fatal: write error: Bad file descriptor
fatal: The remote end hung up unexpectedly
not ok - 4 push to remote repository
#	
#		cd "$ROOT_PATH"/test_repo_clone &&
#		: >path2 &&
#		git add path2 &&
#		test_tick &&
#		git commit -m path2 &&
#		HEAD=$(git rev-parse --verify HEAD) &&
#		git push &&
#		(cd "$HTTPD_DOCUMENT_ROOT_PATH"/test_repo.git &&
#		 test $HEAD = $(git rev-parse --verify HEAD))
#	

expecting success: 
	git push

Counting objects: 3, done.
Delta compression using up to 2 threads.
Compressing objects: 100% (2/2), done.
Writing objects: 100% (2/2), 240 bytes, done.
Total 2 (delta 0), reused 0 (delta 0)
fatal: write error: Bad file descriptor
fatal: The remote end hung up unexpectedly
not ok - 5 push already up-to-date
#	
#		git push
#	

expecting success: 
	cd "$ROOT_PATH"/test_repo_clone &&
	git checkout -b dev &&
	: >path3 &&
	git add path3 &&
	test_tick &&
	git commit -m dev &&
	git push origin dev &&
	git push origin :dev &&
	test_must_fail git show-ref --verify refs/remotes/origin/dev

Switched to a new branch 'dev'
[dev 3ea4fbb] dev
 Author: A U Thor <author@example.com>
 0 files changed, 0 insertions(+), 0 deletions(-)
 create mode 100644 path3
Counting objects: 5, done.
Delta compression using up to 2 threads.
Compressing objects: 100% (4/4), done.
Writing objects: 100% (4/4), 414 bytes, done.
Total 4 (delta 1), reused 0 (delta 0)
fatal: The remote end hung up unexpectedly
fatal: write error: Bad file descriptor
not ok - 6 create and delete remote branch
#	
#		cd "$ROOT_PATH"/test_repo_clone &&
#		git checkout -b dev &&
#		: >path3 &&
#		git add path3 &&
#		test_tick &&
#		git commit -m dev &&
#		git push origin dev &&
#		git push origin :dev &&
#		test_must_fail git show-ref --verify refs/remotes/origin/dev
#	

expecting success: 
	sed -e "
		s/^.* \"//
		s/\"//
		s/ [1-9][0-9]*\$//
		s/^GET /GET  /
	" >act <"$HTTPD_ROOT_PATH"/access.log &&
	test_cmp exp act

--- exp	2011-05-05 04:48:00.000000000 +0000
+++ act	2011-05-05 04:48:00.000000000 +0000
@@ -2,9 +2,5 @@
 GET  /smart/test_repo.git/info/refs?service=git-upload-pack HTTP/1.1 200
 POST /smart/test_repo.git/git-upload-pack HTTP/1.1 200
 GET  /smart/test_repo.git/info/refs?service=git-receive-pack HTTP/1.1 200
-POST /smart/test_repo.git/git-receive-pack HTTP/1.1 200
 GET  /smart/test_repo.git/info/refs?service=git-receive-pack HTTP/1.1 200
 GET  /smart/test_repo.git/info/refs?service=git-receive-pack HTTP/1.1 200
-POST /smart/test_repo.git/git-receive-pack HTTP/1.1 200
-GET  /smart/test_repo.git/info/refs?service=git-receive-pack HTTP/1.1 200
-POST /smart/test_repo.git/git-receive-pack HTTP/1.1 200
not ok - 7 used receive-pack service
#	
#		sed -e "
#			s/^.* \"//
#			s/\"//
#			s/ [1-9][0-9]*\$//
#			s/^GET /GET  /
#		" >act <"$HTTPD_ROOT_PATH"/access.log &&
#		test_cmp exp act
#	

expecting success: 
		cd "$REMOTE_REPO" &&
		HEAD=$(git rev-parse --verify HEAD) &&

		cd "$LOCAL_REPO" &&
		git checkout $BRANCH &&
		echo "changed" > path2 &&
		git commit -a -m path2 --amend &&

		test_must_fail git push -v origin >output 2>&1 &&
		(cd "$REMOTE_REPO" &&
		 test $HEAD = $(git rev-parse --verify HEAD))
	
Switched to branch 'master'
Your branch is ahead of 'origin/master' by 1 commit.
[master 910616f] path2
 Author: A U Thor <author@example.com>
 1 files changed, 1 insertions(+), 0 deletions(-)
 create mode 100644 path2
ok 8 - non-fast-forward push fails

expecting success: 
		grep "^ ! \[rejected\][ ]*$BRANCH -> $BRANCH (non-fast-forward)$" output
	
not ok - 9 non-fast-forward push show ref status
#	
#			grep "^ ! \[rejected\][ ]*$BRANCH -> $BRANCH (non-fast-forward)$" output
#		

expecting success: 
		test_i18ngrep "To prevent you from losing history, non-fast-forward updates were rejected" output
	
not ok - 10 non-fast-forward push shows help message
#	
#			test_i18ngrep "To prevent you from losing history, non-fast-forward updates were rejected" output
#		

expecting success: 
	# create a dissimilarly-named remote ref so that git is unable to match the
	# two refs (viz. local, remote) unless an explicit refspec is provided.
	git push origin master:retsam

	echo "change changed" > path2 &&
	git commit -a -m path2 --amend &&

	# push master too; this ensures there is at least one 'push' command to
	# the remote helper and triggers interaction with the helper.
	test_must_fail git push -v origin +master master:retsam >output 2>&1
Counting objects: 4, done.
Delta compression using up to 2 threads.
Compressing objects: 100% (2/2), done.
Writing objects: 100% (3/3), 279 bytes, done.
Total 3 (delta 0), reused 0 (delta 0)
fatal: write error: Bad file descriptor
fatal: The remote end hung up unexpectedly
[master 6773b42] path2
 Author: A U Thor <author@example.com>
 1 files changed, 1 insertions(+), 0 deletions(-)
 create mode 100644 path2
ok 11 - push fails for non-fast-forward refs unmatched by remote helper

expecting success: 
	grep "^ + [a-f0-9]*\.\.\.[a-f0-9]* *master -> master (forced update)$" output &&
	grep "^ ! \[rejected\] *master -> retsam (non-fast-forward)$" output

not ok - 12 push fails for non-fast-forward refs unmatched by remote helper: remote output
#	
#		grep "^ + [a-f0-9]*\.\.\.[a-f0-9]* *master -> master (forced update)$" output &&
#		grep "^ ! \[rejected\] *master -> retsam (non-fast-forward)$" output
#	

expecting success: 
	test_i18ngrep "To prevent you from losing history, non-fast-forward updates were rejected" \
		output

not ok - 13 push fails for non-fast-forward refs unmatched by remote helper: our output
#	
#		test_i18ngrep "To prevent you from losing history, non-fast-forward updates were rejected" \
#			output
#	

# failed 8 among 13 test(s)
1..13

Re: t5541: Bad file descriptor

[Junio C Hamano]

Brian Gernhardt <brian@gernhardtsoftware.com> writes:

> I haven't had a lot of time to track down it down until today, but I've
> been getting failures in t5541-http-push-.sh.  Several tests fail with
> the error "fatal: write error: Bad file descriptor".

A wild guess.

Does it help if you cherry-picked 1e41827 (http: clear POSTFIELDS when
initializing a slot, 2011-04-26) on top of the faulty commit?

Re: t5541: Bad file descriptor

[Jeff King]

On Wed, May 04, 2011 at 10:35:13PM -0700, Junio C Hamano wrote:

> Brian Gernhardt <brian@gernhardtsoftware.com> writes:
> 
> > I haven't had a lot of time to track down it down until today, but I've
> > been getting failures in t5541-http-push-.sh.  Several tests fail with
> > the error "fatal: write error: Bad file descriptor".
> 
> A wild guess.
> 
> Does it help if you cherry-picked 1e41827 (http: clear POSTFIELDS when
> initializing a slot, 2011-04-26) on top of the faulty commit?

I think that 09c9957 (send-pack: avoid deadlock when pack-object dies
early, 2011-04-25) is totally broken.

Looking back at my tests, I only tested the case where pack-objects
fails. And it seems we totally broke the case where the push is supposed
to succeed.

Still investigating...

-Peff

Re: t5541: Bad file descriptor

[Jeff King]

On Thu, May 05, 2011 at 01:46:11AM -0400, Jeff King wrote:

> On Wed, May 04, 2011 at 10:35:13PM -0700, Junio C Hamano wrote:
> 
> > Brian Gernhardt <brian@gernhardtsoftware.com> writes:
> > 
> > > I haven't had a lot of time to track down it down until today, but I've
> > > been getting failures in t5541-http-push-.sh.  Several tests fail with
> > > the error "fatal: write error: Bad file descriptor".
> > 
> > A wild guess.
> > 
> > Does it help if you cherry-picked 1e41827 (http: clear POSTFIELDS when
> > initializing a slot, 2011-04-26) on top of the faulty commit?
> 
> I think that 09c9957 (send-pack: avoid deadlock when pack-object dies
> early, 2011-04-25) is totally broken.
> 
> Looking back at my tests, I only tested the case where pack-objects
> fails. And it seems we totally broke the case where the push is supposed
> to succeed.
> 
> Still investigating...

OK, embarrassing. 09c9957 completely breaks smart http pushing. My
testing of Johannes' patch was completely focused on the error case, and
I didn't have a single test for the non-error case. And on top of that,
we _have_ nice tests in the test suite to catch this, but obviously
neither I, nor Johannes, nor Junio were running them (because they need
apache installed and GIT_TEST_HTTPD set).

Ugh.

This patch on top of 09c9957 should fix it.

-- >8 --
Subject: [PATCH] send-pack: unbreak push over stateless rpc

Commit 09c9957 (send-pack: avoid deadlock when pack-object
dies early, 2011-04-25) attempted to fix a hang in the
stateless rpc case by closing a file descriptor early, but
we still need that descriptor.

Basically the deadlock can happen when pack-objects fails,
and the descriptor to upstream is left open. We never send
the pack, so the upstream is left waiting for us to say
something, and we are left waiting for upstream to close the
connection.

In the non-rpc case, our descriptor points straight to the
upstream. We hand it off to run-command, which takes
ownership and closes the descriptor after pack-objects
finishes (whether it succeeds or not).

Commit 09c9957 tried to emulate that in the rpc case. That
isn't right, though. We actually have a descriptor going
back to the remote-helper, and we need to keep using it
after pack-objects is finished. Closing it early completely
breaks pushing via smart-http.

We still need to do something on error to signal the
remote-helper that we won't be sending any pack data
(otherwise we get the deadlock).  In an ideal world, we
would send a special packet back that says "Sorry, there was
an error". But the remote-helper doesn't understand any such
packet, so the best we can do is close the descriptor and
let it report that we hung up unexpectedly.

Signed-off-by: Jeff King <peff@peff.net>
---
 builtin-send-pack.c |    3 ++-
 1 files changed, 2 insertions(+), 1 deletions(-)

diff --git a/builtin-send-pack.c b/builtin-send-pack.c
index 6516288..3e70795 100644
--- a/builtin-send-pack.c
+++ b/builtin-send-pack.c
@@ -97,7 +97,6 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 		free(buf);
 		close(po.out);
 		po.out = -1;
-		close(fd);
 	}
 
 	if (finish_command(&po))
@@ -519,6 +518,8 @@ int send_pack(struct send_pack_args *args,
 		if (pack_objects(out, remote_refs, extra_have, args) < 0) {
 			for (ref = remote_refs; ref; ref = ref->next)
 				ref->status = REF_STATUS_NONE;
+			if (args->stateless_rpc)
+				close(out);
 			if (use_sideband)
 				finish_async(&demux);
 			return -1;
-- 
1.7.5.406.gfbb2

Re: t5541: Bad file descriptor

[Sverre Rabbelier]

Heya,

On Thu, May 5, 2011 at 08:16, Jeff King <peff@peff.net> wrote:
> OK, embarrassing. 09c9957 completely breaks smart http pushing. My
> testing of Johannes' patch was completely focused on the error case, and
> I didn't have a single test for the non-error case. And on top of that,
> we _have_ nice tests in the test suite to catch this, but obviously
> neither I, nor Johannes, nor Junio were running them (because they need
> apache installed and GIT_TEST_HTTPD set).

Wasn't someone, I _think_ Ævar, or maybe Avery, (I could be totally
wrong) running a buildbot of git.git on various platforms? If so,
maybe they can turn on these tests since they aren't often run?

-- 
Cheers,

Sverre Rabbelier

Re: t5541: Bad file descriptor

[Avery Pennarun]

On Thu, May 5, 2011 at 7:18 AM, Sverre Rabbelier <srabbelier@gmail.com> wrote:
> On Thu, May 5, 2011 at 08:16, Jeff King <peff@peff.net> wrote:
>> OK, embarrassing. 09c9957 completely breaks smart http pushing. My
>> testing of Johannes' patch was completely focused on the error case, and
>> I didn't have a single test for the non-error case. And on top of that,
>> we _have_ nice tests in the test suite to catch this, but obviously
>> neither I, nor Johannes, nor Junio were running them (because they need
>> apache installed and GIT_TEST_HTTPD set).
>
> Wasn't someone, I _think_ Ævar, or maybe Avery, (I could be totally
> wrong) running a buildbot of git.git on various platforms? If so,
> maybe they can turn on these tests since they aren't often run?

I was running one, didn't think anybody cared about it though.  Please
point me at the necessary docs for this test and I can set up a new
one in my copious spare time (tm).  I can't promise to monitor it
though, so that might be more of a problem :)  gitbuilder does produce
rss feeds that are easy to track.

Have fun,

Avery

Re: t5541: Bad file descriptor

[Sverre Rabbelier]

Heya,

On Thu, May 5, 2011 at 19:59, Avery Pennarun <apenwarr@gmail.com> wrote:
> I was running one, didn't think anybody cared about it though.  Please
> point me at the necessary docs for this test and I can set up a new
> one in my copious spare time (tm).  I can't promise to monitor it
> though, so that might be more of a problem :)  gitbuilder does produce
> rss feeds that are easy to track.

I don't think there are any docs as such, but see t/lib-httpd.sh.
Should be easy enough to deduce which variables to set to what from
that.

-- 
Cheers,

Sverre Rabbelier

Re: t5541: Bad file descriptor

[Jeff King]

On Thu, May 05, 2011 at 08:51:29PM +0200, Sverre Rabbelier wrote:

> Heya,
> 
> On Thu, May 5, 2011 at 19:59, Avery Pennarun <apenwarr@gmail.com> wrote:
> > I was running one, didn't think anybody cared about it though.  Please
> > point me at the necessary docs for this test and I can set up a new
> > one in my copious spare time (tm).  I can't promise to monitor it
> > though, so that might be more of a problem :)  gitbuilder does produce
> > rss feeds that are easy to track.
> 
> I don't think there are any docs as such, but see t/lib-httpd.sh.
> Should be easy enough to deduce which variables to set to what from
> that.

Just setting GIT_TEST_HTTPD=1 in the environment would turn on those
tests. But you need apache installed, too. The scripts should take care
of any config.

-Peff

Re: t5541: Bad file descriptor

[Jeff King]

[argh, resend, I meant to cc Johannes Sixt]

On Thu, May 05, 2011 at 01:46:11AM -0400, Jeff King wrote:

> On Wed, May 04, 2011 at 10:35:13PM -0700, Junio C Hamano wrote:
> 
> > Brian Gernhardt <brian@gernhardtsoftware.com> writes:
> > 
> > > I haven't had a lot of time to track down it down until today, but I've
> > > been getting failures in t5541-http-push-.sh.  Several tests fail with
> > > the error "fatal: write error: Bad file descriptor".
> > 
> > A wild guess.
> > 
> > Does it help if you cherry-picked 1e41827 (http: clear POSTFIELDS when
> > initializing a slot, 2011-04-26) on top of the faulty commit?
> 
> I think that 09c9957 (send-pack: avoid deadlock when pack-object dies
> early, 2011-04-25) is totally broken.
> 
> Looking back at my tests, I only tested the case where pack-objects
> fails. And it seems we totally broke the case where the push is supposed
> to succeed.
> 
> Still investigating...

OK, embarrassing. 09c9957 completely breaks smart http pushing. My
testing of Johannes' patch was completely focused on the error case, and
I didn't have a single test for the non-error case. And on top of that,
we _have_ nice tests in the test suite to catch this, but obviously
neither I, nor Johannes, nor Junio were running them (because they need
apache installed and GIT_TEST_HTTPD set).

Ugh.

This patch on top of 09c9957 should fix it.

-- >8 --
Subject: [PATCH] send-pack: unbreak push over stateless rpc

Commit 09c9957 (send-pack: avoid deadlock when pack-object
dies early, 2011-04-25) attempted to fix a hang in the
stateless rpc case by closing a file descriptor early, but
we still need that descriptor.

Basically the deadlock can happen when pack-objects fails,
and the descriptor to upstream is left open. We never send
the pack, so the upstream is left waiting for us to say
something, and we are left waiting for upstream to close the
connection.

In the non-rpc case, our descriptor points straight to the
upstream. We hand it off to run-command, which takes
ownership and closes the descriptor after pack-objects
finishes (whether it succeeds or not).

Commit 09c9957 tried to emulate that in the rpc case. That
isn't right, though. We actually have a descriptor going
back to the remote-helper, and we need to keep using it
after pack-objects is finished. Closing it early completely
breaks pushing via smart-http.

We still need to do something on error to signal the
remote-helper that we won't be sending any pack data
(otherwise we get the deadlock).  In an ideal world, we
would send a special packet back that says "Sorry, there was
an error". But the remote-helper doesn't understand any such
packet, so the best we can do is close the descriptor and
let it report that we hung up unexpectedly.

Signed-off-by: Jeff King <peff@peff.net>
---
 builtin-send-pack.c |    3 ++-
 1 files changed, 2 insertions(+), 1 deletions(-)

diff --git a/builtin-send-pack.c b/builtin-send-pack.c
index 6516288..3e70795 100644
--- a/builtin-send-pack.c
+++ b/builtin-send-pack.c
@@ -97,7 +97,6 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 		free(buf);
 		close(po.out);
 		po.out = -1;
-		close(fd);
 	}
 
 	if (finish_command(&po))
@@ -519,6 +518,8 @@ int send_pack(struct send_pack_args *args,
 		if (pack_objects(out, remote_refs, extra_have, args) < 0) {
 			for (ref = remote_refs; ref; ref = ref->next)
 				ref->status = REF_STATUS_NONE;
+			if (args->stateless_rpc)
+				close(out);
 			if (use_sideband)
 				finish_async(&demux);
 			return -1;
-- 
1.7.5.406.gfbb2

Re: t5541: Bad file descriptor

[Brian Gernhardt]

On May 5, 2011, at 2:18 AM, Jeff King wrote:

> OK, embarrassing. 09c9957 completely breaks smart http pushing. My
> testing of Johannes' patch was completely focused on the error case, and
> I didn't have a single test for the non-error case. And on top of that,
> we _have_ nice tests in the test suite to catch this, but obviously
> neither I, nor Johannes, nor Junio were running them (because they need
> apache installed and GIT_TEST_HTTPD set).
> 
> Ugh.
> 
> This patch on top of 09c9957 should fix it.
> 
> -- >8 --
> Subject: [PATCH] send-pack: unbreak push over stateless rpc

While I could not get the patch to apply as-is (git apply complained of trailing whitespace), I performed the changes by hand and t5541 passed once more.

~~ Brian

Re: t5541: Bad file descriptor

[Johannes Sixt]

Am 05.05.2011 08:18, schrieb Jeff King:
> OK, embarrassing. 09c9957 completely breaks smart http pushing. My
> testing of Johannes' patch was completely focused on the error case, and
> I didn't have a single test for the non-error case. And on top of that,
> we _have_ nice tests in the test suite to catch this, but obviously
> neither I, nor Johannes, nor Junio were running them (because they need
> apache installed and GIT_TEST_HTTPD set).
> 
> Ugh.
> 
> This patch on top of 09c9957 should fix it.

Very embarassing! Thanks for fixing up my mess. The patch looks good.

-- Hannes