Bug 59838

Summary: mod_proxy_fcgi and AH01068 Got bogus version X error message
Product: Apache httpd-2 Reporter: Luca Toscano <toscano.luca>
Component: mod_proxy_fcgiAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: RESOLVED FIXED    
Severity: normal    
Priority: P2    
Version: 2.5-HEAD   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: Force httpd to read the whole response from a FCGI backend even in presence of errors
Force httpd to read the whole response from a FCGI backend even in presence of errors

Description Luca Toscano 2016-07-10 10:26:09 UTC 
Created attachment 34028 [details]
Force httpd  to read the whole response from a FCGI backend even in presence of errors

Hi! This is a follow up for https://bz.apache.org/bugzilla/show_bug.cgi?id=57198

Recently I tried to track down the following error logs:

[proxy_fcgi:error] [pid 12210:tid 139857489786624] [client ::1:56442] AH01068: Got bogus version 103
[proxy_fcgi:error] [pid 12210:tid 139857489786624] (22)Invalid argument: [client ::1:56442] AH01075: Error dispatching request to :

I am running httpd 2.4.10 (Debian Stable) so I tried to backport some patches to solve the issue with no luck:

- http://svn.apache.org/r1642855
- http://svn.apache.org/r1726019
- http://svn.apache.org/r1650677

So I tried to reproduce in httpd-trunk. Thanks to https://bz.apache.org/bugzilla/show_bug.cgi?id=57198 I was able reproduce, simply issuing a big enough php response that leads to a 304. I attached a simple patch that solves the problem, but I am not expert enough to be sure that it wouldn't trigger undesired side effects. 

The idea is that if iobuf_size is smaller than clen (the length of the FCGI response), then in presence of a non HTTP_OK response (so even a HTTP_NOT_MODIFIED) mod_proxy_fcgi will not try to read the whole response due to a break in the code. For example:

1) FCGI response size/clen:10705 iobuf_size: 8192 
2) mod_proxy_fcgi sees a POLLIN event, reads the FCGI headers finding a AP_FCGI_STDOUT type FCGI record. readbuflen is 8192
3) mod_proxy_fcgi establishes that the response is a 304 (HTTP_NOT_MODIFIED) and flushes the HTTP headers that gets to the client correctly.
4) At this point mod_proxy_fcgi "break"s because it is supposed to not send the 304 response body but it forgets to clear the remaining 10705 - 8192 bytes still pending to read. 
5) mod_proxy_fcgi still sees a POLLIN event for the 10705 - 8192 bytes, and tries to read the FCGI record headers. The data is of course not a valid header so mod_proxy_fcgi recognizes a wrong version and starts the error procedure, namely logging the aforementioned AH01068 and AH01075 errors plus a 503 in the access logs.

So the 304 without the body gets correctly to the client, but httpd thinks it was an error and logs a 503 + scary error messages instead.

Looking forward go get some feedback!

Thanks,

Luca
Comment 1 Luca Toscano 2016-07-10 14:49:12 UTC 
Another thing to consider for a good solution is the "enablereuse=on" use case. The solution that I proposed should ensure that no data will be left to read generating spurious error for subsequent requests, but not super sure about it.
Comment 2 Luca Toscano 2016-07-11 21:23:45 UTC 
After a chat with Jacob on IRC we figured out a simpler way to make this change, namely avoid breaking in the HTTP_NOT_MODIFIED branch case, since it is not an error condition. Added a new patch!
Comment 3 Luca Toscano 2016-07-11 21:24:55 UTC 
Created attachment 34032 [details]
Force httpd  to read the whole response from a FCGI backend even in presence of errors
Comment 4 Luca Toscano 2016-07-12 21:16:49 UTC 
First attempt to patch trunk in http://svn.apache.org/viewvc?view=revision&revision=1752347

As discussed on IRC it would be great to fix the HTTP_PRECONDITION_FAILED use case (HTTP 412) since it causes the following confusing error messages:

AH01070: Error parsing script headers
AH01075: Error dispatching request to :

HTTP_PRECONDITION_FAILED is a value that can be returned by ap_scan_script_header_err_brigade_ex
Comment 5 Luca Toscano 2016-08-01 10:56:55 UTC 
Tried to add another improvement to my change, namely http://svn.apache.org/r1754732

The new behavior that I am proposing should be used only when connection reuse is set to avoid inconsistencies.
Comment 6 Luca Toscano 2016-08-25 12:59:40 UTC 
The issue has been backported to 2.4.x with http://svn.apache.org/r1757670