Re: Finding query execution time using \timing and EXPLAIN ANALYZE.. - Mailing list pgsql-admin

From Tom Lane
Subject Re: Finding query execution time using \timing and EXPLAIN ANALYZE..
Date
Msg-id 3118192.1669042441@sss.pgh.pa.us
Whole thread Raw
In response to Finding query execution time using \timing and EXPLAIN ANALYZE..  (Satalabaha Postgres <satalabaha.postgres@gmail.com>)
Responses Re: Finding query execution time using \timing and EXPLAIN ANALYZE..
List pgsql-admin
Satalabaha Postgres <satalabaha.postgres@gmail.com> writes:
> I was trying to get elapsed time for the sql using the \timing command in
> psql as well as EXPLAIN ANALYZE.. I see both the commands reporting
> different elapsed time. And this is after repeated execution of the same
> query and not the first execution. In this case, which one would be the
> right execution time for the query.

They're presumably both accurate, but they aren't measuring the same
thing.  psql's \timing reports the end-to-end time from the client's
perspective.  EXPLAIN ANALYZE reports the time for two components
of the server's processing.  So \timing includes all of these:

1. Transmission of the query across the network to the server
2. Parsing and parse analysis of the query
3. Rewriting (a/k/a view expansion) of the query
4. Planning
5. Execution
6. Formatting of the query results as text
7. Transmission of the results across the network to the client.

while EXPLAIN is only telling you about steps 4 and 5.

Having said that, I'm a bit baffled by the size of the difference.
This example doesn't look like any of the other steps should take
very long: it's a short simple query, there doesn't seem to be
any view involved, and the result is only one row.  Unless maybe
you're using tin-cans-and-string for the network connection?

There are various effects whereby the first execution of a query
can take longer than repeat executions, but you said you'd
controlled for that.

Also, how stable are these numbers if you repeat them several
times?  It might be mostly about noise and/or the effects of
CPU power management.  On my Linux box I find that I don't
get very reproducible numbers for short queries unless I've
done "sudo cpupower frequency-set --governor performance".

            regards, tom lane



pgsql-admin by date:

Previous
From: Tom Lane
Date:
Subject: Re: how can one infer the maximum possible restore time from a WAL file(name) in a backup?
Next
From: "Anjul Tyagi"
Date:
Subject: Client IP in Patroni