Created attachment 32893 [details] Patch If the user aborts the connection, while mod_proxy_fcgi reads data from the backend and pass it down the filter chain, ap_core_output_filter returns EPIPE or ECONNABORTED which is returned by dispatch and interpreted by fcgi_do_request in mod_proxy_fcgi as an backend failure and HTTP_SERVICE_UNAVAILABLE is returned. This seems to be wrong since the fcgi backend worked fine. There is also an inconsistency between what the client (partially) recieved and what's logged. I invested some time to retrace this behaviour. You can provoke it, when you request a big file from the fcgi backend and abort the retrieval (e.g. use wget on the CLI and Ctrl + C). I want to propose a patch (see attachement), but please be aware that I'm neither an experienced C-programmer nor ever submitted a patch to an open source project. Having this in mind: The patch worked for me (built successfully on SLES and tested it with the described procedure above). If LogLevel is trace1 or lower it leads to a error-Log entry. I don't know whether APLOGNO(001075) is the correct error number, I didn't find the documentation under docs/log-message-tags/README (pointed to in includes/httpd.h, 117) If necessary I can provide further information. Kind regards, Tobias Adolph
This should be fixed in 2.4.16 by r1682544, can you confirm?
I can confirm that the described behaviour vanished using random samples in a 2.4.16-test environment. If you would be so kind to let this bug report open another two weeks I could confirm it with one week of a heavy loaded and productive 2.4.16-httpd. Thanks a lot for the hint. Kind regards, Tobias Adolph
Thanks for your patience. The number of instances of the described behaviour has been dramatically reduced by updating to 2.4.16. There are two remaining issues though: *) Error reporting is still relatively verbose (this could be solved by placing the error logging in dispatch in mod_proxy_fcgi behind the newly introduced lines (from 836 to 848). *) There are still some 503 errors, correlating them with events in the error log is hard, since the error logs are still flooded by "Broken Pipe"-Messages (see first issue). Please let me know, whether you are interested in a patch proposal to solve the verbosity of the error log (see also Eric Coveners Mail to the dev-list concerning AH01075: https://www.mail-archive.com/dev@httpd.apache.org/msg62716.html)
This still appears to be an issue, my access logs are being flooded with "errors" that aren't really errors at all because of it (e.g. Broken pipe and Connection reset by peer): [Fri Jan 15 13:52:30.310363 2016] [proxy_fcgi:error] [pid 30073:tid 139625334949632] (32)Broken pipe: [client (client IP):21616] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:53:25.254195 2016] [proxy_fcgi:error] [pid 30073:tid 139625486018304] (32)Broken pipe: [client (client IP):21698] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:53:26.909418 2016] [proxy_fcgi:error] [pid 30073:tid 139625326556928] (32)Broken pipe: [client (client IP):21700] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:53:32.273391 2016] [proxy_fcgi:error] [pid 30073:tid 139625175488256] (32)Broken pipe: [client (client IP):21706] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:53:33.761588 2016] [proxy_fcgi:error] [pid 30073:tid 139625368520448] (32)Broken pipe: [client (client IP):21708] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:53:50.531227 2016] [proxy_fcgi:error] [pid 30073:tid 139625318164224] (32)Broken pipe: [client (client IP):21721] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:53:52.041563 2016] [proxy_fcgi:error] [pid 30073:tid 139625259415296] (32)Broken pipe: [client (client IP):21722] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:54:19.809860 2016] [proxy_fcgi:error] [pid 30073:tid 139625309771520] (32)Broken pipe: [client (client IP):21739] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:54:21.735914 2016] [proxy_fcgi:error] [pid 30073:tid 139625735673600] (32)Broken pipe: [client (client IP):21741] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:54:38.697700 2016] [proxy_fcgi:error] [pid 30073:tid 139625595123456] (32)Broken pipe: [client (client IP):21789] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:54:40.084698 2016] [proxy_fcgi:error] [pid 30073:tid 139625334949632] (32)Broken pipe: [client (client IP):21790] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:54:51.835886 2016] [proxy_fcgi:error] [pid 30073:tid 139625469232896] (32)Broken pipe: [client (client IP):21810] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:54:53.080191 2016] [proxy_fcgi:error] [pid 30073:tid 139625209059072] (32)Broken pipe: [client (client IP):21814] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:55:36.217963 2016] [proxy_fcgi:error] [pid 30073:tid 139625527981824] (32)Broken pipe: [client (client IP):21858] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:55:37.585038 2016] [proxy_fcgi:error] [pid 30073:tid 139625267808000] (32)Broken pipe: [client (client IP):21859] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:56:14.820135 2016] [proxy_fcgi:error] [pid 30073:tid 139625435662080] (32)Broken pipe: [client (client IP):21933] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:56:15.965667 2016] [proxy_fcgi:error] [pid 30050:tid 139625578338048] (32)Broken pipe: [client (client IP):21934] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:56:50.592806 2016] [proxy_fcgi:error] [pid 30073:tid 139625167095552] (32)Broken pipe: [client (client IP):22008] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:56:51.728229 2016] [proxy_fcgi:error] [pid 30073:tid 139625175488256] (32)Broken pipe: [client (client IP):22017] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:57:57.974901 2016] [proxy_fcgi:error] [pid 30073:tid 139625735673600] (32)Broken pipe: [client (client IP):22097] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:00.088720 2016] [proxy_fcgi:error] [pid 30073:tid 139625385305856] (32)Broken pipe: [client (client IP):22100] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:02.945572 2016] [proxy_fcgi:error] [pid 30073:tid 139625444054784] (32)Broken pipe: [client (client IP):22106] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:03.386505 2016] [proxy_fcgi:error] [pid 30073:tid 139625284593408] (32)Broken pipe: [client (client IP):22108] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:04.106937 2016] [proxy_fcgi:error] [pid 30073:tid 139625603516160] (32)Broken pipe: [client (client IP):22110] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:04.928936 2016] [proxy_fcgi:error] [pid 30073:tid 139625460840192] (32)Broken pipe: [client (client IP):22111] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:38.240030 2016] [proxy_fcgi:error] [pid 30050:tid 139625477625600] (104)Connection reset by peer: [client (client IP):22165] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:58:39.472181 2016] [proxy_fcgi:error] [pid 30050:tid 139625217451776] (32)Broken pipe: [client (client IP):22168] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:59:55.384356 2016] [proxy_fcgi:error] [pid 30073:tid 139625318164224] (32)Broken pipe: [client (client IP):22255] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 13:59:56.961341 2016] [proxy_fcgi:error] [pid 30073:tid 139625267808000] (32)Broken pipe: [client (client IP):22257] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:03.262299 2016] [proxy_fcgi:error] [pid 30073:tid 139625735673600] (32)Broken pipe: [client (client IP):22270] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:05.265313 2016] [proxy_fcgi:error] [pid 30073:tid 139625595123456] (32)Broken pipe: [client (client IP):22273] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:11.569012 2016] [proxy_fcgi:error] [pid 30073:tid 139625519589120] (32)Broken pipe: [client (client IP):22299] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:13.052268 2016] [proxy_fcgi:error] [pid 30073:tid 139625385305856] (32)Broken pipe: [client (client IP):22303] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:21.001057 2016] [proxy_fcgi:error] [pid 30050:tid 139625752459008] (32)Broken pipe: [client (client IP):22332] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:21.920456 2016] [proxy_fcgi:error] [pid 30073:tid 139625710495488] (32)Broken pipe: [client (client IP):22333] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:23.061276 2016] [proxy_fcgi:error] [pid 30073:tid 139625752459008] (32)Broken pipe: [client (client IP):22348] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:29.002429 2016] [proxy_fcgi:error] [pid 30073:tid 139625718888192] (32)Broken pipe: [client (client IP):22357] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:30.182881 2016] [proxy_fcgi:error] [pid 30073:tid 139625486018304] (32)Broken pipe: [client (client IP):22359] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:31.164754 2016] [proxy_fcgi:error] [pid 30073:tid 139625225844480] (32)Broken pipe: [client (client IP):22361] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:34.523333 2016] [proxy_fcgi:error] [pid 30050:tid 139625251022592] (32)Broken pipe: [client (client IP):22368] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:36.076287 2016] [proxy_fcgi:error] [pid 30073:tid 139625578338048] (32)Broken pipe: [client (client IP):22370] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:37.088040 2016] [proxy_fcgi:error] [pid 30073:tid 139625477625600] (32)Broken pipe: [client (client IP):22371] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL) [Fri Jan 15 14:00:38.288891 2016] [proxy_fcgi:error] [pid 30073:tid 139625175488256] (32)Broken pipe: [client (client IP):22372] AH01075: Error dispatching request to : (passing brigade to output filters), referer: (website URL)
committed with minor changes -- removed msgid and some style changes. Will propose for 2.4.x.
(In reply to Eric Covener from comment #5) > committed with minor changes -- removed msgid and some style changes. Will > propose for 2.4.x. whoops, and thanks for the report & patch!
Afaik the verbose logging has been fixed, the last occurrence of bogus AH01075 should have been handled in https://bz.apache.org/bugzilla/show_bug.cgi?id=59838 Tobias, please re-open the ticket if I missed something! Luca