very bad network performance
Hi all, I'm using mercurial with the release25-maint branch. I noticed that checking out a local repository now takes more than 5 minutes (it should be around 30s). I've tracked it down to this change: http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd this is svn revision 61009. Here is the diff inline: --- a/Lib/socket.py Fri Mar 23 14:27:29 2007 +0100 +++ b/Lib/socket.py Sat Feb 23 20:30:59 2008 +0100 @@ -305,7 +305,7 @@ self._rbuf = "" while True: left = size - buf_len - recv_size = max(self._rbufsize, left) + recv_size = min(self._rbufsize, left) data = self._sock.recv(recv_size) if not data: break self._rbufsize if 1, and so the code reads one byte at a time. this is clearly wrong, I'm posting it to the mailing list, as I don't want this issue to get lost in the bugtracker. - Ralf
"Ralf Schmitt" <schmir@gmail.com> wrote in message news:932f8baf0804140912u54adc7d5md7261541857f21bd@mail.gmail.com... | Hi all, | | I'm using mercurial with the release25-maint branch. I noticed that checking | out a local repository now takes more than | 5 minutes (it should be around 30s). | | I've tracked it down to this change: | http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd | this is svn revision 61009. Here is the diff inline: | | --- a/Lib/socket.py Fri Mar 23 14:27:29 2007 +0100 | +++ b/Lib/socket.py Sat Feb 23 20:30:59 2008 +0100 | @@ -305,7 +305,7 @@ | self._rbuf = "" | while True: | left = size - buf_len | - recv_size = max(self._rbufsize, left) | + recv_size = min(self._rbufsize, left) | data = self._sock.recv(recv_size) | if not data: | break | | | | self._rbufsize if 1, and so the code reads one byte at a time. this is | clearly wrong, I'm posting it to the mailing list, as I don't want | this issue to get lost in the bugtracker. -------------------------------------------------------------------------------- It is at least as likely to get lost here. There is a mailing list for new tracker items that many devs subscribe to.
Ralf, Terry is right. Please file a bug. I do think there may be a problem with that change but I don't have the time to review it in depth. Hopefully others will. I do recall that sockets reading one byte at a time has been a problem before -- I recall a bug about this in the 1.5.2 era for Windows... Too bad it's back. :-( --Guido On Mon, Apr 14, 2008 at 10:25 AM, Terry Reedy <tjreedy@udel.edu> wrote:
"Ralf Schmitt" <schmir@gmail.com> wrote in message news:932f8baf0804140912u54adc7d5md7261541857f21bd@mail.gmail.com...
| Hi all, | | I'm using mercurial with the release25-maint branch. I noticed that checking | out a local repository now takes more than | 5 minutes (it should be around 30s). | | I've tracked it down to this change: | http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd | this is svn revision 61009. Here is the diff inline: | | --- a/Lib/socket.py Fri Mar 23 14:27:29 2007 +0100 | +++ b/Lib/socket.py Sat Feb 23 20:30:59 2008 +0100 | @@ -305,7 +305,7 @@ | self._rbuf = "" | while True: | left = size - buf_len | - recv_size = max(self._rbufsize, left) | + recv_size = min(self._rbufsize, left) | data = self._sock.recv(recv_size) | if not data: | break | | | | self._rbufsize if 1, and so the code reads one byte at a time. this is | clearly wrong, I'm posting it to the mailing list, as I don't want | this issue to get lost in the bugtracker.
--------------------------------------------------------------------------------
It is at least as likely to get lost here. There is a mailing list for new tracker items that many devs subscribe to.
_______________________________________________ Python-Dev mailing list Python-Dev@python.org http://mail.python.org/mailman/listinfo/python-dev Unsubscribe: http://mail.python.org/mailman/options/python-dev/guido%40python.org
-- --Guido van Rossum (home page: http://www.python.org/~guido/)
There's some really convoluted code in socket._fileobject.__init__() here. When initializing a _fileobject, if the 'bufsize' parameter is explicitly given as zero, that's turned into an _rbufsize of 1, which, combined with the 'min' change, will produce the read-one-byte behavior. The code for setting _rbufsize seems odd; be nice if it was commented with some notes on why these specific selections were made. if bufsize < 0: bufsize = self.default_bufsize if bufsize == 0: self._rbufsize = 1 elif bufsize == 1: self._rbufsize = self.default_bufsize else: self._rbufsize = bufsize self._wbufsize = bufsize It also depends on whether 'read' is called with an explicit # of bytes to read (which appears to be the case here). So, it's not the code in socket.py, necessarily; it's the code which opens the socket, most likely. The only library which seems to use a bufsize of zero is httplib (which has a lot of other problems as well). I think the change cited below (while IMO correct) will affect a number of other HTTP-based services, as well. Bill
Ralf,
Terry is right. Please file a bug. I do think there may be a problem with that change but I don't have the time to review it in depth. Hopefully others will. I do recall that sockets reading one byte at a time has been a problem before -- I recall a bug about this in the 1.5.2 era for Windows... Too bad it's back. :-(
--Guido
On Mon, Apr 14, 2008 at 10:25 AM, Terry Reedy <tjreedy@udel.edu> wrote:
"Ralf Schmitt" <schmir@gmail.com> wrote in message news:932f8baf0804140912u54adc7d5md7261541857f21bd@mail.gmail.com...
| Hi all, | | I'm using mercurial with the release25-maint branch. I noticed that checking | out a local repository now takes more than | 5 minutes (it should be around 30s). | | I've tracked it down to this change: | http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd | this is svn revision 61009. Here is the diff inline: | | --- a/Lib/socket.py Fri Mar 23 14:27:29 2007 +0100 | +++ b/Lib/socket.py Sat Feb 23 20:30:59 2008 +0100 | @@ -305,7 +305,7 @@ | self._rbuf = "" | while True: | left = size - buf_len | - recv_size = max(self._rbufsize, left) | + recv_size = min(self._rbufsize, left) | data = self._sock.recv(recv_size) | if not data: | break | | | | self._rbufsize if 1, and so the code reads one byte at a time. this is | clearly wrong, I'm posting it to the mailing list, as I don't want | this issue to get lost in the bugtracker.
--------------------------------------------------------------------------------
It is at least as likely to get lost here. There is a mailing list for new tracker items that many devs subscribe to.
On Mon, Apr 14, 2008 at 9:12 AM, Ralf Schmitt <schmir@gmail.com> wrote:
I've tracked it down to this change: http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd this is svn revision 61009. [...] self._rbufsize if 1, and so the code reads one byte at a time
The change is correct, but exposes a flaw earlier in the same method. "_rbufsize == 1" represents a request to buffer "by line", which is clearly irrelevant in this context. A request to read n bytes should just use the default buffer size if buffering "by line". Sample patch is attached. -- Curt Hagenlocher curt@hagenlocher.org
Eek! Please use the bug tracker. On Mon, Apr 14, 2008 at 11:10 AM, Curt Hagenlocher <curt@hagenlocher.org> wrote:
On Mon, Apr 14, 2008 at 9:12 AM, Ralf Schmitt <schmir@gmail.com> wrote:
I've tracked it down to this change: http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd this is svn revision 61009. [...]
self._rbufsize if 1, and so the code reads one byte at a time
The change is correct, but exposes a flaw earlier in the same method. "_rbufsize == 1" represents a request to buffer "by line", which is clearly irrelevant in this context. A request to read n bytes should just use the default buffer size if buffering "by line". Sample patch is attached.
-- Curt Hagenlocher curt@hagenlocher.org
_______________________________________________ Python-Dev mailing list Python-Dev@python.org http://mail.python.org/mailman/listinfo/python-dev Unsubscribe: http://mail.python.org/mailman/options/python-dev/guido%40python.org
-- --Guido van Rossum (home page: http://www.python.org/~guido/)
On Mon, Apr 14, 2008 at 8:22 PM, Guido van Rossum <guido@python.org> wrote:
Eek! Please use the bug tracker.
I 've made some comments on: http://bugs.python.org/issue1092502 (which is the original issue). However I cannot reopen this issue. Regards, - Ralf
On Mon, Apr 14, 2008 at 11:18 PM, Ralf Schmitt <schmir@gmail.com> wrote:
On Mon, Apr 14, 2008 at 8:22 PM, Guido van Rossum <guido@python.org> wrote:
Eek! Please use the bug tracker.
I 've made some comments on: http://bugs.python.org/issue1092502 (which is the original issue). However I cannot reopen this issue.
Curt opened another bug for it: http://bugs.python.org/issue2632 someone should change the priority.
On Mon, Apr 14, 2008 at 11:10:12AM -0700, Curt Hagenlocher wrote:
while True: left = size - buf_len ! recv_size = max(self._rbufsize, left) data = self._sock.recv(recv_size)
What version is this patch against? (The last 2.5 release, maybe?) The max() in the above line should be min(), because you want to use the *smaller* number of the buffer size and the # of remaining bytes to read, not the *larger*. This code is using min() in both 25-maint and trunk. --amk
On Mon, Apr 14, 2008 at 12:17 PM, A.M. Kuchling <amk@amk.ca> wrote:
On Mon, Apr 14, 2008 at 11:10:12AM -0700, Curt Hagenlocher wrote:
while True: left = size - buf_len ! recv_size = max(self._rbufsize, left) data = self._sock.recv(recv_size)
What version is this patch against? (The last 2.5 release, maybe?)
Yes, sorry. I thought I had checked this against the repository -- particularly because the max->min change is what kicked off this thread. -- Curt Hagenlocher curt@hagenlocher.org
On Mon, Apr 14, 2008 at 8:10 PM, Curt Hagenlocher <curt@hagenlocher.org> wrote:
On Mon, Apr 14, 2008 at 9:12 AM, Ralf Schmitt <schmir@gmail.com> wrote:
I've tracked it down to this change: http://hgpy.de/py/release25-maint/rev/e9446c6ab3cd this is svn revision 61009. [...] self._rbufsize if 1, and so the code reads one byte at a time
The change is correct, but exposes a flaw earlier in the same method. "_rbufsize == 1" represents a request to buffer "by line", which is clearly irrelevant in this context. A request to read n bytes should just use the default buffer size if buffering "by line". Sample patch is attached.
Sorry to reply on the mailing list. But this change is wrong. e.g. if you're using a buffer size of 16 bytes and try to read 256 bytes, it should call recv with a value of 256 and not call recv 16 times with a value of 16. However, there should be an upper limit (as shown by the imap bug). Regards, - Ralf
On Mon, Apr 14, 2008 at 2:29 PM, Ralf Schmitt <schmir@gmail.com> wrote:
Sorry to reply on the mailing list. But this change is wrong. e.g. if you're using a buffer size of 16 bytes and try to read 256 bytes, it should call recv with a value of 256 and not call recv 16 times with a value of 16. However, there should be an upper limit (as shown by the imap bug).
There is an upper limit. It's called "the buffer size". If someone specifies a buffer size of 16 bytes, it means "read 16 bytes at a time". I don't know why someone would want such a small buffer size, but presumably they have their reasons. The only reason "min" is a problem is that there's standard library code passing a zero to socket.makefile, which gets turned into a bufsize of 1 by the constructor. I actually agree with Bill Janssen -- __init__ is where the real problem lies. But I think the change to read() is safer. -- Curt Hagenlocher curt@hagenlocher.org
On Tue, Apr 15, 2008 at 12:19 AM, Curt Hagenlocher <curt@hagenlocher.org> wrote:
On Mon, Apr 14, 2008 at 2:29 PM, Ralf Schmitt <schmir@gmail.com> wrote:
Sorry to reply on the mailing list. But this change is wrong. e.g. if you're using a buffer size of 16 bytes and try to read 256
bytes, it
should call recv with a value of 256 and not call recv 16 times with a value of 16. However, there should be an upper limit (as shown by the imap bug).
There is an upper limit. It's called "the buffer size". If someone specifies a buffer size of 16 bytes, it means "read 16 bytes at a time". I don't know why someone would want such a small buffer size, but presumably they have their reasons.
No, I don't agree. To me buffer size means buffer up to buffer_size bytes in memory. It does not mean that it should read only buffer_size bytes at once when asked to read more bytes than buffer size. The upper limit I was talking about is the buffer size limit of the operating system, i.e. the operating system will at a maximum return N bytes from recv call. It doesn't make sense to ask for more then, and the original problem with imaplip asking for 10MB of data and then realloc'ing that buffer would be gone.
The only reason "min" is a problem is that there's standard library code passing a zero to socket.makefile, which gets turned into a bufsize of 1 by the constructor. I actually agree with Bill Janssen -- __init__ is where the real problem lies. But I think the change to read() is safer.
again no, if I pass in 4 as buffer size, I don't expect the system to make 1024 calls to recv when I want to read 4096 bytes. Regards, - Ralf
On Mon, Apr 14, 2008 at 3:57 PM, Ralf Schmitt <schmir@gmail.com> wrote:
On Tue, Apr 15, 2008 at 12:19 AM, Curt Hagenlocher <curt@hagenlocher.org> wrote:
On Mon, Apr 14, 2008 at 2:29 PM, Ralf Schmitt <schmir@gmail.com> wrote:
Sorry to reply on the mailing list. But this change is wrong. e.g. if you're using a buffer size of 16 bytes and try to read 256
bytes, it
should call recv with a value of 256 and not call recv 16 times with a value of 16. However, there should be an upper limit (as shown by the imap bug).
There is an upper limit. It's called "the buffer size". If someone specifies a buffer size of 16 bytes, it means "read 16 bytes at a time". I don't know why someone would want such a small buffer size, but presumably they have their reasons.
No, I don't agree. To me buffer size means buffer up to buffer_size bytes in memory. It does not mean that it should read only buffer_size bytes at once when asked to read more bytes than buffer size.
The upper limit I was talking about is the buffer size limit of the operating system, i.e. the operating system will at a maximum return N bytes from recv call. It doesn't make sense to ask for more then, and the original problem with imaplip asking for 10MB of data and then realloc'ing that buffer would be gone.
The only reason "min" is a problem is that there's standard library code passing a zero to socket.makefile, which gets turned into a bufsize of 1 by the constructor. I actually agree with Bill Janssen -- __init__ is where the real problem lies. But I think the change to read() is safer.
again no, if I pass in 4 as buffer size, I don't expect the system to make 1024 calls to recv when I want to read 4096 bytes.
But why was imaplib apparently specifying 10MB? Did it know there was that much data? Or did it just not want to bother looping over all the data in smaller buffer increments (e.g. 64K, which is probably the max of what most TCP stacks will give you)? If I'm right with my hunch that the TCP stack will probably clamp at 64K, perhaps we should use min(system limit, max(requested size, buffer size))? -- --Guido van Rossum (home page: http://www.python.org/~guido/)
On Tue, Apr 15, 2008 at 1:19 AM, Guido van Rossum <guido@python.org> wrote:
But why was imaplib apparently specifying 10MB? Did it know there was that much data? Or did it just not want to bother looping over all the data in smaller buffer increments (e.g. 64K, which is probably the max of what most TCP stacks will give you)?
Well, calling read with a size of 10MB should be possible. The problem is that this value ended up inside the recv call, which then did the malloc/realloc calls.
If I'm right with my hunch that the TCP stack will probably clamp at 64K, perhaps we should use min(system limit, max(requested size, buffer size))?
yes, this is what I was trying to explain.
-- --Guido van Rossum (home page: http://www.python.org/~guido/<http://www.python.org/%7Eguido/> )
On Mon, Apr 14, 2008 at 4:19 PM, Guido van Rossum <guido@python.org> wrote:
But why was imaplib apparently specifying 10MB? Did it know there was that much data? Or did it just not want to bother looping over all the data in smaller buffer increments (e.g. 64K, which is probably the max of what most TCP stacks will give you)?
I'm going to guess that the code in question is size = int(self.mo.group('size')) if __debug__: if self.debug >= 4: self._mesg('read literal size %s' % size) data = self.read(size) It's reading however many bytes are reported by the server as the size.
If I'm right with my hunch that the TCP stack will probably clamp at 64K, perhaps we should use min(system limit, max(requested size, buffer size))?
I have indeed missed the point of the read buffer size. This would work. -- Curt Hagenlocher curt@hagenlocher.org
On Mon, Apr 14, 2008 at 4:41 PM, Curt Hagenlocher <curt@hagenlocher.org> wrote:
On Mon, Apr 14, 2008 at 4:19 PM, Guido van Rossum <guido@python.org> wrote:
But why was imaplib apparently specifying 10MB? Did it know there was that much data? Or did it just not want to bother looping over all the data in smaller buffer increments (e.g. 64K, which is probably the max of what most TCP stacks will give you)?
I'm going to guess that the code in question is
size = int(self.mo.group('size')) if __debug__: if self.debug >= 4: self._mesg('read literal size %s' % size) data = self.read(size)
It's reading however many bytes are reported by the server as the size.
If I'm right with my hunch that the TCP stack will probably clamp at 64K, perhaps we should use min(system limit, max(requested size, buffer size))?
I have indeed missed the point of the read buffer size. This would work.
The 64K hunch is wrong. The system limit can be found using getsockopt(...SO_RCVBUF...). It can easily be (and often is) set to many megabytes either at a system default level or on a per socket level by the user using setsockopt. When the system default is that large, limiting by the system limit would not help the 10mb read case. Even smaller allocations like 64K cause problems as mentioned in issue 1092502 linking to this twisted http://twistedmatrix.com/trac/ticket/1079bug. twisted's solution was to make the string object returned by a recv as short lived as possible by copying it into a StringIO. We could do the same in _fileobject.read() and readline(). I have attached a patch to issue 2632 that changes socket to use StringIO for its read buffer and keeps the lifetime of strings returned by recv() as short as possible when appropriate. It also refuses to call recv() with a size smaller than default_bufsize within read() [the source of the performance problem]. That changes internal recv() call behavior over the existing code after the issue 1092502 "fix" was applied to use min() rather than max(), but it is -not- a significant change over the pre-1092502 "fix" behavior that exists in all released versions of python (it already chose the larger of two values for recv sizes). The main difference behind the scenes? StringIO is using realloc only to increase its size while recv() was using realloc to shrink the allocation size and many of these recv()ed shrunken strings were being held onto in a list before the final value was constructed. I suggest continuing the discussion within issue 2632 to keep better track of it. My socket-strio patch in 2632 needs more testing (it passed socket, http* and url* tests) and verification that both issue's problems are indeed gone but they should be. -gps
On Mon, Apr 21, 2008 at 8:10 PM, Gregory P. Smith <greg@krypto.org> wrote:
The 64K hunch is wrong. The system limit can be found using getsockopt(...SO_RCVBUF...). It can easily be (and often is) set to many megabytes either at a system default level or on a per socket level by the user using setsockopt. When the system default is that large, limiting by the system limit would not help the 10mb read case.
but it would help in the 100mb read case.
Even smaller allocations like 64K cause problems as mentioned in issue 1092502 linking to this twisted http://twistedmatrix.com/trac/ticket/1079bug. twisted's solution was to make the string object returned by a recv as short lived as possible by copying it into a StringIO. We could do the same in _fileobject.read() and readline().
this approach look reasonable to me. - Ralf
participants (7)
-
A.M. Kuchling
-
Bill Janssen
-
Curt Hagenlocher
-
Gregory P. Smith
-
Guido van Rossum
-
Ralf Schmitt
-
Terry Reedy