t5541-http-push hanging

t5541-http-push hanging

[Brian Gernhardt]

My build script for git has been hanging at t5541.2 and I haven't had the tuits to discover why.  Here's what I've gotten so far, in case anyone can figure it out faster:

$ ./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
 0 files changed, 0 insertions(+), 0 deletions(-)
 create mode 100644 path1
/Users/brian/dev/git/t/trash directory.t5541-http-push
Initialized empty Git repository in /Users/brian/dev/git/t/trash directory.t5541-http-push/test_repo.git/
/Users/brian/dev/git/t/trash directory.t5541-http-push
*   ok 1: setup remote repository

* expecting success: 
	cd "$ROOT_PATH" &&
	git clone $HTTPD_URL/smart/test_repo.git test_repo_clone

Initialized empty Git repository in /Users/brian/dev/git/t/trash directory.t5541-http-push/test_repo_clone/.git/
error: RPC failed; result=22, HTTP code = 500
^CFATAL: Unexpected exit with code 130

brian@hermes t (master)$ cd trash\ directory.t5541-http-push/httpd/
brian@hermes httpd (master)$ cat error.log 
[Wed Nov 11 06:19:39 2009] [notice] Apache/2.2.13 (Unix) configured -- resuming normal operations
[Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] git-http-backend(59490) malloc: *** error for object 0x100200340: incorrect checksum for freed object - object was probably modified after being freed.
[Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] *** set a breakpoint in malloc_error_break to debug
[Wed Nov 11 06:19:40 2009] [error] [client 127.0.0.1] Premature end of script headers: git-http-backend
[Wed Nov 11 06:24:23 2009] [notice] caught SIGTERM, shutting down

Re: t5541-http-push hanging

[Tay Ray Chuan]

Hi,

On Wed, Nov 11, 2009 at 2:28 PM, Brian Gernhardt
<brian@gernhardtsoftware.com> wrote:
> error: RPC failed; result=22, HTTP code = 500
> ^CFATAL: Unexpected exit with code 130

looks like an apache/http-backend issue. What version of apache are you running?

Also, are you running out of the 'next' branch?

-- 
Cheers,
Ray Chuan

Re: t5541-http-push hanging

[Shawn O. Pearce]

Brian Gernhardt <brian@gernhardtsoftware.com> wrote:
> brian@hermes httpd (master)$ cat error.log 
> [Wed Nov 11 06:19:39 2009] [notice] Apache/2.2.13 (Unix) configured -- resuming normal operations
> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] git-http-backend(59490) malloc: *** error for object 0x100200340: incorrect checksum for freed object - object was probably modified after being freed.
> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] *** set a breakpoint in malloc_error_break to debug
> [Wed Nov 11 06:19:40 2009] [error] [client 127.0.0.1] Premature end of script headers: git-http-backend
> [Wed Nov 11 06:24:23 2009] [notice] caught SIGTERM, shutting down--

Yikes, looks like git-http-backend corrupted its heap.

Is this by any chance Mac OS X ?

-- 
Shawn.

Re: t5541-http-push hanging

[Brian Gernhardt]

On Nov 11, 2009, at 10:47 AM, Tay Ray Chuan wrote:

> On Wed, Nov 11, 2009 at 2:28 PM, Brian Gernhardt
> <brian@gernhardtsoftware.com> wrote:
>> error: RPC failed; result=22, HTTP code = 500
>> ^CFATAL: Unexpected exit with code 130
> 
> looks like an apache/http-backend issue. What version of apache are you running?

It's Apache 2.2.13 on Mac OS X 10.6.2

> Also, are you running out of the 'next' branch?

Yes.  That particular build was v1.6.5.2-372-gc05027d

However I've been seeing it for a couple days.

~~ Brian

Re: t5541-http-push hanging

[Shawn O. Pearce]

Brian Gernhardt <brian@gernhardtsoftware.com> wrote:
> My build script for git has been hanging at t5541.2 and I haven't had the tuits to discover why.  Here's what I've gotten so far, in case anyone can figure it out faster:
...
> Initialized empty Git repository in /Users/brian/dev/git/t/trash directory.t5541-http-push/test_repo_clone/.git/
> error: RPC failed; result=22, HTTP code = 500
> ^CFATAL: Unexpected exit with code 130
...
> 
> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] git-http-backend(59490) malloc: *** error for object 0x100200340: incorrect checksum for freed object - object was probably modified after being freed.
> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] *** set a breakpoint in malloc_error_break to debug
> [Wed Nov 11 06:19:40 2009] [error] [client 127.0.0.1] Premature end of script headers: git-http-backend

Probably caused by a missing cast:


diff --git a/http-backend.c b/http-backend.c
index f8ea9d7..957e4ef 100644
--- a/http-backend.c
+++ b/http-backend.c
@@ -136,7 +136,7 @@ static void hdr_str(const char *name, const char *value)
 
 static void hdr_int(const char *name, size_t value)
 {
-	format_write(1, "%s: %" PRIuMAX "\r\n", name, value);
+	format_write(1, "%s: %" PRIuMAX "\r\n", name, (uintmax_t)value);
 }
 
 static void hdr_date(const char *name, unsigned long when)

-- 
Shawn.

Re: t5541-http-push hanging

[Shawn O. Pearce]

Brian Gernhardt <brian@gernhardtsoftware.com> wrote:
> My build script for git has been hanging at t5541.2 and I haven't had the tuits to discover why.  Here's what I've gotten so far, in case anyone can figure it out faster:
...
> 	git clone $HTTPD_URL/smart/test_repo.git test_repo_clone
...
> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] git-http-backend(59490) malloc: *** error for object 0x100200340: incorrect checksum for freed object - object was probably modified after being freed.
> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] *** set a breakpoint in malloc_error_break to debug

