t5559 breaks with apache 2.4.55

t5559 breaks with apache 2.4.55

[Jeff King]

I noticed that the test suite now fails after upgrading from apache
2.4.54 to 2.4.55 (the latter of which just hit debian unstable). The
problem is with the http2 tests, specifically t5559.30, where we send a
large fetch negotiation over http2. The output from curl is (including
some bits of tracing):

  == Info: Received 101, Switching to HTTP/2
  == Info: Using HTTP2, server supports multiplexing
  == Info: Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
  == Info: Closing connection 1
  error: RPC failed; HTTP 101 curl 16 Error in the HTTP2 framing layer

Bisecting within apache's Git repo, the culprit is their 9767274b88,
which says:

  mod_http2: version 2.0.10 of the module, synchronizing changes
  with the gitgub version. This is a partial rewrite of how connections
  and streams are handled.

which seems like a plausible source. But the diff is 8000 lines. It may
be possible to bisect within the mod_http2 source itself, but I haven't
tried it yet.

It's also not 100% clear that it's an apache bug. We could be doing
something weird with git-http-backend, or curl might be doing something
wrong. Though I tend to doubt it, given the simplicity of the CGI
interface on the server side and the fact that curl was working reliably
with older versions of apache.

So I haven't reported the bug further yet. But I thought I'd post this
here before anybody else wastes time digging in the same hole.

-Peff

Re: t5559 breaks with apache 2.4.55

[Todd Zullinger]

Jeff King wrote:
> I noticed that the test suite now fails after upgrading from apache
> 2.4.54 to 2.4.55 (the latter of which just hit debian unstable). The
> problem is with the http2 tests, specifically t5559.30, where we send a
> large fetch negotiation over http2. The output from curl is (including
> some bits of tracing):
> 
>   == Info: Received 101, Switching to HTTP/2
>   == Info: Using HTTP2, server supports multiplexing
>   == Info: Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
>   == Info: Closing connection 1
>   error: RPC failed; HTTP 101 curl 16 Error in the HTTP2 framing layer
> 
> Bisecting within apache's Git repo, the culprit is their 9767274b88,
> which says:
> 
>   mod_http2: version 2.0.10 of the module, synchronizing changes
>   with the gitgub version. This is a partial rewrite of how connections
>   and streams are handled.
> 
> which seems like a plausible source. But the diff is 8000 lines. It may
> be possible to bisect within the mod_http2 source itself, but I haven't
> tried it yet.
> 
> It's also not 100% clear that it's an apache bug. We could be doing
> something weird with git-http-backend, or curl might be doing something
> wrong. Though I tend to doubt it, given the simplicity of the CGI
> interface on the server side and the fact that curl was working reliably
> with older versions of apache.
> 
> So I haven't reported the bug further yet. But I thought I'd post this
> here before anybody else wastes time digging in the same hole.

FWIW, I think this is the same issue we discussed about 2
months back, in <Y4fUntdlc1mqwad5@pobox.com>¹.

I haven't done much else with it since then.  It's almost
surely either an apache httpd/mod_http2 or curl issue.  If I
had to bet, I'd say mod_http2.  (But then, it could be curl
and just has yet to be exposed widely because not many are
using the current mod_http2 code.)

¹ https://lore.kernel.org/git/Y4fUntdlc1mqwad5@pobox.com/

-- 
Todd

Re: t5559 breaks with apache 2.4.55

[Jeff King]

On Sun, Jan 22, 2023 at 11:33:07AM -0500, Todd Zullinger wrote:

> > So I haven't reported the bug further yet. But I thought I'd post this
> > here before anybody else wastes time digging in the same hole.
> 
> FWIW, I think this is the same issue we discussed about 2
> months back, in <Y4fUntdlc1mqwad5@pobox.com>¹.
> 
> I haven't done much else with it since then.  It's almost
> surely either an apache httpd/mod_http2 or curl issue.  If I
> had to bet, I'd say mod_http2.  (But then, it could be curl
> and just has yet to be exposed widely because not many are
> using the current mod_http2 code.)
> 
> ¹ https://lore.kernel.org/git/Y4fUntdlc1mqwad5@pobox.com/

Ah, I somehow completely forgot about that issue. Despite being one of
the two participants on the thread.

