t5559 breaks with apache 2.4.55

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

Jeff King wrote:

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/

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

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

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

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

Jeff King <peff@peff.net> writes:

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(-)

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

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...

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

Jeff King <peff@peff.net> writes:

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.

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

OK, works for me.

Thanks.

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

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.

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.

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