Dev & EngARTICLE

The four forgotten PostgreSQL GUCs that still reveal CPU and page faults per query

log_parser_stats, log_planner_stats, log_executor_stats, and log_statement_stats date back to 2003, but they report something EXPLAIN ANALYZE and pg_stat_statements don't show: the split between CPU and wait time in a query.

The four forgotten PostgreSQL GUCs that still reveal CPU and page faults per query
Image: Roberto Diniz

log_parser_stats, log_planner_stats, log_executor_stats, and log_statement_stats date back to 2003, but they report something EXPLAIN ANALYZE and pg_stat_statements don't show: the split between CPU and wait time in a query.

The "All Your GUCs in a Row" series, published on Planet PostgreSQL, dedicated an article to the four oldest logging parameters that PostgreSQL still carries: log_parser_stats, log_planner_stats, log_executor_stats, and log_statement_stats. They are remnants from 2003 (the current names came in version 7.4), older than EXPLAIN ANALYZE itself (7.2) and well before pg_stat_statements and auto_explain, both from 8.4. The text classifies them with brutal honesty: when enabled in the wrong place, they "produce a log made up largely of exclamation points."

Still, for the DBA who needs to dissect a specific query, these parameters report information that no other core tool delivers per statement. And that's where they stop being a historical curiosity.

What they do under the hood

Each one is a boolean, off by default, and requires superuser context. The mechanism is simple to the point of being crude: the backend calls getrusage() before and after a stage of statement execution and writes the difference to the log, at LOG level. The documentation itself calls this "a crude profiling instrument," and the text reinforces the diagnosis: it's getrusage() wrapped in a printf(), inside a function that still carries a code comment about who drinks coffee at DEC.

The division of labor between the four:

| Parameter | Stage covered | Blocks per statement | |---|---|---| | log_parser_stats | parser, parse analysis, and rewriter | 3 (one per stage) | | log_planner_stats | planner | 1 | | log_executor_stats | executor | 1 | | log_statement_stats | entire statement | 1 |

Since log_statement_stats measures the entire statement, it refuses to be enabled together with any of the other three, and vice versa. The article points out a revealing detail: the comment in the source code admits that this mutual exclusion doesn't work properly when the values arrive via ALTER ROLE ... SET, and "nobody cared enough to fix it."

What shows up in the log

The output of a SELECT count(*) with log_statement_stats enabled:

LOG:  QUERY STATISTICS
DETAIL:  ! system usage stats:
	! 0.178254 s user, 0.318332 s system, 5.021073 s elapsed
	! [0.179736 s user, 0.318332 s system total]
	! 126332 kB max resident size
	! 784/248560 [784/248560] filesystem blocks in/out
	! 0/2605 [0/3105] page faults/reclaims, 0 [0] swaps
	! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
	! 270/281 [272/282] voluntary/involuntary context switches
STATEMENT:  select count(*) from t

The reading is what matters: the numbers without brackets are the delta for that stage; the ones in brackets are the backend's total since it started; and max resident size is neither one nor the other, it's a peak mark (high-water mark).

Why this still matters, and where EXPLAIN ANALYZE falls short

Here's the article's central argument, and the point that matters to anyone running PostgreSQL in production. EXPLAIN ANALYZE gives wall time and buffers. pg_stat_statements gives wall time and buffers, aggregated. Neither one tells you that the five seconds in the example above were half a second of CPU and four and a half of wait.

This distinction is decisive for diagnosis. A query that consumes five seconds of wall time and burns CPU the whole time is a plan problem, a missing index, a wrong estimate. A query that consumes five seconds but only spends half a second of CPU is waiting: on I/O, a lock, resource contention. These are incidents of opposite natures, and EXPLAIN ANALYZE alone doesn't separate the two. The executor stats do.

The same goes for page faults. As the article notes, these counters reveal when a query is "generating minor faults because something is allocating and freeing a large work_mem inside a loop," a pattern that goes unnoticed by conventional tools.

The correct use, then, is surgical. In a superuser session:

sql
SET log_executor_stats = on;
-- run the problematic query here
SET log_executor_stats = off;

The answer ends up in the log. It's not meant to be left on.

Three traps before trusting the numbers

The article lists three caveats the DBA needs to internalize, or risk drawing the wrong conclusion from a correct number:

  1. Parallelism distorts. getrusage() only measures the backend, and parallel workers are separate processes. A parallel query reports only the leader's slice. In the article's example, the same count(*) showed 0.03 s of user CPU with two workers and 0.12 s with none, and "the smaller number is the wrong one."
  2. Extended protocol triples the blocks. Every modern driver uses the extended protocol, and that generates three blocks per statement, labeled PARSE MESSAGE, BIND MESSAGE, and EXECUTE MESSAGE STATISTICS, instead of just one. Whoever reads the log needs to know what they're looking at.
  3. log_error_verbosity = terse kills the DETAIL. With this setting, all that's left is a log of QUERY STATISTICS headers with nothing underneath, "a special kind of nothing."

The modern alternative: pg_stat_kcache

For anyone who wants these counters on all queries instead of a single one, the answer isn't to turn on the GUCs in postgresql.conf. It's the pg_stat_kcache extension, which collects the same getrusage() fields and aggregates them by query ID, alongside pg_stat_statements. In the article's words, it's what these four parameters "would be if they had been designed after 2009 instead of before 1997."

That's the practical recommendation for day-to-day work: anyone monitoring a fleet of PostgreSQL instances and wanting continuous visibility into user/system CPU and page faults per query ID should evaluate pg_stat_kcache, not the legacy GUCs.

The verdict

The article's final guidance is direct: leave all four off in postgresql.conf. Their habitat is a superuser session, for a single statement, followed by setting them back to off with SET. Anywhere else, the cost (log pollution, distortion from parallelism, tripled blocks) outweighs the benefit.

The real value of these parameters for the Brazilian DBA is conceptual and situational: understanding that there's a core tool capable of separating CPU from wait time in a suspect query, before scaling hardware or rewriting the query in the dark. Correct diagnosis starts with knowing what the query is actually doing with its time, and sometimes a 2003 GUC, used for thirty seconds, answers the question that EXPLAIN ANALYZE doesn't.

Translated from the Brazilian Portuguese original · Read the original