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

AH03467: h2_task: unable to parse status line #138

Closed
xplode opened this Issue May 4, 2017 · 8 comments

Comments

Projects
None yet
2 participants
@xplode

xplode commented May 4, 2017

Configuration
apache: 2.4.25
openssl: 1.0.2j
nghttp2: 1.21.1
mod_http2: 1.10.1

I have a setup where the apache http2 server is acting as a reverse proxy using mod_proxy

I regularily see these errors in the apache log (one every 5 mins or so).

AH03467: h2_task: unable to parse status line: <!DOCTYPE html PUBLIC X XHTML Y Z A <html B xml:lang="en" lang="en" class="loading"> <head> <title>
AH03467: h2_task: unable to parse status line: \xff\xd8\xff\xe1
AH03467: h2_task: unable to parse status line: \x89PNG
AH03467: h2_task: unable to parse status line: \x1f\x8b\b

From what I can gather looking at the mod_http2 code, it seems that mod_http2 thinks that is parsing a serialized http/1.1 response but instead has html, gzipped data, a png file, or basically something that is not an http/1.1 response.

Could this be a state error in mod_http2?

It looks like a similar problem was reported in issue #133 however I am not using mod_proxy_http2.

@icing

This comment has been minimized.

Show comment
Hide comment
@icing

icing May 5, 2017

Owner

Interesting. Will have a closer check, but this looks like mod_http2 expects an interim response, like 100, but it there is still some data pending from a previous request. Hmm.

It must be the same issue as #133. Interesting. Do you know more about the requests that trigger this? Can you give me an example on how mod_proxy is configured (no hostname or addresses, pls.)?

Owner

icing commented May 5, 2017

Interesting. Will have a closer check, but this looks like mod_http2 expects an interim response, like 100, but it there is still some data pending from a previous request. Hmm.

It must be the same issue as #133. Interesting. Do you know more about the requests that trigger this? Can you give me an example on how mod_proxy is configured (no hostname or addresses, pls.)?

@icing

This comment has been minimized.

Show comment
Hide comment
@icing

icing May 5, 2017

Owner

Also, are these messages all from different task ids? h2_task(nn-xx)?

Owner

icing commented May 5, 2017

Also, are these messages all from different task ids? h2_task(nn-xx)?

@icing

This comment has been minimized.

Show comment
Hide comment
@icing

icing May 5, 2017

Owner

Hmm, can it be that someone makes HEAD requests against a handler in the backend that sends the data as if it is a GET? That would leave the response body on the proxy connection. When that is re-used, mod_http2's interim response complains about it.

As it looks, the request will fail and mod_proxy will try it on a new connection. If that is true, the ERROR logging is too high level and DEBUG should be enough.

Can we check if the backend implements HEAD requests correctly?

Owner

icing commented May 5, 2017

Hmm, can it be that someone makes HEAD requests against a handler in the backend that sends the data as if it is a GET? That would leave the response body on the proxy connection. When that is re-used, mod_http2's interim response complains about it.

As it looks, the request will fail and mod_proxy will try it on a new connection. If that is true, the ERROR logging is too high level and DEBUG should be enough.

Can we check if the backend implements HEAD requests correctly?

@icing icing closed this May 5, 2017

@icing icing reopened this May 5, 2017

@icing

This comment has been minimized.

Show comment
Hide comment
@icing

icing May 5, 2017

Owner

Please check v1.10.5 if that works for you.

Owner

icing commented May 5, 2017

Please check v1.10.5 if that works for you.

@xplode

This comment has been minimized.

Show comment
Hide comment
@xplode

xplode May 5, 2017

Thanks for the quick response Stefan. I'll try to respond to the questions you asked above:

Do you know more about the requests that trigger this?
I don't know the exact requests that trigger this error yet.

Can you give me an example on how mod_proxy is configured (no hostname or addresses, pls.)?
Here is an example of the vhost configuration:

<VirtualHost *:443>
  ServerName www.example.com

  ####### inbound SSL setup #######
  SSLEngine on
  SSLCertificateFile "vhosts/example/ssl/server.crt"
  SSLCertificateKeyFile "vhosts/example/ssl/server.key"
  SSLCertificateChainFile "vhosts/example/server.int"
  ####### outbound SSL setup #######
  SSLProxyEngine on

  AddOutputFilterByType DEFLATE text/html text/plain text/xml text/css text/javascript application/javascript text/javascript text/x-js text/x-javascript
 ProxyPreserveHost On

  ####### load balancers ########
  <Proxy balancer://cluster_0_0>
    BalancerMember https://1.1.1.1:443 route=0 timeout=600 retry=0 connectiontimeout=60 loadfactor=1
    ProxySet lbmethod=bybusyness
  </Proxy>

  # ProxyPass configuration for path '/'.
  ProxyPass / balancer://cluster_0_0/
  ProxyPassReverse / balancer://cluster_0_0/

  RequestHeader set X-Forwarded-Proto https
  Protocols h2 http/1.1
