What does \timing measure?

On Tue, Sep 24, 2013 at 1:13 PM, Daniel Tahara <daniel.tahara@yale.edu>wrote:

I am attempting to benchmark a number of queries over a 15GB dataset with
~ 10mil records. When I run linux time on the query execution (single
column projection), it returns 1 minute, but the \timing command returns
only 15 seconds?

Can you show exactly how you are executing those?

Can someone explain the difference? 1 minute is consistent with reading
the 15gb from disk at 250mb/s (I have SSDs), but is \timing supposed to
include that cost? Or simply the computation time plus the time to return
results.

Probably much of your data is cached in RAM so doesn't have be read from
disk anyway. To the extent it does need to be read from disk, that time
will be included.

psql's \timing doesn't include the time it takes for psql to format and
print the results to the screen (or whereever the output of psql is sent).

Cheers,

Jeff

On Tue, Sep 24, 2013 at 6:07 PM, Jeff Janes <jeff.janes@gmail.com> wrote:

On Tue, Sep 24, 2013 at 1:13 PM, Daniel Tahara <daniel.tahara@yale.edu>wrote:

I am attempting to benchmark a number of queries over a 15GB dataset with
~ 10mil records. When I run linux time on the query execution (single
column projection), it returns 1 minute, but the \timing command returns
only 15 seconds?

Can you show exactly how you are executing those?

time echo '\\timing \\\\ select msg from test' | $PG_ROOT/bin/psql >>
out.txt

Here is the actual console output of running the above line four times:

Output from Unix time:
~/pgsql/bin/psql test 51.61s user 1.26s system 82% cpu 1:04.08 total
~/pgsql/bin/psql test 50.84s user 1.04s system 83% cpu 1:02.11 total
~/pgsql/bin/psql test 50.32s user 0.79s system 83% cpu 1:01.29 total
~/pgsql/bin/psql test 50.86s user 0.74s system 83% cpu 1:01.53 total

Results of \timing:
Time: 13423.454 ms
Time: 11861.327 ms
Time: 11568.109 ms
Time: 11292.633 ms

Can someone explain the difference? 1 minute is consistent with reading
the 15gb from disk at 250mb/s (I have SSDs), but is \timing supposed to
include that cost? Or simply the computation time plus the time to return
results.

Probably much of your data is cached in RAM so doesn't have be read from
disk anyway. To the extent it does need to be read from disk, that time
will be included.

shared_buffers are set to default (128mb), as is everything else in
postgresql.conf

psql's \timing doesn't include the time it takes for psql to format and
print the results to the screen (or whereever the output of psql is sent).

Got it.

Cheers,

Jeff

Thanks!

On Tue, Sep 24, 2013 at 6:37 PM, Daniel Tahara <daniel.tahara@yale.edu>wrote:

time echo '\\timing \\\\ select msg from test' | $PG_ROOT/bin/psql >>
out.txt

This should be:
time echo '\\timing \\\\ select msg from test' | $PG_ROOT/bin/psql test >>
out.txt

Sorry for the typo, and thanks for the help.

Daniel

Computer Science
Yale University, Class of 2014
daniel.tahara@yale.edu
(646) 397-6379

I'm curious what the following would show:

time echo '\\timing \\\\ select 1 from dual' | $PG_ROOT/bin/psql test >>
out.txt

Greg Haase
On Sep 24, 2013 4:01 PM, "Daniel Tahara" <daniel.tahara@yale.edu> wrote:

On 09/24/2013 04:07 PM, Gregory Haase wrote:

I'm curious what the following would show:

time echo '\\timing \\\\ select 1 from dual' | $PG_ROOT/bin/psql test

out.txt

Also try ...>/dev/null to see if writing to local disk or buffer is part
of the delay.

Cheers,
Steve

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general