Re: Timing of 'SELECT 1'

pgman wrote:
> Merlin Moncure wrote:
> > > > The problem with gprof is that I am going to see all the backend
> > startup
> > > > stuff too, no?  Is there a way to get a dump just the run of the
> > query?
> > > 
> > > I was sort of lurking on this thread, waiting to see what became of
> > it.
> > > Did
> > > nobody actually come to a conclusion on what that "last msec" was
> > from?
> > 
> > I think the consensus was it was coming from the network layer somehow.
> > If that's the case (it probably is), there isn't a whole lot that can be
> > done about it except to bypass it using server side functions and such.
> > 
> 
> I did a little more research and found an unusual cause.  It turns out
> enabling log_parser/executor_status itself makes SELECT 1's log_duration
> go from 0.296 to 1.156 so the slowness I was seeing for SELECT 1 was
> from the measurement, not slowness in the normal code path.

I did a litte more testing.  It turns out that turning on
log_parser_stats and log_executor_stats and _not_ modifying
client_min_messages increases the execution time to 0.564 ms, and
modifying client_min_messages so the output is sent to the client
increases execution to 1.156, so the increase is half doing the time
measurements and half sending the info to the client.

--  Bruce Momjian                        |  http://candle.pha.pa.us pgman@candle.pha.pa.us               |  (610)
359-1001+  If your life is a hard drive,     |  13 Roberts Road +  Christ can be your backup.        |  Newtown Square,
Pennsylvania19073