</VirtualHost>

Also, are these messages all from different task ids? h2_task(nn-xx)?
Yes, here is a small block of errors:

[Fri May 05 01:08:50.744753 2017] [http2:error] [pid 25280:tid 140526283908864] [client ---.---.--.--6:----9] AH03467: h2_task(1411-3): unable to parse status line: \x1f\x8b\b
[Fri May 05 01:13:11.102462 2017] [http2:error] [pid 31212:tid 140526300694272] [client --.---.---.--1:----9] AH03467: h2_task(1619-1): unable to parse status line: \xff\xd8\xff\xe0
[Fri May 05 01:16:12.424502 2017] [http2:error] [pid 31211:tid 140526065698560] [client --.---.---.-3:----2] AH03467: h2_task(1294-1): unable to parse status line: \x89PNG
[Fri May 05 01:16:36.718699 2017] [http2:error] [pid 31210:tid 140526149625600] [client --.---.---.--7:----0] AH03467: h2_task(458-7): unable to parse status line: \x89PNG
[Fri May 05 01:16:46.493899 2017] [http2:error] [pid 25580:tid 140526023735040] [client ---.--.--.--2:----2] AH03467: h2_task(1046-13): unable to parse status line: \x1f\x8b\b

xplode commented May 5, 2017

Thanks for the quick response Stefan. I'll try to respond to the questions you asked above:

Do you know more about the requests that trigger this?
I don't know the exact requests that trigger this error yet.

Can you give me an example on how mod_proxy is configured (no hostname or addresses, pls.)?
Here is an example of the vhost configuration:

<VirtualHost *:443>
  ServerName www.example.com

  ####### inbound SSL setup #######
  SSLEngine on
  SSLCertificateFile "vhosts/example/ssl/server.crt"
  SSLCertificateKeyFile "vhosts/example/ssl/server.key"
  SSLCertificateChainFile "vhosts/example/server.int"
  ####### outbound SSL setup #######
  SSLProxyEngine on

  AddOutputFilterByType DEFLATE text/html text/plain text/xml text/css text/javascript application/javascript text/javascript text/x-js text/x-javascript
 ProxyPreserveHost On

  ####### load balancers ########
  <Proxy balancer://cluster_0_0>
    BalancerMember https://1.1.1.1:443 route=0 timeout=600 retry=0 connectiontimeout=60 loadfactor=1
    ProxySet lbmethod=bybusyness
  </Proxy>

  # ProxyPass configuration for path '/'.
  ProxyPass / balancer://cluster_0_0/
  ProxyPassReverse / balancer://cluster_0_0/

  RequestHeader set X-Forwarded-Proto https
  Protocols h2 http/1.1
</VirtualHost>

Also, are these messages all from different task ids? h2_task(nn-xx)?
Yes, here is a small block of errors:

[Fri May 05 01:08:50.744753 2017] [http2:error] [pid 25280:tid 140526283908864] [client ---.---.--.--6:----9] AH03467: h2_task(1411-3): unable to parse status line: \x1f\x8b\b
[Fri May 05 01:13:11.102462 2017] [http2:error] [pid 31212:tid 140526300694272] [client --.---.---.--1:----9] AH03467: h2_task(1619-1): unable to parse status line: \xff\xd8\xff\xe0
[Fri May 05 01:16:12.424502 2017] [http2:error] [pid 31211:tid 140526065698560] [client --.---.---.-3:----2] AH03467: h2_task(1294-1): unable to parse status line: \x89PNG
[Fri May 05 01:16:36.718699 2017] [http2:error] [pid 31210:tid 140526149625600] [client --.---.---.--7:----0] AH03467: h2_task(458-7): unable to parse status line: \x89PNG
[Fri May 05 01:16:46.493899 2017] [http2:error] [pid 25580:tid 140526023735040] [client ---.--.--.--2:----2] AH03467: h2_task(1046-13): unable to parse status line: \x1f\x8b\b
@xplode

This comment has been minimized.

Show comment
Hide comment
@xplode

xplode May 5, 2017

I'm working to identify the requests that cause this error. I'll also investigate how the backend responds to HEAD requests to see if it is sending GET data for these. I'll also check out v1.10.5

xplode commented May 5, 2017

I'm working to identify the requests that cause this error. I'll also investigate how the backend responds to HEAD requests to see if it is sending GET data for these. I'll also check out v1.10.5

@icing

This comment has been minimized.

Show comment
Hide comment
@icing

icing Jul 6, 2017

Owner

@xplode anything came out of that? Otherwise, with the mitigation in place, I'd tend to close this issue.

Owner

icing commented Jul 6, 2017

@xplode anything came out of that? Otherwise, with the mitigation in place, I'd tend to close this issue.

@icing

This comment has been minimized.

Show comment
Hide comment
@icing

icing Jul 31, 2017

Owner

Closed due to to interest gone away.

Owner

icing commented Jul 31, 2017

Closed due to to interest gone away.

@icing icing closed this Jul 31, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment