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(at)candle(dot)pha(dot)pa(dot)us | (610) 359-1001
+ If your life is a hard drive, | 13 Roberts Road
+ Christ can be your backup. | Newtown Square, Pennsylvania 19073