Am 29.08.2016 um 15:52 schrieb Stefan Eissing: > >> Am 29.08.2016 um 15:43 schrieb Stefan Priebe - Profihost AG >> <[email protected]>: >> >> Am 29.08.2016 um 15:31 schrieb Stefan Eissing: >>> >>>> Am 26.08.2016 um 20:02 schrieb Stefan Priebe - Profihost AG >>>> <[email protected]>: >>>> >>>> [Fri Aug 26 19:54:05.321979 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_stream.c(205): [client 1.2.3.4:38822] AH03082: >>>> h2_stream(212-45): opened >>>> [Fri Aug 26 19:54:05.322017 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_session.c(432): [client 1.2.3.4:38822] AH03066: >>>> h2_session(212): recv FRAME[HEADERS[length=126, hend=1, stream=45, >>>> eos=1]], frames=25/47 (r/s) >>>> [Fri Aug 26 19:54:05.651654 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_session.c(432): [client 1.2.3.4:38822] AH03066: >>>> h2_session(212): recv FRAME[RST_STREAM[length=4, flags=0, stream=45]], >>>> frames=26/47 (r/s) >>>> [Fri Aug 26 19:54:05.651673 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_session.c(501): [client 1.2.3.4:38822] AH03067: >>>> h2_session(212-45): RST_STREAM by client, errror=8 >>>> [Fri Aug 26 19:54:05.651678 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_session.c(340): [client 1.2.3.4:38822] AH03065: >>>> h2_stream(212-45): closing with err=8 cancel >>>> [Fri Aug 26 19:54:05.651697 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_stream.c(205): [client 1.2.3.4:38822] AH03082: >>>> h2_stream(212-47): opened >>>> [Fri Aug 26 19:54:05.651720 2016] [http2:debug] [pid 13222:tid >>>> 139700320794368] h2_session.c(432): [client 1.2.3.4:38822] AH03066: >>>> h2_session(212): recv FRAME[HEADERS[length=126, hend=1, stream=47, >>>> eos=1]], frames=27/47 (r/s) >>>> [Fri Aug 26 19:54:06.119019 2016] [http2:debug] [pid 13222:tid >>>> 139700772161280] h2_task.c(357): [client 1.2.3.4:38822] AH03348: >>>> h2_task(212-45): open response to GET X.de /admin/admin.cgi?todo=admin >>>> [Fri Aug 26 19:54:06.421545 2016] [cgid:error] [pid 13222:tid >>>> 139700755375872] [client 1.2.3.4:38822] End of script output before >>>> headers: admin.cgi, referer: https://X.de/admin/admin.cgi?todo=admin >>> >>> What I can see here is that stream 45 is opened on connection 212 and >>> scheduled for processing. The client then aborts the request (RST_STREAM) >>> and start the new stream 47. >>> During this, the CGI has produced a response ("open response") which >>> leads to an error, since the stream is gone, and the CGI closes early >>> (End of script output before headers) >> >> The problem is this happens only sporadic. You can reload the page X >> times and in about 1/10 you get an internal server error. You never get >> one if you close STDERR in the beginning of the script. This also never >> happens with HTTP 1.1. >> >> >>> So, I'd say from the log output, all seems as expected. Where is the >>> internal server error you mentioned? >> What do you exactly mean? There is nothing else written to the log. Not >> even an error log message. > > What I mean is that I see no delivery to the client that contains an error. > What exactly do you see? A "500 blabla HTTP/2" status response? Or something > else? That is not clear to me (or I overlooked sth)
Response Header is: accept-ranges:bytes content-length:1751 content-type:text/html date:Mon, 29 Aug 2016 14:06:56 GMT last-modified:Wed, 10 Sep 2014 08:40:06 GMT server:Apache status:500 strict-transport-security:max-age=7776000 vary:User-Agent May be this filtered log output is better: It was produced by: grep "131" server-error.log | egrep "=77|-77" [Mon Aug 29 16:12:09.672322 2016] [http2:debug] [pid 28482:tid 139700455077632] h2_stream.c(205): [client X.X.X.X:51744] AH03082: h2_stream(131-77): opened [Mon Aug 29 16:12:09.672386 2016] [http2:debug] [pid 28482:tid 139700455077632] h2_session.c(432): [client X.X.X.X:51744] AH03066: h2_session(131): recv FRAME[HEADERS[length=128, hend=1, stream=77, eos=1]], frames=41/81 (r/s) [Mon Aug 29 16:12:10.051331 2016] [http2:debug] [pid 28482:tid 139700455077632] h2_session.c(1461): [client X.X.X.X:51744] AH03073: h2_stream(131-77): submit response 500, REMOTE_WINDOW_SIZE=6291456 [Mon Aug 29 16:12:10.051364 2016] [http2:debug] [pid 28482:tid 139700455077632] h2_session.c(652): [client X.X.X.X:51744] AH03068: h2_session(131): sent FRAME[HEADERS[length=22, hend=1, stream=77, eos=0]], frames=42/83 (r/s) [Mon Aug 29 16:12:10.051381 2016] [http2:debug] [pid 28482:tid 139700455077632] h2_session.c(652): [client X.X.X.X:51744] AH03068: h2_session(131): sent FRAME[DATA[length=1751, flags=1, stream=77, padlen=0]], frames=42/84 (r/s) [Mon Aug 29 16:12:15.969186 2016] [http2:debug] [pid 28482:tid 139700278830848] h2_session.c(652): [remote X.X.X.X:51744] AH03068: h2_session(131): sent FRAME[GOAWAY[error=0, reason='timeout', last_stream=77]], frames=42/85 (r/s) Stefan
