New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

File streams interrupted with Apache 2.4.35 #170

Closed
pesc opened this Issue Oct 9, 2018 · 13 comments

Comments

Projects
None yet
2 participants
@pesc
Copy link

pesc commented Oct 9, 2018

Hi

Not sure if I'm at the right place but I have a problem with h2 since the Apache 2.4.35 update:

t=39441 [st= 757]    HTTP2_SESSION_RECV_HEADERS
                     --> fin = false
                     --> :status: 200

                         date: Tue, 09 Oct 2018 08:32:52 GMT
                         server: Apache/2.4
                         expires: Thu, 19 Nov 1981 08:52:00 GMT
                         cache-control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
                         pragma: no-cache
                         access-control-allow-origin: *
                         access-control-allow-methods: GET, POST,PUT
                         content-type: text/html; charset=UTF-8
                     --> stream_id = 87
t=39441 [st= 757]    HTTP2_SESSION_RECV_DATA
                     --> fin = false
                     --> size = 2
                     --> stream_id = 87
t=39441 [st= 757]    HTTP2_SESSION_UPDATE_RECV_WINDOW
                     --> delta = -2
                     --> window_size = 15728638
t=39441 [st= 757]    HTTP2_SESSION_RECV_DATA
                     --> fin = true
                     --> size = 0
                     --> stream_id = 87
t=39441 [st= 757]    HTTP2_SESSION_UPDATE_RECV_WINDOW
                     --> delta = 2
                     --> window_size = 15728640
t=44652 [st=5968]    HTTP2_SESSION_RECV_GOAWAY
                     --> active_streams = 0
                     --> debug_data = "timeout"
                     --> error_code = "0 (NO_ERROR)"
                     --> last_accepted_stream_id = 87
                     --> unclaimed_streams = 0
t=44652 [st=5968]    HTTP2_SESSION_CLOSE
                     --> description = "Finished going away"
                     --> net_error = 0 (?)
t=44652 [st=5968]    HTTP2_SESSION_POOL_REMOVE_SESSION
t=44653 [st=5969] -HTTP2_SESSION

Does it have something to do with "low: DoS for HTTP/2 connections by continuous SETTINGS (CVE-2018-11763)"?

Greetings Pascal

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 9, 2018

Trying to parse this. You receive a complete response to stream 757 and then, after 5 seconds, the connection is closed. Am I reading this right?

There were changes related to connection timeout handling and idleness. Connected to the issue, but there were other fixes in connection timeout as well.

The 5 seconds is the default for KeepAliveTimeout in Apache. What behaviour do you expect and/or does it change when you set another keepalive timeout?

@pesc

This comment has been minimized.

Copy link
Author

pesc commented Oct 9, 2018

Yes that's right. In Chrome I get an "net::ERR_CONNECTION_CLOSED" error. And when I disable http2/spdy in my browser or disable h2 in Apache it works without problems. And it just started after updating from Apache 2.4.34 to 2.4.35.

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 9, 2018

Will this go away if you set

KeepAliveTimeout 120

?

@pesc

This comment has been minimized.

Copy link
Author

pesc commented Oct 10, 2018

t=  1029 [st=    80]  HTTP2_SESSION_RECV_HEADERS
                      --> fin = false
                      --> :status: 200
                          date: Wed, 10 Oct 2018 07:42:54 GMT
                          server: Apache/2.4
                          access-control-allow-origin: *
                          access-control-allow-methods: GET, POST,PUT
                          content-type: text/html; charset=UTF-8
                      --> stream_id = 767
t=  1029 [st=    80]  HTTP2_SESSION_RECV_DATA
                      --> fin = false
                      --> size = 1291
                      --> stream_id = 767
t=  1029 [st=    80]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                      --> delta = -1291
                      --> window_size = 15727349
t=  1048 [st=    99]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                      --> delta = 1291
                      --> window_size = 15728640
t=121343 [st=120394]  HTTP2_SESSION_RECV_GOAWAY
                      --> active_streams = 1
                      --> debug_data = "timeout"
                      --> error_code = "0 (NO_ERROR)"
                      --> last_accepted_stream_id = 767
                      --> unclaimed_streams = 0
t=121347 [st=120398]  HTTP2_SESSION_CLOSE
                      --> description = "Connection closed"
                      --> net_error = -100 (ERR_CONNECTION_CLOSED)
t=121347 [st=120398]  HTTP2_SESSION_POOL_REMOVE_SESSION
t=121347 [st=120398] -HTTP2_SESSION

Same thing, but my browser tab is freezed for the 120 seconds

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 10, 2018

Do you have a URL where I can try that with chrome?

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 10, 2018

Upon looking at that second log, I see that the stream is not closed. That would explain the hanging. In your first example the --> fin = true was there.

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 10, 2018

More questions: is this a static file or html generated by some php/cgi backend? (See #167 for another issue with missing fin)

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 10, 2018

And one more: I could really use a error_log at LogLevel http2:trace2 for such a request. :-D
(Mail it to icing at apache.org, in case data may be sensitive)

@pesc

This comment has been minimized.

Copy link
Author

pesc commented Oct 10, 2018

Do you have a URL where I can try that with chrome?

Not right now. Trying to get a public instance of it

More questions: is this a static file or html generated by some php/cgi backend? (See #167 for another issue with missing fin)

It's generated by php.

And one more: I could really use a error_log at LogLevel http2:trace2 for such a request. :-D
(Mail it to icing at apache.org, in case data may be sensitive)

Ok, I'll give it a try.

@pesc

This comment has been minimized.

Copy link
Author

pesc commented Oct 10, 2018

And one more: I could really use a error_log at LogLevel http2:trace2 for such a request. :-D
(Mail it to icing at apache.org, in case data may be sensitive)

I have just sent the e-mail

icing added a commit that referenced this issue Oct 10, 2018

* Adding defensive code for stream EOS handling, in case the request…
… handler somehow

   missed to signal it the normal way. Should address #167 and #170.
@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 10, 2018

Thanks! Just released a (hopefully correct) fix...

asfgit pushed a commit to apache/httpd that referenced this issue Oct 10, 2018

Stefan Eissing
mod_http2: adding defensive code for stream EOS handling, in case the…
… request handler

     missed to signal it the normal way (eos buckets). Addresses github issues 
     icing/mod_h2#164, icing/mod_h2#167
     and icing/mod_h2#170. 



git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@1843426 13f79535-47bb-0310-9956-ffa450edef68
@pesc

This comment has been minimized.

Copy link
Author

pesc commented Oct 10, 2018

Problem seems gone with "mod_http2 (v1.11.3-git.." 👍

@icing

This comment has been minimized.

Copy link
Owner

icing commented Oct 10, 2018

@icing icing closed this Oct 10, 2018

asfgit pushed a commit to apache/httpd that referenced this issue Oct 10, 2018

Merge r1843426 from trunk:
mod_http2: adding defensive code for stream EOS handling, in case the request handler
     missed to signal it the normal way (eos buckets). Addresses github issues 
     icing/mod_h2#164, icing/mod_h2#167
     and icing/mod_h2#170. 


Submitted by: icing
Reviewed by: icing, ylavic, jim


git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/branches/2.4.x@1843468 13f79535-47bb-0310-9956-ffa450edef68
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment