pg.ddx.io  pgsql-interfaces@postgresql.org mailing list archive  
help / color / mirror / Atom feed
Re: pgin.tcl pg_exec_prepared slow (was: Released...)
8+ messages / 3 participants
[nested] [flat]

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
@ 2004-07-06 01:07 L J Bayuk <ljb220@mindspring.com>
  2004-07-06 02:43 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-07 01:27 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Greg Stark <gsstark@mit.edu>
  2004-07-07 01:44 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Greg Stark <gsstark@mit.edu>
  0 siblings, 3 replies; 8+ messages in thread

From: L J Bayuk @ 2004-07-06 01:07 UTC (permalink / raw)
  To: Nigel J. Andrews <nandrews@investsystems.co.uk>; +Cc: pgsql-interfaces

On Wed, Jun 30, 2004 at 11:29:32PM +0100, Nigel J. Andrews wrote:
> ... (description of prepared query execution in pgin.tcl taking 10 times
>      longer than pg_exec doing the same query)
> Obviously the prepared query execution is an order of magnitude slower and
> it's the TCL interface that's making it so.

My own tests show equivalent performance of pg_exec and pg_exec_prepared,
but that is for medium-to-large result sets. With tiny result sets - one
row, 2 values - I also see an unexpected 40 ms delay in pg_exec_prepared
when using pgin.tcl.  (Very interesting that it's the same delay on different
hardware.)

After looking at it for a while, I know where the problem is, but not
what is causing it. I also know how to fix it, but not why the fix works.
I'm going to explain what I know, hoping someone can fill in some missing
parts.

pg_exec sends 1 message: Query.  pg_exec_prepared sends 4 messages: Bind,
DescribePortal, Execute, and Sync. After that, they are identical.

The delay we are seeing (about 40 ms) is from the time the client sends the
Bind message to PostgreSQL until it gets a TCP ACK back. (It should get
a BindComplete message back, but the backend does't flush after sending
this - no pq_flush() at the end of exec_bind_message(). Hello, Tom, is this
a bug? Changing it just moves the delay around, though.) Other messages
from the client are typically replied to and/or ACK'd in under 1 ms,
according to Ethereal.  I don't know why this message takes so much longer
to ACK, nor why the client waits for the ACK. I'm sure it isn't the
backend; I don't think it is Tcl; it could be something in the TCP stack.

The fix: pgin.tcl sets its Tcl connection socket channel to "unbuffered",
which means each PostgreSQL message it sends will be go into the TCP
buffers immediately, since each message is written in a single "puts".  And
it seems to work fine with all messages except that Bind. My fix is to
change it to use Tcl "buffering full" mode; then I have it flush after each
sent message, except in pg_exec_prepared (and pg_exec_params), where it
flushes only after sending the final Sync.  The result is to combine the 4
messages from pg_exec_prepared so they get dumped into the TCP buffers at
once. The problem goes away, but I don't know why it works, and that
bothers me.
  Before:
    39987 microseconds per iteration - pg_exec_prepared
    39992 microseconds per iteration - pg_exec_params
     4133 microseconds per iteration - pg_exec
  After:
     4483 microseconds per iteration - pg_exec_prepared
     5214 microseconds per iteration - pg_exec_params
     4150 microseconds per iteration - pg_exec



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
@ 2004-07-06 02:43 ` Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-08 01:12   ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2 siblings, 1 reply; 8+ messages in thread

From: Tom Lane @ 2004-07-06 02:43 UTC (permalink / raw)
  To: L J Bayuk <ljb220@mindspring.com>; +Cc: Nigel J. Andrews <nandrews@investsystems.co.uk>; pgsql-interfaces

L J Bayuk <ljb220@mindspring.com> writes:
> The delay we are seeing (about 40 ms) is from the time the client sends the
> Bind message to PostgreSQL until it gets a TCP ACK back. (It should get
> a BindComplete message back, but the backend does't flush after sending
> this - no pq_flush() at the end of exec_bind_message(). Hello, Tom, is this
> a bug?

No.  If you wanted a flush just there, send a Flush message.  But AFAICS
the only reason why you'd do that is if you needed to look at the
BindComplete before sending your next message --- which you do not.

> pgin.tcl sets its Tcl connection socket channel to "unbuffered",
> which means each PostgreSQL message it sends will be go into the TCP
> buffers immediately, since each message is written in a single "puts".

This is certainly bogus.  A good implementation would arrange to flush
the TCP outbound queue immediately after sending either a Flush or a
Sync message --- and *no place else*.  Those are exactly the points
where you are starting to wait for a backend reply.  More frequent
flushing simply results in more separate network packets, which is not
a win.  Also, if you haven't sent one of these message types, you are
not entitled to expect any immediate reply (which is essentially what's
happening with pgin.tcl, evidently).

The V3 protocol is designed around the assumption that each side will
batch multiple logical messages into single network packets whenever
possible.  If you don't do this, it's not surprising that performance
sucks :-(

The reason error recovery is defined as doing skip-to-Sync is exactly
so that you can shove off a batch of messages without having first
checked the results of the earlier messages.

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2004-07-06 02:43 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
@ 2004-07-08 01:12   ` L J Bayuk <ljb220@mindspring.com>
  2004-07-10 00:07     ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 8+ messages in thread

