logging.SocketHandler connections

Vinay Sajip vinay_sajip at yahoo.co.uk
Mon Nov 19 18:30:03 CET 2007

On Nov 19, 10:27 am, oj <ojee... at gmail.com> wrote:
> On Nov 16, 2:31 pm, Vinay Sajip <vinay_sa... at yahoo.co.uk> wrote:
> Here is the server code. Pretty much directly copied from the example,
> aside from not having the the handler loop forever, and queing the
> records instead of dealing with the directly.
> After further investigation, running the client with a long timeout,
> without the server, so that every connection will fail, produces
> results much closer to what I would expect. Connections attempted for
> each message initially, but not for all of the later messages as the
> retry time increases.
> The point is kinda moot now, since I guess not closing the connection
> is the 'right way' to do this, but I'm still interested in why I see
> this behaviour when the server closes the connection.

I've investigated this and the issue appears not to be related to
closing connections. Your server code differs from the example in the
docs in one crucial way: there is a while loop which you have left out
in the handle() function, which deals with multiple logging events
received in one packet. Add this back in, and all 9 events are

    def handle(self):
        while 1:
            chunk = self.connection.recv(4)

            if len(chunk) < 4:

            slen = struct.unpack(">L", chunk)[0]
            chunk = self.connection.recv(slen)

            while len(chunk) < slen:
                chunk = chunk + self.connection.recv(slen -

            obj = self.unPickle(chunk)
            record = logging.makeLogRecord(obj)
            queue.insert(0, record)

So it appears that due to buffering, 3 socket events are sent in each
packet sent over the wire. You were only processing the first of each
set of three, viz. nos. 0, 3, 6 and 9. Mystery solved, it appears!


Vinay Sajip

More information about the Python-list mailing list