Michael, I can reproduce the problem and habe a fix. Can you test if the
following patch also solves the problem for you? Thanks!
Index: modules/http2/h2_mplx.c
===================================================================
--- modules/http2/h2_mplx.c (revision 1748955)
+++ modules/http2/h2_mplx.c (working copy)
@@ -436,6 +436,9 @@
if (stream->input) {
m->tx_handles_reserved += h2_beam_get_files_beamed(stream->input);
h2_beam_on_consumed(stream->input, NULL, NULL);
+ /* Let anyone blocked reading know that there is no more to come */
+ h2_beam_abort(stream->input);
+ /* Remove mutex after, so that abort still finds cond to signal */
h2_beam_mutex_set(stream->input, NULL, NULL, NULL);
}
h2_stream_cleanup(stream);
> Am 17.06.2016 um 16:40 schrieb Michael Kaufmann <m...@michael-kaufmann.ch>:
>
> Hi,
>
> I have found a regression in mod_http2. When the client stops sending data
> and closes the connection, mod_http2 doesn't detect that the client has left
> and continues to "read" request data (until the request times out because of
> the server's TimeOut value).
>
> The bug has been introduced with mod_http2 version 1.5.8 (SVN 1747532). It is
> also present in the httpd 2.4.21 release candidate. mod_http2 version 1.5.7
> (SVN 1747194) works.
>
>
> How to reproduce:
>
> curl --http2 -k -v --data-binary @bigfile.dat --limit-rate 1
> https://http2-enabled-apache-server/
>
> ... then kill the curl process with "kill <pid>"
>
>
> Log messages:
>
> h2_session.c(1827): h2_session(66): NO_IO event, 1 streams open
> h2_session.c(1691): AH03078: h2_session(66): transit [BUSY] -- no io -->
> [WAIT]
> h2_session.c(2260): h2_session: wait for data, 200000 micros
> h2_mplx.c(775): h2_mplx(66): trywait on data for 200.000000 ms)
> h2_session.c(1691): AH03078: h2_session(66): transit [WAIT] -- wait cycle -->
> [BUSY]
> h2_filter.c(113): core_input(66): read, NONBLOCK_READ, mode=0, readbytes=8000
> h2_filter.c(164): (104)Connection reset by peer: AH03046: h2_conn_io: error
> reading
> h2_session.c(1576): (104)Connection reset by peer: h2_session(66): input gone
> h2_session.c(1777): h2_session(66): conn error -> shutdown
> h2_session.c(789): h2_session(66): malloc(120)
> h2_session.c(643): AH03068: h2_session(66): sent FRAME[GOAWAY[error=0,
> reason='', last_stream=1]], frames=3/3 (r/s)
> h2_session.c(799): h2_session(66): free()
> h2_session.c(799): h2_session(66): free()
> h2_conn_io.c(289): h2_conn_io: pass_output
> h2_conn_io.c(124): bb_dump(66-0)-master conn pass: heap[17] flush
> h2_conn_io.c(309): (32)Broken pipe: AH03044: h2_conn_io(66): pass_out brigade
> 17 bytes
> h2_session.c(740): AH03069: session(66): sent GOAWAY, err=0, msg=
> h2_session.c(1691): AH03078: h2_session(66): transit [BUSY] -- local goaway
> --> [LSHUTDOWN]
> h2_mplx.c(1356): h2_mplx(66): dispatch events
> h2_session.c(1827): h2_session(66): NO_IO event, 1 streams open
> h2_session.c(1691): AH03078: h2_session(66): transit [LSHUTDOWN] -- no io -->
> [WAIT]
> h2_session.c(2260): h2_session: wait for data, 200000 micros
> h2_mplx.c(775): h2_mplx(66): trywait on data for 200.000000 ms)
> h2_session.c(1691): AH03078: h2_session(66): transit [WAIT] -- wait cycle -->
> [LSHUTDOWN]
> h2_filter.c(113): core_input(66): read, NONBLOCK_READ, mode=0, readbytes=8000
> h2_filter.c(164): (103)Software caused connection abort: AH03046: h2_conn_io:
> error reading
> h2_session.c(1576): (103)Software caused connection abort: h2_session(66):
> input gone
> h2_session.c(1691): AH03078: h2_session(66): transit [LSHUTDOWN] -- conn
> error --> [DONE]
> h2_mplx.c(1356): h2_mplx(66): dispatch events
> h2_session.c(2312): (70014)End of file found: h2_session(66): [DONE] process
> returns
> h2_conn_io.c(289): h2_conn_io: pass_output
> h2_conn_io.c(124): bb_dump(66-0)-master conn pass: h2eoc flush
> h2_session.c(963): session(66): cleanup and destroy
> h2_mplx.c(539): h2_mplx(66): release_join with 1 streams open, 0 streams
> resume, 0 streams ready, 1 tasks
> h2_mplx.c(518): h2_mplx(66-1): exists, started=1, scheduled=1, submitted=0,
> suspended=0
> h2_mplx.c(402): h2_stream(66-1): done
> h2_mplx.c(567): h2_mplx(66): 2. release_join with 1 streams in hold
> AH03198: h2_mplx(66): release, waiting for 5 seconds now for 1 h2_workers to
> return, have still 1 tasks outstanding
> ->03198: h2_stream(66-1): POST server /myurl -> ? 0[orph=1/started=1/done=0]
> AH03198: h2_mplx(66): release, waiting for 10 seconds now for 1 h2_workers to
> return, have still 1 tasks outstanding
> AH03198: h2_mplx(66): release, waiting for 15 seconds now for 1 h2_workers to
> return, have still 1 tasks outstanding
> AH03198: h2_mplx(66): release, waiting for 20 seconds now for 1 h2_workers to
> return, have still 1 tasks outstanding
> [...]
> AH03198: h2_mplx(66): release, waiting for 270 seconds now for 1 h2_workers
> to return, have still 1 tasks outstanding
> AH03198: h2_mplx(66): release, waiting for 275 seconds now for 1 h2_workers
> to return, have still 1 tasks outstanding
> AH03198: h2_mplx(66): release, waiting for 280 seconds now for 1 h2_workers
> to return, have still 1 tasks outstanding
> AH03198: h2_mplx(66): release, waiting for 285 seconds now for 1 h2_workers
> to return, have still 1 tasks outstanding
> h2_task.c(194): (70007)The timeout specified has expired: h2_task(66-1): read
> returned
> mod_airlock.c(1307): Error reading body data from client (errno = 0)
> h2_from_h1.c(488): h2_from_h1(1): output_filter called
> h2_from_h1.c(551): h2_from_h1(1): removed header filter, passing brigade len=0
> h2_task.c(355): h2_task(66-1): write response body (0 bytes)
> h2_task.c(355): h2_task(66-1): write response body (0 bytes)
> h2_task.c(355): h2_task(66-1): write response body (0 bytes)
> h2_task.c(343): AH03348: h2_task(66-1): open response to POST iaves60
> /capi/TestServlet
> h2_task.c(753): h2_task(66-1): process_request done
> h2_task.c(725): h2_task(66-1): processing done
> h2_mplx.c(949): h2_mplx(66): task(66-1) done
> h2_mplx.c(995): h2_mplx(66-1): request done, 300007.554000 ms elapsed
> h2_mplx.c(1009): h2_mplx(66): increase worker limit to 8
> h2_mplx.c(1030): h2_mplx(66-1): task_done, stream in hold
> h2_workers.c(119): h2_worker(0): looking for work
> h2_workers.c(159): h2_worker(0): waiting signal (eternal), worker_count=64,
> idle=64
> h2_mplx.c(612): h2_mplx(66): 3. release_join 1 streams to purge
> h2_stream.c(234): h2_stream(66-1): destroy
> h2_mplx.c(350): h2_task(66-1): destroy
> h2_conn.c(316): h2_slave_conn(66): destroy (task=66-1)
> h2_mplx.c(223): h2_mplx(66): destroy, tasks=0
> h2_session.c(799): h2_session(66): free()
> h2_session.c(799): h2_session(66): free()
> h2_session.c(799): h2_session(66): free()
> [...]
> h2_session.c(698): h2_session(66): destroy
> h2_conn_io.c(309): (103)Software caused connection abort: AH03044:
> h2_conn_io(66): pass_out brigade 0 bytes
> h2_conn.c(215): (70014)End of file found: AH03045: h2_session(66): process,
> closing conn
>
>
> Regards,
> Michael
>