From: L J Bayuk @ 2004-07-08 01:12 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-interfaces

On Mon, Jul 05, 2004 at 10:43:47PM -0400, Tom Lane wrote:
> L J Bayuk <ljb220@mindspring.com> writes:
> > The delay we are seeing (about 40 ms) is from the time the client sends the
> > Bind message to PostgreSQL until it gets a TCP ACK back. (It should get
> > a BindComplete message back, but the backend doesn't flush after sending
> > this - no pq_flush() at the end of exec_bind_message(). Hello, Tom, is this
> > a bug?
> 
> No.  If you wanted a flush just there, send a Flush message.  But AFAICS
> the only reason why you'd do that is if you needed to look at the
> BindComplete before sending your next message --- which you do not.


I agree, it works OK as is. I only raised the question because of two
things. First, the protocol documentation says:
  "The response (to the Bind message) is either BindComplete
   or ErrorResponse."
From which one might wrongly conclude that you get BindComplete (or
ErrorResponse) back when you send Bind. (Pgin.tcl doesn't assume this.)

Second, this comment in backend/utils/error/elog.c:
   "This flush is normally not necessary, since postgres.c will flush
    out waiting data when control returns to the main loop. But it..."
I could not find the described flush "when control returns to the main
loop". Either I'm missing it, or it isn't there, and the comment implies
that it may have been there at one time.


> > pgin.tcl sets its Tcl connection socket channel to "unbuffered",
> > which means each PostgreSQL message it sends will be go into the TCP
> > buffers immediately, since each message is written in a single "puts".
> 
> This is certainly bogus.  A good implementation would arrange to flush
> the TCP outbound queue immediately after sending either a Flush or a
> Sync message --- and *no place else*.  Those are exactly the points
> where you are starting to wait for a backend reply.  More frequent
> flushing simply results in more separate network packets, which is not
> a win.  Also, if you haven't sent one of these message types, you are
> not entitled to expect any immediate reply (which is essentially what's
> happening with pgin.tcl, evidently).
> ...

No, I didn't explain it well.  Pgin.tcl itself isn't waiting for a reply to
Bind. It sends Bind, DescribePortal, Execute, and Sync without waiting in
between.  Currently it flushes after each, but this is Tcl flushing to TCP,
not to the wire. I'm going to change that, although in Tcl I can't force
TCP to flush its outbound queue.  But for now, I seem to end up with Bind
in one packet, and the other three messages combined into another.  That
delay is pgin.tcl blocked while the TCP stack waits for an ACK to the Bind
message's packet. I don't know why this happens but it seems to be a case
where TCP performs "less than optimally" in deciding when to send what it's
got, when to ACK, and when to wait. I will work around it by exercising
more control on when Tcl flushes the data to TCP.  I just haven't decided
whether to flush before reading, or flush after all messages that need a
response (I think: Startup, PasswordMessage, Query, Sync, CopyDone, and
FunctionCall are the ones I use).



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2004-07-06 02:43 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-08 01:12   ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
@ 2004-07-10 00:07     ` Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-12 01:33       ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  0 siblings, 1 reply; 8+ messages in thread

From: Tom Lane @ 2004-07-10 00:07 UTC (permalink / raw)
  To: L J Bayuk <ljb220@mindspring.com>; +Cc: pgsql-interfaces

L J Bayuk <ljb220@mindspring.com> writes:
> I just haven't decided
> whether to flush before reading, or flush after all messages that need a
> response (I think: Startup, PasswordMessage, Query, Sync, CopyDone, and
> FunctionCall are the ones I use).

You seem to have quite missed my point.  If you decide to flush on the
basis of flush-after-certain-message-types-are-sent, then the types to
flush after are precisely Sync and Flush.  If you think you want
something different, you are wrong and should think again (or more
likely, insert Flush messages into the outgoing stream at the places
where you want a flush to occur).  There is no point in flushing after
any other message type because the backend won't flush its response.

Of course this is all moot if you choose to flush just before waiting
for input (though you'd still better be sure that Flush or Sync was the
last message sent before you do so).

> I could not find the described flush "when control returns to the main
> loop". Either I'm missing it, or it isn't there, and the comment implies
> that it may have been there at one time.

It's actually in ReadyForQuery() these days.

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2004-07-06 02:43 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-08 01:12   ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2004-07-10 00:07     ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
@ 2004-07-12 01:33       ` L J Bayuk <ljb220@mindspring.com>
  2004-07-12 02:02         ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 8+ messages in thread

From: L J Bayuk @ 2004-07-12 01:33 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-interfaces

On Fri, Jul 09, 2004 at 08:07:56PM -0400, Tom Lane wrote:
> L J Bayuk <ljb220@mindspring.com> writes:
> > I just haven't decided
> > whether to flush before reading, or flush after all messages that need a
> > response (I think: Startup, PasswordMessage, Query, Sync, CopyDone, and
> > FunctionCall are the ones I use).
> 
> You seem to have quite missed my point.  If you decide to flush on the
> basis of flush-after-certain-message-types-are-sent, then the types to
> flush after are precisely Sync and Flush.  If you think you want
> something different, you are wrong and should think again (or more
> likely, insert Flush messages into the outgoing stream at the places
> where you want a flush to occur).  There is no point in flushing after
> any other message type because the backend won't flush its response.
>...

Yes, I must be missing your point, unless you are talking only about the
Extended Query mode. Surely outside of Extended Query mode (Startup, Basic
Query mode, Function Call) the client must flush output after (at least)
the messages I listed above. That's what I get from the protocol
documentation, what works in practice, and network traces.



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2004-07-06 02:43 ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-08 01:12   ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
  2004-07-10 00:07     ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) Tom Lane <tgl@sss.pgh.pa.us>
  2004-07-12 01:33       ` Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
@ 2004-07-12 02:02         ` Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 0 replies; 8+ messages in thread

From: Tom Lane @ 2004-07-12 02:02 UTC (permalink / raw)
  To: L J Bayuk <ljb220@mindspring.com>; +Cc: pgsql-interfaces

L J Bayuk <ljb220@mindspring.com> writes:
> Yes, I must be missing your point, unless you are talking only about the
> Extended Query mode.

Sorry, you're right, that was what I was thinking about.

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
@ 2004-07-07 01:27 ` Greg Stark <gsstark@mit.edu>
  2 siblings, 0 replies; 8+ messages in thread

From: Greg Stark @ 2004-07-07 01:27 UTC (permalink / raw)
  To: L J Bayuk <ljb220@mindspring.com>; +Cc: Nigel J. Andrews <nandrews@investsystems.co.uk>; pgsql-interfaces


L J Bayuk <ljb220@mindspring.com> writes:

> The delay we are seeing (about 40 ms) is from the time the client sends the
> Bind message to PostgreSQL until it gets a TCP ACK back.

You might consider disabling the NAGLE algorithm. It can delay acks like this.
You could do this with setsockopt(SOL_TCP, TCP_NODELAY,...)

The problem is that while this would be perfectly appropriate for things like
bind messages, it's entirely inappropriate for the bulk data transfer
of the results of a query.

I would not suggest enabling TCP_NODELAY for all data. And I'm not sure how
implementations behave if you turn it on and off.

-- 
greg




^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: pgin.tcl pg_exec_prepared slow (was: Released...)
  2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
@ 2004-07-07 01:44 ` Greg Stark <gsstark@mit.edu>
  2 siblings, 0 replies; 8+ messages in thread

From: Greg Stark @ 2004-07-07 01:44 UTC (permalink / raw)
  To: L J Bayuk <ljb220@mindspring.com>; +Cc: Nigel J. Andrews <nandrews@investsystems.co.uk>; pgsql-interfaces


L J Bayuk <ljb220@mindspring.com> writes:

> Other messages from the client are typically replied to and/or ACK'd in
> under 1 ms, according to Ethereal. I don't know why this message takes so
> much longer to ACK, nor why the client waits for the ACK. I'm sure it isn't
> the backend; I don't think it is Tcl; it could be something in the TCP
> stack.

Ahah, found a good explanation from a pretty authoritative source:

http://groups.google.com/groups?oi=djq&selm=an_477899304

Nothing like getting it straight from the horse's mouth. 

(Note for any non-native-english-speakers: that's an expression, I've never
seen Mr Nagle's mouth personally)

-- 
greg




^ permalink  raw  reply  [nested|flat] 8+ messages in thread


end of thread, other threads:[~2004-07-12 02:02 UTC | newest]

Thread overview: 8+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2004-07-06 01:07 Re: pgin.tcl pg_exec_prepared slow (was: Released...) L J Bayuk <ljb220@mindspring.com>
2004-07-06 02:43 ` Tom Lane <tgl@sss.pgh.pa.us>
2004-07-08 01:12   ` L J Bayuk <ljb220@mindspring.com>
2004-07-10 00:07     ` Tom Lane <tgl@sss.pgh.pa.us>
2004-07-12 01:33       ` L J Bayuk <ljb220@mindspring.com>
2004-07-12 02:02         ` Tom Lane <tgl@sss.pgh.pa.us>
2004-07-07 01:27 ` Greg Stark <gsstark@mit.edu>
2004-07-07 01:44 ` Greg Stark <gsstark@mit.edu>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox