Re: t5559-http-fetch-smart-http2 failures

From: Jeff King <peff@peff.net>
Date: Dec 1, 2022, 20:25 UTC
Message-ID: <Y4kNu9iFQuKjuub1@coredump.intra.peff.net>
In-Reply-To: <Y4fUntdlc1mqwad5@pobox.com>

On Wed, Nov 30, 2022 at 05:09:34PM -0500, Todd Zullinger wrote:

> The changes in 73c49a4474 (t: run t5551 tests with both HTTP
> and HTTP/2, 2022-11-11) seem to rather frequently trigger
> test failures on Fedora.

Thanks for the report. I can't seem to reproduce here on my Debian system, even with --stress.

I can try a Fedora chroot or vm, but it may take some time to set up. It also sounds like you're not able to reproduce it locally on a Fedora system? Have you tried "./t5559-* --stress"?

Show 18 quoted lines

> The most frequent test to fail is "large fetch-pack requests
> can be sent using chunked encoding" (t5559.30), but earlier
> tests have also failed on occasion.  For the common failure,
> the test exits with:
> 
>     expecting success of 5559.30 'large fetch-pack requests can be sent using chunked encoding': 
> 	    GIT_TRACE_CURL=true git -c http.postbuffer=65536 \
> 		    clone --bare "$HTTPD_URL/smart/repo.git" split.git 2>err &&
> 	    {
> 		    test_have_prereq HTTP2 ||
> 		    grep "^=> Send header: Transfer-Encoding: chunked" err
> 	    }
>     +++ GIT_TRACE_CURL=true
>     +++ git -c http.postbuffer=65536 clone --bare http://127.0.0.1:5559/smart/repo.git split.git
>     error: last command exited with $?=128
>     not ok 30 - large fetch-pack requests can be sent using chunked encoding
> 
> (Less frequently, I've seen the last command exit 141.)

Interesting. 141 implies SIGPIPE, but that may be a red herring. The operation isn't supposed to fail, but if it does due to the server bailing, then the client sometimes hitting SIGPIPE is a known unrelated problem.

Is it possible to see the contents of "err" here? That will have the message from the client, but also the curl trace, which is probably helpful.

It might also be interesting to see the server's view, which would be in httpd/error.log in the trash directory (also access.log, but probably that is not interesting).

> I can easily disable the failing tests for a bit, but does
> anyone have an idea what might be the cause or how to better
> debug it when it occurs on a buildsystem without direct
> access?

If t5551 isn't failing similarly, then presumably the problem is either:

  1. There is some race or bad interaction between curl and apache
     speaking http2 (possibly a buggy version of one?)

  2. http2 requires using mpm_event instead of mpm_prefork. Maybe this
     introduces problems with apache on this system?

  3. there is a bug in git. ;) This is always a possibility, of course,
     but we literally do nothing differently from our end, except pass
     it to curl via CURLOPT_HTTP_VERSION.

It would be interesting to see if doing this:

diff --git a/t/lib-httpd/apache.conf b/t/lib-httpd/apache.conf
index 0294739a77..b24ca44a95 100644
--- a/t/lib-httpd/apache.conf
+++ b/t/lib-httpd/apache.conf
@@ -73,16 +73,9 @@ LockFile accept.lock
 	LoadModule unixd_module modules/mod_unixd.so
 </IfModule>
 
-<IfDefine HTTP2>
 <IfModule !mod_mpm_event.c>
 	LoadModule mpm_event_module modules/mod_mpm_event.so
 </IfModule>
-</IfDefine>
-<IfDefine !HTTP2>
-<IfModule !mod_mpm_prefork.c>
-	LoadModule mpm_prefork_module modules/mod_mpm_prefork.so
-</IfModule>
-</IfDefine>
 </IfVersion>
 
 PassEnv GIT_VALGRIND

also causes t5551 to start failing. If so, then we can blame mpm_event,
and not http2.

-Peff