Yeah, after seeing that, I'm quite sure this is a mod_http2 issue. It
would be nice to bisect within the mod_http2 history to find the
culprit, but I'd first have to figure out how to build standalone apache
modules. ;)

I may try to poke at it later if I have time. It might also be worth
submitting a bug report to the mod_http2 folks. I'd hope to have a more
compact reproduction, but it does at least seem to fail reliably for me
(not even racily).

-Peff

Re: t5559 breaks with apache 2.4.55

[Jeff King]

On Thu, Jan 26, 2023 at 06:39:42AM -0500, Jeff King wrote:

> Yeah, after seeing that, I'm quite sure this is a mod_http2 issue. It
> would be nice to bisect within the mod_http2 history to find the
> culprit, but I'd first have to figure out how to build standalone apache
> modules. ;)

This turned out to be quite painless, so I bisected using the source at:

  https://github.com/icing/mod_h2

Unfortunately, it's not super helpful for identifying the problem.  The
culprit turns out to be 16ffed9692b, which has a 450-line diff. The
commit message is:

  * refactored stream response handling to reflect the different phases
    (response/data/trailers) more clearly and help resolving cpu busy loops.

But that does at least give me more confidence that the bug is in
mod_http2, and isn't, say, some intentional behavior change there that
happens to trigger a bug in curl.

I opened an issue here: https://github.com/icing/mod_h2/issues/243

So we'll see if that helps.

I re-read your earlier thread, and the version problems you have don't
quite line up. I think you were having issues with mod_http2 2.0.9, but
the older version (1.5.19) worked. I was OK with 2.0.9, but upgrading to
2.0.10 broke things. I'd hate to have to disable t5559 by default; it
does catch some cases that would trigger in the real-world (since real
sites like GitHub are using http2). But if it's too unreliable in
practice, that might be the path of least resistance.

-Peff

Re: t5559 breaks with apache 2.4.55

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> ...
> But that does at least give me more confidence that the bug is in
> mod_http2, and isn't, say, some intentional behavior change there that
> happens to trigger a bug in curl.
>
> I opened an issue here: https://github.com/icing/mod_h2/issues/243
>
> So we'll see if that helps.

Thanks.  I've seen that the above issue may have redirected the
investigation to cURL, and over time, I expect taht this will start
to trigger in more environments (as Apache 2.4.55 and mod_h2 2.0.10
propagates) before it fixes itself (as fixed versions of these
things we use in our tests percolates down).

In the meantime, perhaps we should punt with a patch like this?


------------ >8 ------------
Subject: [PATCH] t5559: skip a known-to-be-broken test

t5559 runs the same set of tests as t5551 under HTTP/2 but one of
them started failing with Apache 2.4.55 and mod_h2 2.0.10 (but not
with HTTP/1.1).  Newer mod_h2 is known to have fixed the issue.

In the meantime, skip the test.

Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 t/t5551-http-fetch-smart.sh | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git c/t/t5551-http-fetch-smart.sh w/t/t5551-http-fetch-smart.sh
index bc0719a4fc..52159e8b6f 100755
--- c/t/t5551-http-fetch-smart.sh
+++ w/t/t5551-http-fetch-smart.sh
@@ -350,7 +350,8 @@ test_expect_success CMDLINE_LIMIT \
 	)
 '
 
