classification
Title: asynchat push always sends 512 bytes (ignoring ac_out_buffer_size)
Type: behavior Stage:
Components: Library (Lib) Versions: Python 2.5
process
Status: closed Resolution: out of date
Dependencies: Superseder:
Assigned To: Nosy List: akuchling, giampaolo.rodola, intgr, josiahcarlson, klimkin, mkc
Priority: normal Keywords:

Created on 2008-02-11 22:17 by mkc, last changed 2009-03-31 21:56 by josiahcarlson. This issue is now closed.

Messages (12)
msg62294 - (view) Author: Mike Coleman (mkc) Date: 2008-02-11 22:17
In asynchat, 'push' doesn't specify 'buffer_size', so the default of 512
is used.  This is bogus and causes poor performance--it should use the
value of 'ac_out_buffer_size' instead.
msg62360 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2008-02-13 14:46
ac_out_buffer_size value is already used when sending data.
Look at initiate_send method:

    def initiate_send (self):
        obs = self.ac_out_buffer_size
        ...
        if self.ac_out_buffer and self.connected:
            try:
                num_sent = self.send (self.ac_out_buffer[:obs])
        ...
msg62364 - (view) Author: Mike Coleman (mkc) Date: 2008-02-13 15:59
The value is used there, but this is not effective in causing larger
packets to be sent, which I noticed by watching with strace.  I think
the reason for this is that 'refill_buffer' will only make at most one
call to simple_producer.more, and that call will produce at most 512
bytes, because that's the default value of that argument, and its not
overridden in the call that creates the simple_producer inside of 'push'.

In addition, I see at least one other place in the code where the
constant '512' appears.  Probably all of these should be changed to use
the 'ac_*' values, or at least a larger constant.

Looking at the big picture, though, I don't understand why we're trying
to break this stuff up in the first place.  That seems like the job of
the OS, and it may well do it faster and better anyway.  I would think
that every call to socket 'send' should try to ram as much data through
as possible.  The return value will let us know what actually happened.

(In my application, send's of size >200K are regularly succeeding, as
seen with strace.  I got this behavior by overriding 'push' with a fixed
version.)
msg62365 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2008-02-13 16:45
> The value is used there, but this is not effective in causing larger
> packets to be sent, which I noticed by watching with strace.  I think
> the reason for this is that 'refill_buffer' will only make at most one
> call to simple_producer.more, and that call will produce at most 512
> bytes, because that's the default value of that argument, and its not
> overridden in the call that creates the simple_producer inside of 
> 'push'.

Sorry, you're right. 
I remember now that I reported a similar thing in bug #1736190:
http://bugs.python.org/msg57581

> In addition, I see at least one other place in the code where the
> constant '512' appears.

Where? Aside from simple_producer.__init__ I don't see other places
where it is used.
msg62366 - (view) Author: Mike Coleman (mkc) Date: 2008-02-13 17:35
The other place I see the constant is in asyncore.py:

class dispatcher_with_send(dispatcher):

    def __init__(self, sock=None, map=None):
        dispatcher.__init__(self, sock, map)
        self.out_buffer = ''

    def initiate_send(self):
        num_sent = 0
        num_sent = dispatcher.send(self, self.out_buffer[:512])
        self.out_buffer = self.out_buffer[num_sent:]


This code seems to be undocumented and perhaps unused, but until/unless
it's deleted, it probably ought to be fixed.
msg63983 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2008-03-18 20:55
I know nothing about asyncore.  Does this problem still exist in the
trunk (2.6)?
msg63995 - (view) Author: Mike Coleman (mkc) Date: 2008-03-18 21:45
[Tracker bounced this the first time...]

