logging.SocketHandler connections

[oj]

On Nov 19, 5:30 pm, Vinay Sajip <vinay_sa... at yahoo.co.uk> wrote:
> 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
> received.
>
>     def handle(self):
>         while 1:
>             chunk = self.connection.recv(4)
>
>             if len(chunk) < 4:
>                 break
>
>             slen = struct.unpack(">L", chunk)[0]
>             chunk = self.connection.recv(slen)
>
>             while len(chunk) < slen:
>                 chunk = chunk + self.connection.recv(slen -
> len(chunk))
>
>             obj = self.unPickle(chunk)
>             record = logging.makeLogRecord(obj)
>             queue_lock.acquire()
>             queue.insert(0, record)
>             queue_lock.release()
>
> 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!
>
> Regards,
>
> Vinay Sajip

I don't think buffering explains the behaviour I was seeing.

The server was logging message 0 about the same time the client logged
message 0, which means that the information was sent then and there.
Messages 1 and 2 hadn't yet been sent, so they couldn't be in the same
packet.

If buffering was the cause, I'd expect to see message 0 logged on the
server at the same time message 2 was logged on the client.

-Oliver