-test_expect_success 'large fetch-pack requests can be sent using chunked encoding' '
+# https://github.com/icing/mod_h2/issues/243
+test_expect_success !HTTP2 '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 &&
 	{

Re: t5559 breaks with apache 2.4.55

[Jeff King]

On Thu, Feb 09, 2023 at 01:45:10PM -0800, Junio C Hamano wrote:

> Jeff King <peff@peff.net> writes:
> 
> > ...
> > But that does at least give me more confidence that the bug is in
> > mod_http2, and isn't, say, some intentional behavior change there that
> > happens to trigger a bug in curl.
> >
> > I opened an issue here: https://github.com/icing/mod_h2/issues/243
> >
> > So we'll see if that helps.
> 
> Thanks.  I've seen that the above issue may have redirected the
> investigation to cURL, and over time, I expect taht this will start
> to trigger in more environments (as Apache 2.4.55 and mod_h2 2.0.10
> propagates) before it fixes itself (as fixed versions of these
> things we use in our tests percolates down).

Yeah, I am worried that this will bite other people, though it's not
clear to me yet how common the problematic version will be. But...

> In the meantime, perhaps we should punt with a patch like this?
> 
> 
> ------------ >8 ------------
> Subject: [PATCH] t5559: skip a known-to-be-broken test
> 
> t5559 runs the same set of tests as t5551 under HTTP/2 but one of
> them started failing with Apache 2.4.55 and mod_h2 2.0.10 (but not
> with HTTP/1.1).  Newer mod_h2 is known to have fixed the issue.
> 
> In the meantime, skip the test.

I'm not sure this is really sufficient. As I was running t5559 over and
over to test various versions, I noticed a few other cases that seemed
to fail, some of them racily. So I'm a bit worried that the problem may
be more extensive, and it is only that this particular test happened to
trigger it reliably.

In which case the right solution may be ditching t5559, or at the very
least adding a knob or version check to disable it.

So I'm tempted to just punt for now and see how often this bites people
in the real world. And if it does become a problem, we'll have more data
on what exactly should be changed.

-Peff

Re: t5559 breaks with apache 2.4.55

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> I'm not sure this is really sufficient. As I was running t5559 over and
> over to test various versions, I noticed a few other cases that seemed
> to fail, some of them racily. So I'm a bit worried that the problem may
> be more extensive, and it is only that this particular test happened to
> trigger it reliably.

Yeah, I've seen not just t5559.30 (which is what the patch was
about) reliably fail, but t5559.25 fail only from time to time.
There may be others.

> In which case the right solution may be ditching t5559, or at the very
> least adding a knob or version check to disable it.

Yup.  Do we have an example of checking versions of mod_frob being
used from within our test suite?  I didn't locate one.

> So I'm tempted to just punt for now and see how often this bites people
> in the real world. And if it does become a problem, we'll have more data
> on what exactly should be changed.

OK, works for me.

Thanks.

Re: t5559 breaks with apache 2.4.55

[Jeff King]

On Fri, Feb 10, 2023 at 06:34:43PM -0800, Junio C Hamano wrote:

> Jeff King <peff@peff.net> writes:
> 
> > I'm not sure this is really sufficient. As I was running t5559 over and
> > over to test various versions, I noticed a few other cases that seemed
> > to fail, some of them racily. So I'm a bit worried that the problem may
> > be more extensive, and it is only that this particular test happened to
> > trigger it reliably.
> 
> Yeah, I've seen not just t5559.30 (which is what the patch was
> about) reliably fail, but t5559.25 fail only from time to time.
> There may be others.

Ah, then if it's not just me, maybe it is time to take action. :)

I'm not sure if we have a complete list of good/bad versions, though. I
know 2.0.10 was bad, and 2.0.9 seemed to be OK for me. 2.0.12 passes for
me in regular use, but --stress seems to quickly barf. But it does for
v2.0.9, too.

> > In which case the right solution may be ditching t5559, or at the very
> > least adding a knob or version check to disable it.
> 
> Yup.  Do we have an example of checking versions of mod_frob being
> used from within our test suite?  I didn't locate one.

No, I don't think we do. The answers on stack overflow suggest using
"strings" on the .so file. Not only is that gross, it doesn't seem to
work in this case (I find "mod_http2 (v%s)", which is useless).

We could check the outer apache version with "apachectl -v", which is
enough for Debian, but I think Todd had cases where the system was using
a separate version of the mod, not the one that ships with apache
itself.

I didn't see anything with IfVersion or IfModule that would let us
depend on the module version. It does look like we can probably crank
the LogLevel up and then grep for "mod_http2 (v[0-9.]+" in the log after
starting the server. That would let us bail before actually running any
tests.

We can be a bit cavalier here with technique, I think, because the worst
case is that we say "this is not a known-good version" and just skip the
http/2 tests.

> > So I'm tempted to just punt for now and see how often this bites people
> > in the real world. And if it does become a problem, we'll have more data
> > on what exactly should be changed.
> 
> OK, works for me.

Well, I was all set to try a version check, but after seeing the
race problems above, it doesn't seem like a good direction, at least not
yet. So I'm content to sit on my hands for a while longer.

-Peff