> I haven't run it, but just browsing the trunk source, it appears to
>  still be present.  In fact, asynchat.py and asyncore.py have
>  apparently not been changed in two years.  Andrew Kuchling would seem
>  to be the closest to this code (?), since medusa is apparently dead.
>
>  (More broadly, if these modules are going to stay, they really need to
>  be preened and better documented.  It's not at all obvious, for
>  example, how the handle_error, handle_expt, and handle_close functions
>  all fit together.  Is handle_error supposed to call handle_close, or
>  will the modules make that happen internally?  etc.)
msg64055 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2008-03-19 13:38
As discussed on python-dev patch #1736190 should be committed before
doing anything against asyncore or asynchat.
msg84832 - (view) Author: Josiah Carlson (josiahcarlson) * (Python triager) Date: 2009-03-31 16:41
When push is called in the current trunk (as of 2.6), the data is 
automatically chopped up into self.ac_out_buffer_size blocks for later 
writing.

In order to force the use of the asynchat.simple_producer class (which 
takes an argument for the block size to send), you must pass the 
producer itself with push_with_producer() .

Closing as out of date.
msg84886 - (view) Author: Mike Coleman (mkc) Date: 2009-03-31 20:12
Just to confirm, the real problem here was that tiny packets were being
sent out by default, and the obvious fix (altering ac_out_buffer_size)
didn't work.

Looking at the code, it appears that the change by Josiah Carlson
(#64062) causes ac_out_buffer_size (which currently defaults to 4096) to
be obeyed.

Should that 4096 be larger?  MTU for jumbo packets is ~9000, I think,
plus there's less system call overhead for larger values.  (I use 62000
for my app, but I haven't studied alternatives lately.)

Also, there are still two constants '512' in asyncore/asynchat. 
Shouldn't these be changed to match the 4096 default?
msg84888 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2009-03-31 20:16
In my experience I noticed that 65536 is a pretty good compromise, at
least when moving big amounts of data:
http://code.google.com/p/pyftpdlib/issues/detail?id=94
msg84929 - (view) Author: Josiah Carlson (josiahcarlson) * (Python triager) Date: 2009-03-31 21:56
The spare 512 values are for code that I expect no one is actually 
using.

In terms of increasing the buffer size from 4096 to something larger, 
that can be done, but I think that more than just a 10mbit switched lan 
test should be performed.  I would tend to believe that a larger size 
would tend to perform better, but my concern is sending blocks too large 
to the OS and having it say "sorry, but you need to chop it up more" via 
sock.send() returning 1 or 2 (I've experienced this on Windows with 
stdio and sockets).

Considering how easy it is to adjust, and considering that the value is 
respected everywhere that matters (performance-conscious users aren't 
using simple_producer, nor are they using dispatcher_with_send), I think 
that 4096 is sufficient for the time being.  Adjusting it up to 16k in 
Python 2.8/3.2 seems reasonable to me.  Someone ping me in a year ;) .
History
Date User Action Args
2009-03-31 21:56:53josiahcarlsonsetmessages: + msg84929
2009-03-31 20:16:38giampaolo.rodolasetmessages: + msg84888
2009-03-31 20:12:28mkcsetmessages: + msg84886
2009-03-31 16:41:43josiahcarlsonsetstatus: open -> closed
resolution: out of date
messages: + msg84832
2009-03-28 12:20:31intgrsetnosy: + intgr
2009-01-06 05:06:14gvanrossumsetnosy: - gvanrossum
2009-01-06 05:06:06gvanrossumsetassignee: gvanrossum ->
2008-03-19 13:38:57giampaolo.rodolasetmessages: + msg64055
2008-03-18 21:45:07mkcsetmessages: + msg63995
2008-03-18 20:55:13gvanrossumsetmessages: + msg63983
2008-03-18 20:00:19jafosetpriority: normal
assignee: gvanrossum
nosy: + gvanrossum
2008-02-13 17:35:13mkcsetmessages: + msg62366
2008-02-13 16:45:14giampaolo.rodolasetnosy: + akuchling, josiahcarlson, klimkin
messages: + msg62365
2008-02-13 15:59:41mkcsetmessages: + msg62364
2008-02-13 14:46:24giampaolo.rodolasetnosy: + giampaolo.rodola
messages: + msg62360
2008-02-11 22:17:31mkccreate