Toad World Blog

Going Deep on Stats

Mar 15, 2017 11:24:57 AM by Bruce Momjian

Postgres includes lots of monitoring tools that allow you to see what is happening, but there are a few settings that really go into detail, e.g. log_statement_stats:

SET client_min_messages = log;

SET log_statement_stats = true;

 

SELECT 100;

LOG: QUERY STATISTICS
DETAIL: ! system usage stats:

1 ! 0.000000 s user, 0.000000 s system, 0.000201 s elapsed

2 ! [0.000000 s user, 0.000000 s system total]

3 ! 0/0 [0/0] filesystem blocks in/out

4 ! 0/14 [0/363] page faults/reclaims, 0 [0] swaps

5 ! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent

6 ! 0/0 [3/0] voluntary/involuntary context switches

 ?column?

----------
 100

What do all those numbers mean? Well, the Linux getrusage() manual page has a clue — these are kernel resource usage statistics. The first two lines show the user and kernel ("system") cpu time used, as well as elapsed time. (The numbers in brackets on line #2 and following are totals for this process.) Line #3 shows I/O from/to the storage device (not from the kernel cache). Line #4 covers memory pages faulted into the process address space and reclaimed. Line #5 shows signal and ipc message activity. Line #6 shows process context switches.

Let's look at some more interesting queries by populating a new table:

CREATE TABLE test(x INTEGER);
INSERT INTO test SELECT x FROM generate_series(1, 1000) t(x);

By clearing the kernel buffers with echo 3 > /proc/sys/vm/drop_caches and restarting the server we can see reads from the storage device (via log_statement_stats) and reads from the kernel cache (via explain (buffers true):

EXPLAIN (ANALYZE true, BUFFERS true, TIMING false, COSTS false)
SELECT COUNT() FROM test;

LOG: QUERY STATISTICS

DETAIL: ! system usage stats:

! 0.000000 s user, 0.000000 s system, 0.019259 s elapsed

! [0.008000 s user, 0.000000 s system total]

! 1712/0 [5840/280] filesystem blocks in/out

! 7/94 [21/586] page faults/reclaims, 0 [0] swaps

! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent

! 29/1 [73/3] voluntary/involuntary context switches

 QUERY PLAN

---------------------------------------------------

Aggregate (actual rows=1 loops=1)

 Buffers: shared read=5

 -> Seq Scan on test (actual rows=1000 loops=1)

 Buffers: shared read=5

 Planning time: 3.673 ms

 Execution time: 2.221 ms

EXPLAIN (ANALYZE true, BUFFERS true, TIMING false, COSTS false)

SELECT COUNT() FROM test;

LOG: QUERY STATISTICS

DETAIL: ! system usage stats:

! 0.000000 s user, 0.000000 s system, 0.000408 s elapsed

! [0.008000 s user, 0.000000 s system total]

! 0/0 [5840/288] filesystem blocks in/out

! 0/3 [21/591] page faults/reclaims, 0 [0] swaps

! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent

! 0/0 [74/3] voluntary/involuntary context switches

 QUERY PLAN

---------------------------------------------------

Aggregate (actual rows=1 loops=1)

 Buffers: shared hit=5

 -> Seq Scan on test (actual rows=1000 loops=1)

 Buffers: shared hit=5

 Planning time: 0.027 ms

 Execution time: 0.250 ms

Notice the first count reads 1712 512-byte blocks from storage and 5 8kB blocks from the kernel cache into the shared buffer cache. (The unrecorded reads are probably system table information.) The second query shows no I/O from the storage device, and a hit on 5 8kB shared buffer pages.

As you might know, Postgres executes queries in stages. Fortunately, you can get rusage statistics for each stage with log_parser_stats, log_planner_stats, and log_executor_stats. (explain (analyze true) also shows planning and execution durations, which you can see above.)

As you can see, you can access a wealth of information about Postgres and how it is using the cpus, storage, and caches. These have a large impact on how quickly queries execute.

Bruce Momjian is a Senior Database Architect at EnterpriseDB.

Tags: PostgreSQL

Bruce Momjian

Written by Bruce Momjian

Bruce Momjian is a co-founder of the PostgreSQL Global Development Group, and has worked on PostgreSQL since 1996 as a committer and community leader.

He is a frequent speaker and Postgres evangelist and travels worldwide appearing at conferences to help educate the community on the business value of Postgres advances and new technology enhancements.

He is the author of PostgreSQL: Introduction and Concepts, published by Addison-Wesley.