You are viewing a plain text version of this content. The canonical link for it is here.
Posted to bugs@httpd.apache.org by bu...@apache.org on 2007/10/12 01:12:07 UTC
DO NOT REPLY [Bug 43607] New: - mod_proxy sends data on closed connections without checking
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG�
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=43607>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND�
INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=43607
Summary: mod_proxy sends data on closed connections without
checking
Product: Apache httpd-2
Version: 2.2.6
Platform: Sun
OS/Version: Solaris
Status: NEW
Severity: normal
Priority: P2
Component: mod_proxy
AssignedTo: bugs@httpd.apache.org
ReportedBy: matt@warnertechnology.com
If an HTTP request is split into two packets and, due to network congestion (or
anything else), the second packet arrives significantly later than the first (5
or more seconds), we have a situation where Apache tries to send data down a
closed connection. This happens because Apache first parses the HTTP header,
then opens a connection to the backend server (without sending any data), then
parses the HTTP body, and then tries to send everything at once to the backend
server.
When the delay between HTTP header and HTTP body exceeds the timeout of the
backend server (5 seconds in my case), the backend server closes the connection.
When Apache sends the data to the backend server, it gets a reset from the app
server, which results in a 502 error being sent back to the web browser.
Per the truss output, below, you can see that the header is processed, the
connection is opened, and then the body is parsed. After that, the data is sent
to the backend server (unsuccessfully).
Either mod_proxy should wait to open the connection to the backend server until
after it's processed the body, or Apache should at least check the state of the
connection before sending data. Or maybe if it gets a reset, it tries again.
** NOTE INCOMING POST FROM CLIEN
2030/24: 0.0006 read(61, " P O S T /<OMITTED>".., 8000) = 128
2030/24: 0.0006 pollsys(0xFFFFFFFF6B7FB6A8, 1, 0xFFFFFFFF6B7FB5E0, 0x00000000) = 1
2030/24: fd=61 ev=POLLIN rev=POLLIN
2030/24: timeout: 300.000000000 sec
2030/24: 0.0005 read(61, " H o s t : <OMITTED>".., 8000) = 177
2030/24: 0.6335 pollsys(0xFFFFFFFF6B7FB6A8, 1, 0xFFFFFFFF6B7FB5E0, 0x00000000) = 1
2030/24: fd=61 ev=POLLIN rev=POLLIN
2030/24: timeout: 300.000000000 sec
2030/24: 0.0005 read(61, "\r\n", 8000) = 2
2030/24: 0.0117 open("/dev/udp", O_RDONLY) = 62
2030/24: 0.0005 ioctl(62, SIOCGLIFNUM, 0xFFFFFFFF6B7FB174) = 0
2030/24: 0.0003 close(62) = 0
2030/24: 0.0007 open("/etc/default/nss", O_RDONLY|O_LARGEFILE) = 62
2030/24: 0.0004 fcntl(62, F_DUPFD, 0x00000100) = 256
2030/24: 0.0002 close(62) = 0
2030/24: 0.0002 read(256, " # i d e n t\t " @ ( #".., 1024) = 1024
2030/24: 0.0002 read(256, " y t h o s e\n # f u n".., 1024) = 211
2030/24: 0.0004 read(256, 0x10071B5C4, 1024) = 0
2030/24: 0.0002 close(256) = 0
2030/24: 0.0004 so_socket(PF_INET, SOCK_STREAM, IPPROTO_TCP, "", SOV_DEFAULT) = 62
2030/24: 0.0003 setsockopt(62, tcp, TCP_NODELAY, 0xFFFFFFFF6B7FB66C, 4,
SOV_DEFAULT) = 0
** NOW APACHE OPENS A CONNECTION TO THE BACKEND SERVER
2030/24: 0.0003 fcntl(62, F_GETFL) = 2
2030/24: 0.0001 fcntl(62, F_SETFL, FWRITE|FNONBLOCK) = 0
2030/24: 0.0005 connect(62, 0x100310CA8, 16, SOV_DEFAULT) Err#150 EINPROGRESS
2030/24: AF_INET name = 10.10.5.10 port = 7929
2030/24: 0.0067 pollsys(0xFFFFFFFF6B7FB5A8, 1, 0xFFFFFFFF6B7FB4E0, 0x00000000) = 1
2030/24: fd=62 ev=POLLOUT rev=POLLOUT
2030/24: timeout: 300.000000000 sec
2030/24: 0.0003 getsockopt(62, SOL_SOCKET, SO_ERROR, 0xFFFFFFFF6B7FB668,
0xFFFFFFFF6B7FB66C, SOV_DEFAULT) = 0
2030/24: 0.0004 getsockname(62, 0x100310E48, 0x100310E28, SOV_DEFAULT) = 0
2030/24: AF_INET name = 10.10.4.10 port = 44706
2030/24: pollsys(0xFFFFFFFF6B7FB338, 1, 0xFFFFFFFF6B7FB270, 0x00000000)
(sleeping...)
2030/24: fd=61 ev=POLLIN rev=0xFFFFB49C
2030/24: timeout: 300.000000000 sec
** NOTE THE DELAY IN RECEIVING THE BODY: 14.49 SECONDS
2030/24: 14.4911 pollsys(0xFFFFFFFF6B7FB338, 1, 0xFFFFFFFF6B7FB270, 0x00000000) = 1
2030/24: fd=61 ev=POLLIN rev=POLLIN
2030/24: timeout: 300.000000000 sec
** HERE'S THE BODY
2030/24: 0.0005 read(61, " j _ u s e r n a m e = ".., 8000) = 52
2030/24: 0.0009 writev(62, 0xFFFFFFFF6B7FB650, 14) = 480
** HERE'S WHERE APACHE TRIES TO WRITE TO THE BACKEND CONNECTION WHICH
** HAS ALREADY EXPIRED AND CLOSED
2030/24: iov_base = 0x1006FA5C0 iov_len = 38
2030/24: P O S T /<SOME PATH. DELETED FOR THIS EXAMPLE>
** THE BACKEND SERVER SENDS US A RESET
2030/24: 0.0009 read(62, 0x10071B0C8, 8000) Err#131 ECONNRESET
** A PROXY ERROR IS THROWN BACK TO THE WEB BROWSER/CLIENT
2030/24: 0.0007 write(28, 0xFFFFFFFF6B7F7680, 203) = 203
2030/24: [ T h u O c t 1 1 1 4 : 3 3 : 0 3 2 0 0 7 ] [ e r r o
2030/24: r ] [ c l i e n t 1 0 . 1 0 . 4 . 1 0 ] ( 1 3 1 ) C o n n
2030/24: e c t i o n r e s e t b y p e e r : p r o x y : e r r
2030/24: o r r e a d i n g s t a t u s l i n e f r o m r e m o
2030/24: t e s e r v e r XX , r e f e r e r : SOMEURL\n
2030/24: 0.0006 write(28, 0xFFFFFFFF6B7F75A0, 184) = 184
2030/24: [ T h u O c t 1 1 1 4 : 3 3 : 0 3 2 0 0 7 ] [ e r r o
2030/24: r ] [ c l i e n t 1 0 . 1 0 . 4 . 1 0 ] p r o x y : E r
2030/24: r o r r e a d i n g f r o m r e m o t e s e r v e r r
2030/24: e t u r n e d b y A_URL, r e f e r e r : SOME_URL\n
2030/24: 0.0004 close(62) = 0
2030/24: 0.0006 brk(0x10071FD60) = 0
2030/24: 0.0002 brk(0x100723D60) = 0
2030/24: 0.0006 writev(61, 0xFFFFFFFF6B7FB930, 2) = 576
2030/24: iov_base = 0x10071D0D8 iov_len = 154
2030/24: H T T P / 1 . 1 5 0 2 P r o x y E r r o r\r\n D a t e :
2030/24: T h u , 1 1 O c t 2 0 0 7 2 1 : 3 2 : 4 7 G M T\r\n V
2030/24: a r y : A c c e p t - E n c o d i n g\r\n C o n t e n t - L e
2030/24: n g t h : 4 2 2\r\n C o n t e n t - T y p e : t e x t / h t
2030/24: m l ; c h a r s e t = i s o - 8 8 5 9 - 1\r\n\r\n
2030/24: iov_base = 0x10071B0C8 iov_len = 422
2030/24: < ! D O C T Y P E H T M L P U B L I C " - / / I E T F / /
2030/24: D T D H T M L 2 . 0 / / E N " >\n < h t m l > < h e a d >\n
2030/24: < t i t l e > 5 0 2 P r o x y E r r o r < / t i t l e >\n <
2030/24: / h e a d > < b o d y >\n < h 1 > P r o x y E r r o r < / h 1
2030/24: >\n < p > T h e p r o x y s e r v e r r e c e i v e d a
2030/24: n i n v a l i d\r\n r e s p o n s e f r o m a n u p s t
2030/24: r e a m s e r v e r . < b r / >\r\n T h e p r o x y s e
2030/24: r v e r c o u l d n o t h a n d l e t h e r e q u e s
2030/24: t < e m > < a h r e f = "A_URL" > P O S T & n b s p ; URL< / a >
< / e m > . < p >\n R e a s o n : < s t
2030/24: r o n g > E r r o r r e a d i n g f r o m r e m o t e s
2030/24: e r v e r < / s t r o n g > < / p > < / p >\n < / b o d y > < /
2030/24: h t m l >\n
--
Configure bugmail: http://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
DO NOT REPLY [Bug 43607] - mod_proxy sends data on closed connections without checking
Posted by bu...@apache.org.
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG�
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=43607>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND�
INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=43607
nick@webthing.com changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEEDINFO |NEW
------- Additional Comments From nick@webthing.com 2008-02-21 15:12 -------
OK, reverting to NEW, to maximise the chances of it getting attention from
anyone (including you or me) who might take an interest.
--
Configure bugmail: http://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
DO NOT REPLY [Bug 43607] - mod_proxy sends data on closed connections without checking
Posted by bu...@apache.org.
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG�
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=43607>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND�
INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=43607
nick@webthing.com changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |NEEDINFO
------- Additional Comments From nick@webthing.com 2008-02-19 14:29 -------
marking NEEDINFO pending feedback
--
Configure bugmail: http://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
DO NOT REPLY [Bug 43607] - mod_proxy sends data on closed connections without checking
Posted by bu...@apache.org.
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG�
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=43607>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND�
INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=43607
------- Additional Comments From matt@warnertechnology.com 2008-02-21 14:11 -------
This was occurring in a production environment, so testing the patch will be a
problem. I will have to try to create a test environment and then duplicate the
packet loss/retransmission scenario that first brought this to our attention.
That may not happen for a while.
--
Configure bugmail: http://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
DO NOT REPLY [Bug 43607] - mod_proxy sends data on closed connections without checking
Posted by bu...@apache.org.
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG�
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=43607>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND�
INSERTED IN THE BUG DATABASE.
http://issues.apache.org/bugzilla/show_bug.cgi?id=43607
------- Additional Comments From nick@webthing.com 2008-02-19 14:28 -------
Created an attachment (id=21565)
--> (http://issues.apache.org/bugzilla/attachment.cgi?id=21565&action=view)
quick&dirty hack to try patching it
Can you test-drive the attached patch (against 2.2.8) with
SetEnv fix43607 1
in your proxy's scope?
(Don't try this on a server that matters. This patch will want extensive
cleaning if it works, and scrapping if it doesn't)
--
Configure bugmail: http://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org