I can't reproduce this on 10.5.8.  Can you try running it in the
debugger and putting a breakpoint where they suggest?  Maybe it
will help give us some context information:

  REQUEST_METHOD=GET \
  PATH_TRANSLATED=`pwd`/.git/info/refs \
  QUERY_STRING=service=git-upload-pack \
  gdb ./git-http-backend

  b malloc_error_break
  run

I suspect that's where our failure is, the code path for the actual
common negotiation and data transfer is shorter, and less likely
to need to do a memory allocation... and therefore a free.

-- 
Shawn.

Re: t5541-http-push hanging

[Brian Gernhardt]

On Nov 11, 2009, at 11:49 PM, Shawn O. Pearce wrote:

> Brian Gernhardt <brian@gernhardtsoftware.com> wrote:
>> My build script for git has been hanging at t5541.2 and I haven't had the tuits to discover why.  Here's what I've gotten so far, in case anyone can figure it out faster:
> ...
>> 	git clone $HTTPD_URL/smart/test_repo.git test_repo_clone
> ...
>> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] git-http-backend(59490) malloc: *** error for object 0x100200340: incorrect checksum for freed object - object was probably modified after being freed.
>> [Wed Nov 11 06:19:39 2009] [error] [client 127.0.0.1] *** set a breakpoint in malloc_error_break to debug
> 
> I can't reproduce this on 10.5.8.  Can you try running it in the
> debugger and putting a breakpoint where they suggest?  Maybe it
> will help give us some context information:
> 
>  REQUEST_METHOD=GET \
>  PATH_TRANSLATED=`pwd`/.git/info/refs \
>  QUERY_STRING=service=git-upload-pack \
>  gdb ./git-http-backend
> 
>  b malloc_error_break
>  run
> 
> I suspect that's where our failure is, the code path for the actual
> common negotiation and data transfer is shorter, and less likely
> to need to do a memory allocation... and therefore a free.

Interesting.  This command runs to completion.  In the test environment it gives:

Expires: Fri, 01 Jan 1980 00:00:00 GMT
Pragma: no-cache
Cache-Control: no-cache, max-age=0, must-revalidate
Content-Type: application/x-git-upload-pack-advertisement

001e# service=git-upload-pack
0000009b0c973ae9bd51902a28466f3850b543fa66a6aaf4 HEADmulti_ack thin-pack side-band side-band-64k ofs-delta shallow no-progress include-tag multi_ack_detailed
003f0c973ae9bd51902a28466f3850b543fa66a6aaf4 refs/heads/master
0000

(which looks right to me)

access.log has:
127.0.0.1 - - [12/Nov/2009:04:54:38 +0000] "GET /smart/test_repo.git/info/refs?service=git-upload-pack HTTP/1.1" 200 256
127.0.0.1 - - [12/Nov/2009:04:54:38 +0000] "POST /smart/test_repo.git/git-upload-pack HTTP/1.1" 500 538

After a bit of trial and error, I got this:

test_repo.git (BARE:master)$ REQUEST_METHOD=POST PATH_TRANSLATED=`pwd`/git-upload-pack gdb ../../../../../git-http-backend GNU gdb 6.3.50-20050815 (Apple version gdb-1344) (Fri Jul  3 01:19:56 UTC 2009)
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "x86_64-apple-darwin"...Reading symbols for shared libraries ..
warning: Could not find object file "/sw/src/fink.build/libiconv-1.12-3/libiconv-1.12/lib/.libs/iconv.o" - no debug information available for "./iconv.c".


warning: Could not find object file "/sw/src/fink.build/libiconv-1.12-3/libiconv-1.12/lib/.libs/localcharset.o" - no debug information available for "./../libcharset/lib/localcharset.c".


warning: Could not find object file "/sw/src/fink.build/libiconv-1.12-3/libiconv-1.12/lib/.libs/relocatable.o" - no debug information available for "./relocatable.c".

.. done

(gdb) b malloc_error_break 
Breakpoint 1 at 0x4189374bb86951
(gdb) run
Starting program: /Users/brian/dev/git/git-http-backend 
Reading symbols for shared libraries +++. done
git-http-backend(2358) malloc: *** error for object 0x100200390: incorrect checksum for freed object - object was probably modified after being freed.
*** set a breakpoint in malloc_error_break to debug

Breakpoint 1, 0x00007fff84c19951 in malloc_error_break ()
(gdb) bt
#0  0x00007fff84c19951 in malloc_error_break ()
#1  0x00007fff84c1aaa8 in szone_error ()
#2  0x00007fff84b466e3 in tiny_free_list_remove_ptr ()
#3  0x00007fff84b44df7 in szone_realloc ()
#4  0x00007fff84b44b3b in malloc_zone_realloc ()
#5  0x00007fff84b50bd3 in realloc ()
#6  0x000000010004985f in xrealloc (ptr=0x100200370, size=66) at wrapper.c:59
#7  0x0000000100041372 in strbuf_grow (sb=0x7fff5fbfed70, extra=<value temporarily unavailable, due to optimizations>) at strbuf.c:61
#8  0x000000010001e194 in strbuf_addch [inlined] () at /Users/brian/dev/git/strbuf.h:95
#9  0x000000010001e194 in add_path (out=0x7fff5fbfed70, path=0x100200320 "/usr/local/libexec/git-core") at exec_cmd.c:95
#10 0x000000010001e229 in setup_path () at exec_cmd.c:104
#11 0x000000010000226d in main (argc=<value temporarily unavailable, due to optimizations>, argv=<value temporarily unavailable, due to optimizations>) at http-backend.c:641
(gdb) 

I'm lost as to why it's dying doing setup_path.  My guess is that some of the code before here is doing something bad to memory.

~~ Brian