Re: strange logging line/statistics weirdness - plus 'timeout queue' weirdness?

Hi Jeffrey,

> >> The strange log line I see (questionable value is Tt - since I
> >> obviously spent a minute and a half waiting for a reply)
> >>
> >> (extra cruft cut) [27/Aug/2008:12:30:53.081] front-xxx
> >> back-xxx/server1 0/0/0/0/17 200 362 - - --VN 0/0/0/0/0 0/0 "GET /
> >> HTTP/1.1"
> >>
> >> Is this correct? Tt = 0?
> >
> > The total time here is 17 ms and the log indicate that you spent no time
> > in the queue nor anywhere BTW (everything ran instantly). While it's possible,
> > it seems very unlikely, especially considering the time you waited. What
> > version is this ? Wouldn't this be one before 1.3.14.6 or 1.3.15.2 ? In
> > earlier versions, the queue management was buggy but IMHO it would not
> > end up doing nasty things like this.
> >
>
> :) yeah, i would have considered that. Unfortunately, the version i'm
> talking about here is 1.3.15.2 ...

I'm stupid, I found this morning why you see short timers in your logs. It's simply because your frontend is full. The connection between your client and haproxy does not really establish, your connection establishes between the client and the SYSTEM (your connection lies in the backlog queue). And the system will wake haproxy up once the frontend releases one connection slot by closing one connection. Haproxy starts the accept() timer at this precise moment (because it could not even know there was something pending, the system was keeping it), and if your request is fast to process, you have a small timer as above (eg: 17 ms after waiting 1 minute in the system). As a hint, you might see in your logs that the connection which ended just before yours got processed took approximately the time you spent waiting.

So you're not mad, you really saw what you saw, it's just that your connection was not served yet.

Regards,
Willy Received on 2008/09/03 22:20