Zope closes connection if the client closes the write-end of connection
Hi all, Yesterday we tried to get the backend probe feature of varnish to work with zope. It failed, claiming that a response was not received. Checking the Z2 log showed that the request was received but that zero bytes was transferred. Using tcpdump shows that varnish closes the connection before zope can send the response. I eventually distilled the check varnish uses into a small C program, and an interesting problem shows up. When you call shutdown(fd, SHUT_WR) on your socket connection, in effect telling zope that you're done talking to it, it looks like zope responds in kind by not talking to you either. I deduce this from the fact that poll() returns POLLHUP in revents and read() returns zero (EOF). POLLHUP, if I understand this correctly, means the other side (zope) has hung up. This effectively makes it impossible to use certain kinds of monitoring software with zope, specifically varnish. I would appreciate it if someone in the know could look at the code, tell me what I (and by extension varnish) am doing wrong, or whether this is perhaps a bug in zope (which I strongly suspect). The attached C code works fine against apache, and it also works fine against zope if you remove the shutdown() call. regards, Izak --- snip: poll.c --- #define URL "/" #include <sys/socket.h> #include <sys/types.h> #include <netinet/in.h> #include <arpa/inet.h> #include <poll.h> #include <stdio.h> #include <errno.h> #include <string.h> #include <stdlib.h> int main(int argc, char **argv){ struct pollfd fds[1]; int timeout_msecs = 5000; int ret; int i, sd, request_size, offset; struct sockaddr_in addr; char buf[1024]; if(argc < 3){ fprintf(stderr, "Usage: %s ip port\n", argv[0]); return 1; } /* Open network connection */ sd = socket(AF_INET, SOCK_STREAM, 0); addr.sin_family = AF_INET; addr.sin_addr.s_addr = inet_addr(argv[1]); addr.sin_port = htons(atoi(argv[2])); if (connect(sd, (struct sockaddr*)&addr, sizeof(addr)) != 0){ perror("connect"); return 1; } /* Send the request */ request_size = snprintf(buf, sizeof(buf), "GET %s HTTP/1.0\r\nConnection: close\r\n\r\n", URL); offset = 0; while(offset < request_size){ i = write(sd, buf+offset, request_size-offset); offset += i; } /* Shutdown the write side */ shutdown(sd, SHUT_WR); /* Now wait for data to come back */ do { fds[0].fd = sd; fds[0].events = POLLIN; fds[0].revents = 0; ret = poll(fds, 1, timeout_msecs); if (ret > 0) { printf("%d POLLIN events on fd %d\n", ret, fds[0].fd); printf("revents = %d\n", fds[0].revents); i = read(sd, buf, sizeof(buf)); printf("Read %d bytes from %d\n", i, sd); } else if (ret == 0){ printf("Timeout\n"); } else { perror("poll"); } } while(i>0); } --- snip ---
Hi again, Izak Burger wrote:
I eventually distilled the check varnish uses into a small C program, and an interesting problem shows up. When you call shutdown(fd, SHUT_WR) on your socket connection, in effect telling zope that you're done talking to it, it looks like zope responds in kind by not talking to you either. I deduce this from the fact that poll() returns POLLHUP in revents and read() returns zero (EOF). POLLHUP, if I understand this correctly, means the other side (zope) has hung up.
It seems this might not be a bug in zope. I'd like to describe what I've found this morning and where this is most possibly going wrong. Please tell me if I'm mistaken about something. This goes all the way to what happens when you call poll() on a file descriptor. If you ask to be notified for POLLIN events only, it does not necessarily guarantee that POLLIN (or a timeout) are the only events that can cause poll() to return. The man page does not properly document this, but the header file does: /* Event types always implicitly polled for. These bits need not be set in `events', but they will appear in `revents' to indicate the status of the file descriptor. */ #define POLLERR 0x008 /* Error condition. */ #define POLLHUP 0x010 /* Hung up. */ #define POLLNVAL 0x020 /* Invalid polling request. */ In other words, a POLLHUP event can cause your poll() call to return even though the POLLIN event you were looking for didn't occur. If we inspect Modules/socketmodule.c in the python (2.4.4) source code we see that it is assumed that if poll() returns a value greater than zero, it means data is available for reading. If the client calls shutdown(SHUT_WR), this will cause a POLLHUP, which fools python into thinking there is data to be read. When it attempts to read that data, it ends up with nothing, that is, recv() returns 0. Moving on to asyncore.py, we see this: data = self.socket.recv(buffer_size) if not data: # a closed connection is indicated by signaling # a read condition, and having recv() return 0. self.handle_close() return '' And handle_close eventually ends up telling zope to close the connection. This has two possible fixes, but both are probably required. Firstly, it seems the latest python still has this problem, so I probably need to report it as a bug. Secondly, since zope still requires older python versions to run, a workaround probably needs to be found. I suppose just rebuilding the _socket native module will probably do it and I will test this as soon as I have more time. regards, Izak
2009/10/16 Izak Burger <izak@upfrontsystems.co.za>:
Secondly, since zope still requires older python versions to run
Zope 2.12 run on Python 2.6. 2.6.4a1 is coming out the weeken, so if this is a Python bug and we want it in 2.6.4 we need to get it in before a b1, which also probably will be quite soon. Some sort of monkey-patch or so would of course be welcome for earlier Zopes too, so we can use this with Plone 3. -- Lennart Regebro: Python, Zope, Plone, Grok http://regebro.wordpress.com/ +33 661 58 14 64
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Izak Burger wrote:
Hi again,
Izak Burger wrote:
I eventually distilled the check varnish uses into a small C program, and an interesting problem shows up. When you call shutdown(fd, SHUT_WR) on your socket connection, in effect telling zope that you're done talking to it, it looks like zope responds in kind by not talking to you either. I deduce this from the fact that poll() returns POLLHUP in revents and read() returns zero (EOF). POLLHUP, if I understand this correctly, means the other side (zope) has hung up.
It seems this might not be a bug in zope. I'd like to describe what I've found this morning and where this is most possibly going wrong. Please tell me if I'm mistaken about something.
This goes all the way to what happens when you call poll() on a file descriptor. If you ask to be notified for POLLIN events only, it does not necessarily guarantee that POLLIN (or a timeout) are the only events that can cause poll() to return. The man page does not properly document this, but the header file does:
/* Event types always implicitly polled for. These bits need not be set in `events', but they will appear in `revents' to indicate the status of the file descriptor. */ #define POLLERR 0x008 /* Error condition. */ #define POLLHUP 0x010 /* Hung up. */ #define POLLNVAL 0x020 /* Invalid polling request. */
In other words, a POLLHUP event can cause your poll() call to return even though the POLLIN event you were looking for didn't occur.
If we inspect Modules/socketmodule.c in the python (2.4.4) source code we see that it is assumed that if poll() returns a value greater than zero, it means data is available for reading.
If the client calls shutdown(SHUT_WR), this will cause a POLLHUP, which fools python into thinking there is data to be read. When it attempts to read that data, it ends up with nothing, that is, recv() returns 0.
Moving on to asyncore.py, we see this:
data = self.socket.recv(buffer_size) if not data: # a closed connection is indicated by signaling # a read condition, and having recv() return 0. self.handle_close() return ''
And handle_close eventually ends up telling zope to close the connection.
This has two possible fixes, but both are probably required. Firstly, it seems the latest python still has this problem, so I probably need to report it as a bug. Secondly, since zope still requires older python versions to run, a workaround probably needs to be found. I suppose just rebuilding the _socket native module will probably do it and I will test this as soon as I have more time.
You might also look at "fixing" varnish: I don't know of any valid reason for it to be using the "half-open" connection model to test that an HTTP-based backend is "up" -- certainly no browser in the world does that; instead, modern browsers nearly always try to keep the connection open for subsequent requests. Tres. - -- ~~ =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iEYEARECAAYFAkrYhPIACgkQ+gerLs4ltQ5PpACg19JYJc7pTUiUMZV8IWnGi5Dv tJMAnikqfgLsi4lZB1eerO01d/48w3SK =5mP5 -----END PGP SIGNATURE-----
On Fri, Oct 16, 2009 at 16:36, Tres Seaver <tseaver@palladion.com> wrote:
[...] You might also look at "fixing" varnish: I don't know of any valid reason for it to be using the "half-open" connection model to test that an HTTP-based backend is "up"
Going out on a limb here, but I think Varnish might be trying to save on file-descriptors. It could be a while before a backend-server answers and Varnish could have a large number of fds open on any given time while talking to both clients and servers.
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Leonardo Rochael Almeida wrote:
On Fri, Oct 16, 2009 at 16:36, Tres Seaver <tseaver@palladion.com> wrote:
[...] You might also look at "fixing" varnish: I don't know of any valid reason for it to be using the "half-open" connection model to test that an HTTP-based backend is "up"
Going out on a limb here, but I think Varnish might be trying to save on file-descriptors. It could be a while before a backend-server answers and Varnish could have a large number of fds open on any given time while talking to both clients and servers.
Hmmm? A TCP socket corrresponds to exactly one open file descriptor, which has to stick around for the response data to come back on. "Half-closing" it is just silly, and is only guaranteed to work where both ends expect to handle this case. Given HTTP's request-response model, it makes very little sense at all for the client to preemptively shutdown writes on the connection. Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iEYEARECAAYFAkrYiqsACgkQ+gerLs4ltQ5dSgCgnqousqxHj8mGUIAZN2P9JTrZ AeMAn01dRMSOYtRm4usudDBN3IZ4m9ii =avfS -----END PGP SIGNATURE-----
2009/10/16 Tres Seaver <tseaver@palladion.com>:
Hmmm? A TCP socket corrresponds to exactly one open file descriptor, which has to stick around for the response data to come back on. "Half-closing" it is just silly, and is only guaranteed to work where both ends expect to handle this case.
Half-closing is the standard way of saying "close when you will", so it's normal TCP-behavior. How many HTTP-servers that handle that I don't know, but I have to agree that it's probably the right thing to do. -- Lennart Regebro: Python, Zope, Plone, Grok http://regebro.wordpress.com/ +33 661 58 14 64
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Lennart Regebro wrote:
2009/10/16 Tres Seaver <tseaver@palladion.com>:
Hmmm? A TCP socket corrresponds to exactly one open file descriptor, which has to stick around for the response data to come back on. "Half-closing" it is just silly, and is only guaranteed to work where both ends expect to handle this case.
Half-closing is the standard way of saying "close when you will", so it's normal TCP-behavior. How many HTTP-servers that handle that I don't know, but I have to agree that it's probably the right thing to do.
Under HTTP, it doesn't make any sense: there isn't any "mixed flow" of information going on at all; everything is request-response driven. Given that varnish has as its primary mission to be an HTTP accelerator, and that the behavior is unexpected (in ten+ years of web programming, I've *never* seen this behavior before), I would say that varnish should make the "half-close" either go away (since it provides no benefit) or at least configurable (since it breaks talking to servers which don't expect the HUP). Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iEYEARECAAYFAkrYlS0ACgkQ+gerLs4ltQ5xAQCgw/Ifz0asq2Df4gAtSZqIQ7Ha zvgAn3qXgL3tT9ynJ48rN438FUWSsONl =5YXq -----END PGP SIGNATURE-----
From the HTTP/1.1 spec:
Servers SHOULD NOT close a connection in the middle of transmitting a response, unless a network or client failure is suspected. But on the other hand: When a client or server wishes to time-out it SHOULD issue a graceful close on the transport connection. Clients and servers SHOULD both constantly watch for the other side of the transport close, and respond to it as appropriate. If a client or server does not detect the other side's close promptly it could cause unnecessary resource drain on the network. So HTTP seems to contradict itself, typically But from looking at other peoples responses, most interpret the specification that the connection should immediately be closed, so the Zope does the right thing there, and Varnish should be changed. This is apparently the generally accepted interpretation. -- Lennart Regebro: Python, Zope, Plone, Grok http://regebro.wordpress.com/ +33 661 58 14 64
2009/10/16 Lennart Regebro <regebro@gmail.com>:
So HTTP seems to contradict itself, typically But from looking at other peoples responses, most interpret the specification that the connection should immediately be closed, so the Zope does the right thing there, and Varnish should be changed. This is apparently the generally accepted interpretation.
Of course, it would make even more sense if Zope the immediately stopped the transaction, but i have no idea how THAT would work... -- Lennart Regebro: Python, Zope, Plone, Grok http://regebro.wordpress.com/ +33 661 58 14 64
On Sat, Oct 17, 2009 at 10:30, Lennart Regebro <regebro@gmail.com> wrote:
2009/10/16 Lennart Regebro <regebro@gmail.com>:
So HTTP seems to contradict itself, typically But from looking at other peoples responses, most interpret the specification that the connection should immediately be closed, so the Zope does the right thing there, and Varnish should be changed. This is apparently the generally accepted interpretation.
Of course, it would make even more sense if Zope the immediately stopped the transaction, but i have no idea how THAT would work...
- sys.maxint I definitively don't want zope to cancel a long running transaction just because my browser got tired of waiting. At the very least this should be configurable, though I can see a lot of value of being able to toggle this cancel-transaction behaviour per-request. But the default should be off (i.e. the transaction keeps going). Cheers, Leo
Hello, - sys.maxint too It might be bad design to have long running transactions, but there are cases you can't avoid that. E.g. evolving a generation on a huge DB. Saturday, October 17, 2009, 10:30:43 AM, you wrote: LR> 2009/10/16 Lennart Regebro <regebro@gmail.com>:
So HTTP seems to contradict itself, typically But from looking at other peoples responses, most interpret the specification that the connection should immediately be closed, so the Zope does the right thing there, and Varnish should be changed. This is apparently the generally accepted interpretation.
LR> Of course, it would make even more sense if Zope the immediately LR> stopped the transaction, but i have no idea how THAT would work... -- Best regards, Adam GROSZER mailto:agroszer@gmail.com -- Quote of the day: Disgust is the appropriate response to most situations
Leonardo Rochael Almeida wrote:
Going out on a limb here, but I think Varnish might be trying to save on file-descriptors.
Interestingly, The Squid FAQ almost seems to imply that closing the write-side can cause more file-descriptors to be used. Squid can apparently not tell the difference between half-closed and full-closed connections, and it makes matter worse. Though I do not know this for sure, some reading on the subject suggests that nginx also doesn't like half-closed connections.
Tres Seaver wrote:
You might also look at "fixing" varnish: I don't know of any valid reason for it to be using the "half-open" connection model to test that an HTTP-based backend is "up" -- certainly no browser in the world does that; instead, modern browsers nearly always try to keep the connection open for subsequent requests.
I have already "fixed" varnish, I commented out the shutdown() call. It now works as expected. I just had a discussion about this with a colleague and it appears unclear exactly where to blame this. When a client half-closes its connection while the server was calling recv(), it makes absolute sense that recv() SHOULD return an empty buffer. There is nothing to return, and there won't ever be, the connection has been closed. Python is therefore not to blame, even if it doesn't specifically check all the possible revents returned by poll(). When asyncore receives an empty result from recv(), it does correctly assume that the connection was shut down. It doesn't seem wrong for asyncore to let the upper layers know about this. It would seem that asyncore is not to blame either. When asyncore calls the close() method inside zope, it ends up shuting down the whole thing. Though I could argue that zope shouldn't be doing this, the idea of a half-open connection doesn't work all that well in python/asyncore anyway, so given the framework within which zope operates, zope isn't to blame either. Given that no browser (that I know of) does this half-closing thing, I would argue that varnish should at the very least offer a shutdown option for probing, so as to appear more like a browser. In addition, HTTP 1.1 usually leaves the connection open unless you ask for it to be closed, so it almost seems more common not to shutdown the one end. It seems then that the only way to "fix" this is to either put zope behind apache or something else that can handle half-closing, or to "fix" varnish. regards, Izak
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Izak Burger wrote:
Tres Seaver wrote:
You might also look at "fixing" varnish: I don't know of any valid reason for it to be using the "half-open" connection model to test that an HTTP-based backend is "up" -- certainly no browser in the world does that; instead, modern browsers nearly always try to keep the connection open for subsequent requests.
I have already "fixed" varnish, I commented out the shutdown() call. It now works as expected.
I just had a discussion about this with a colleague and it appears unclear exactly where to blame this.
When a client half-closes its connection while the server was calling recv(), it makes absolute sense that recv() SHOULD return an empty buffer. There is nothing to return, and there won't ever be, the connection has been closed. Python is therefore not to blame, even if it doesn't specifically check all the possible revents returned by poll().
When asyncore receives an empty result from recv(), it does correctly assume that the connection was shut down. It doesn't seem wrong for asyncore to let the upper layers know about this. It would seem that asyncore is not to blame either.
When asyncore calls the close() method inside zope, it ends up shuting down the whole thing. Though I could argue that zope shouldn't be doing this, the idea of a half-open connection doesn't work all that well in python/asyncore anyway, so given the framework within which zope operates, zope isn't to blame either.
Given that no browser (that I know of) does this half-closing thing, I would argue that varnish should at the very least offer a shutdown option for probing, so as to appear more like a browser.
In addition, HTTP 1.1 usually leaves the connection open unless you ask for it to be closed, so it almost seems more common not to shutdown the one end.
It seems then that the only way to "fix" this is to either put zope behind apache or something else that can handle half-closing, or to "fix" varnish.
Spot on -- good analysis of the problem. Tres. - -- =================================================================== Tres Seaver +1 540-429-0999 tseaver@palladion.com Palladion Software "Excellence by Design" http://palladion.com -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iEYEARECAAYFAkrYoMoACgkQ+gerLs4ltQ7X/QCfYFSSp1MOVuTryLynCvS3Khs9 AuMAn0bxsQ6zYdl82V4Ye5iFuFptL5tQ =ka8O -----END PGP SIGNATURE-----
participants (5)
-
Adam GROSZER -
Izak Burger -
Lennart Regebro -
Leonardo Rochael Almeida -
Tres Seaver