httpd-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Stefan Eissing <stefan.eiss...@greenbytes.de>
Subject Re: Regression: mod_http2 continues to process abandoned connection
Date Sat, 18 Jun 2016 11:27:05 GMT
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 <mail@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
> 


Mime
View raw message