Bug 60244

Summary: mod_http2 causes serialized requests if there are parallel long running requests on the same connection
Product: Apache httpd-2 Reporter: Reno Reckling <e-apache>
Component: mod_http2Assignee: Apache HTTPD Bugs Mailing List <bugs>
Status: RESOLVED WORKSFORME    
Severity: normal CC: e-apache
Priority: P2    
Version: 2.4.23   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: loglevel trace8 of a session that has the problem

Description Reno Reckling 2016-10-12 11:59:33 UTC 
Hi, I just tried to move my webserver to use http2 and discovered the following phenomenon.

This happens in chrome as well as in firefox with apache2 2.4.23.

If I open one tab to my http2 enabled domain (using h2) and it does background ajax long-polling to a php script on the server (The script just does sleep(30)).
While the longpoll is running, if i try to open a new tab to the same server, the new request gets stuck in the "pending" state until the longpoll is finished.
The second request can be against a static .html file (so no php processing) and still gets stuck.
If I disable http2 for this setup, the requests finish in parallel just fine.

It seems to me that I somehow cause all requests to be serialized for the same connection but different streams.
This does NOT happen for different connections, so longpoll in chrome and second request in firefox is fine.

List of my used modules:
core.c, http_core.c, mod_access_compat.c, mod_actions.c, mod_alias.c, mod_auth_basic.c, mod_authn_core.c, mod_authn_file.c, mod_authz_core.c, mod_authz_groupfile.c, mod_authz_host.c, mod_authz_unixgroup.c, mod_authz_user.c, mod_autoindex.c, mod_cgi.c, mod_dav.c, mod_dav_fs.c, mod_deflate.c, mod_dir.c, mod_env.c, mod_filter.c, mod_headers.c, mod_http2.c, mod_include.c, mod_info.c, mod_log_config.c, mod_logio.c, mod_mime.c, mod_negotiation.c, mod_php7.c, mod_proxy.c, mod_proxy_http.c, mod_reqtimeout.c, mod_rewrite.c, mod_setenvif.c, mod_so.c, mod_socache_shmcb.c, mod_ssl.c, mod_status.c, mod_unixd.c, mod_version.c, mod_watchdog.c, mod_wsgi.c, prefork.c
Comment 1 Reno Reckling 2016-10-12 12:11:51 UTC 
Additional insight:

This happens _only_ during requests that involve php.

If i have a long running download that shares a connection with another static file requests, everything is fine.
Could it be that mod_php7 somehow gets an exclusive lock on the connection except just on the stream?
Comment 2 Eric Covener 2016-10-12 14:30:18 UTC 
loglevel trace8 of the situation pls?
Comment 3 Reno Reckling 2016-10-12 15:13:56 UTC 
Created attachment 34368 [details]
loglevel trace8 of a session that has the problem

This shows the following series of event:

Request to /test/first.html in tab #1, which loads the basic html and some javascript.
The javascript of first.html then does an ajax request to /test/longpoll.php which hangs for 30 seconds.
This phase is clearly visible because of the 30 second long period of:
OpenSSL: I/O error, 5 bytes expected to read on BIO#558423e82670

2 seconds after the longpoll.php request is initiated, i open another tab #2 to /test/second.html. This one does not really show up in the log just yet.

After the longpoll in Tab #1 finished, the log says:
AH02034: Subsequent (No.3) HTTPS request received for child 2 (server exi.wthack.de:443)

Which goes to /test/second.html and finished immediately.

Anything else i could provide to help solve this?
Comment 4 Stefan Eissing 2016-10-12 15:33:42 UTC 
The problem is that you run 'prefork' as your mpm. In prefork there is only one connection/request per process. So, when you browser reuses the h2 connection, it ends up in the very same process that is working on the longpoll.

What can you do?
1. Disable http2
2. Switch to mpm_event
3. Enable more H2Workers per process (the default on prefork is 1, since prefork is intended to not have multithreading).

2 would be my recommendation. 3 might not work if you really need prefork. 1 makes me sad.
Comment 5 Reno Reckling 2016-10-13 10:32:37 UTC 
I went for mpm_event + mod_fcgid which works nicely for php. Thank you
Comment 6 Laurence 'GreenReaper' Parry 2016-10-20 23:51:03 UTC 
This behaviour should really be documented. It makes sense once you understand the reason, but is unexpected nevertheless, and has the potential for triggering hard-to-track bugs where it looks like the client may be at issue. Current browsers show the connections as "stalled" even though they may in fact have done their part in issuing the request.

While HTTP/2 is not doing anything "wrong", per-se, it is a case where it breaks website workflows which worked fine with HTTP/1.1 on the same MPM.

Possible locations to mention it:
https://httpd.apache.org/docs/2.4/howto/http2.html
https://httpd.apache.org/docs/2.4/mod/mod_http2.html#h2maxworkers ("If this directive is not used, mod_http2 will chose a value suitable for the mpm module loaded." is not enough, because it does not specify a value or the implications.)