httpd-bugs mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From bugzi...@apache.org
Subject DO NOT REPLY [Bug 43607] New: - mod_proxy sends data on closed connections without checking
Date Thu, 11 Oct 2007 23:12:07 GMT
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


Mime
View raw message