diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c index f69dde876c..56c549d84c 100644 --- a/contrib/auto_explain/auto_explain.c +++ b/contrib/auto_explain/auto_explain.c @@ -27,6 +27,7 @@ static int auto_explain_log_min_duration = -1; /* msec or -1 */ static bool auto_explain_log_analyze = false; static bool auto_explain_log_verbose = false; static bool auto_explain_log_buffers = false; +static bool auto_explain_log_wal = false; static bool auto_explain_log_triggers = false; static bool auto_explain_log_timing = true; static bool auto_explain_log_settings = false; @@ -148,6 +149,17 @@ _PG_init(void) NULL, NULL); + DefineCustomBoolVariable("auto_explain.log_wal", + "Log WAL usage.", + NULL, + &auto_explain_log_wal, + false, + PGC_SUSET, + 0, + NULL, + NULL, + NULL); + DefineCustomBoolVariable("auto_explain.log_triggers", "Include trigger statistics in plans.", "This has no effect unless log_analyze is also set.", @@ -280,6 +292,8 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags) queryDesc->instrument_options |= INSTRUMENT_ROWS; if (auto_explain_log_buffers) queryDesc->instrument_options |= INSTRUMENT_BUFFERS; + if (auto_explain_log_wal) + queryDesc->instrument_options |= INSTRUMENT_WAL; } } @@ -374,6 +388,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc) es->analyze = (queryDesc->instrument_options && auto_explain_log_analyze); es->verbose = auto_explain_log_verbose; es->buffers = (es->analyze && auto_explain_log_buffers); + es->wal = (es->analyze && auto_explain_log_wal); es->timing = (es->analyze && auto_explain_log_timing); es->summary = es->analyze; es->format = auto_explain_log_format; diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml index 3d619d4a3d..d4d29c4a64 100644 --- a/doc/src/sgml/auto-explain.sgml +++ b/doc/src/sgml/auto-explain.sgml @@ -109,6 +109,26 @@ LOAD 'auto_explain'; + + + auto_explain.log_wal (boolean) + + auto_explain.log_wal configuration parameter + + + + + auto_explain.log_wal controls whether WAL + usage statistics are printed when an execution plan is logged; it's + equivalent to the WAL option of EXPLAIN. + This parameter has no effect + unless auto_explain.log_analyze is enabled. + This parameter is off by default. + Only superusers can change this setting. + + + + auto_explain.log_timing (boolean) diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml index 385d10411f..024ede4a8d 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -41,6 +41,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] statementboolean ] SETTINGS [ boolean ] BUFFERS [ boolean ] + WAL [ boolean ] TIMING [ boolean ] SUMMARY [ boolean ] FORMAT { TEXT | XML | JSON | YAML } @@ -192,6 +193,19 @@ ROLLBACK; + + WAL + + + Include information on WAL record generation. Specifically, include the + number of records, number of full page image records and amount of WAL + bytes generated. In text format, only non-zero values are printed. This + parameter may only be used when ANALYZE is also + enabled. It defaults to FALSE. + + + + TIMING diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 81a18abbeb..bb58f92851 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -113,6 +113,7 @@ static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es); static void show_eval_params(Bitmapset *bms_params, ExplainState *es); static const char *explain_get_index_name(Oid indexId); static void show_buffer_usage(ExplainState *es, const BufferUsage *usage); +static void show_wal_usage(ExplainState *es, const WalUsage *usage); static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir, ExplainState *es); static void ExplainScanTarget(Scan *plan, ExplainState *es); @@ -175,6 +176,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, es->costs = defGetBoolean(opt); else if (strcmp(opt->defname, "buffers") == 0) es->buffers = defGetBoolean(opt); + else if (strcmp(opt->defname, "wal") == 0) + es->wal = defGetBoolean(opt); else if (strcmp(opt->defname, "settings") == 0) es->settings = defGetBoolean(opt); else if (strcmp(opt->defname, "timing") == 0) @@ -219,6 +222,11 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, (errcode(ERRCODE_INVALID_PARAMETER_VALUE), errmsg("EXPLAIN option BUFFERS requires ANALYZE"))); + if (es->wal && !es->analyze) + ereport(ERROR, + (errcode(ERRCODE_INVALID_PARAMETER_VALUE), + errmsg("EXPLAIN option WAL requires ANALYZE"))); + /* if the timing was not set explicitly, set default value */ es->timing = (timing_set) ? es->timing : es->analyze; @@ -506,6 +514,8 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, if (es->buffers) instrument_option |= INSTRUMENT_BUFFERS; + if (es->wal) + instrument_option |= INSTRUMENT_WAL; /* * We always collect timing for the entire statement, even when node-level @@ -1970,12 +1980,14 @@ ExplainNode(PlanState *planstate, List *ancestors, } } - /* Show buffer usage */ + /* Show buffer/WAL usage */ if (es->buffers && planstate->instrument) show_buffer_usage(es, &planstate->instrument->bufusage); + if (es->wal && planstate->instrument) + show_wal_usage(es, &planstate->instrument->walusage); - /* Prepare per-worker buffer usage */ - if (es->workers_state && es->buffers && es->verbose) + /* Prepare per-worker buffer/WAL usage */ + if (es->workers_state && (es->buffers || es->wal) && es->verbose) { WorkerInstrumentation *w = planstate->worker_instrument; @@ -1988,7 +2000,10 @@ ExplainNode(PlanState *planstate, List *ancestors, continue; ExplainOpenWorker(n, es); - show_buffer_usage(es, &instrument->bufusage); + if (es->buffers) + show_buffer_usage(es, &instrument->bufusage); + if (es->wal) + show_wal_usage(es, &instrument->walusage); ExplainCloseWorker(n, es); } } @@ -3087,6 +3102,44 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage) } } +/* + * Show WAL usage details. + */ +static void +show_wal_usage(ExplainState *es, const WalUsage *usage) +{ + if (es->format == EXPLAIN_FORMAT_TEXT) + { + /* Show only positive counter values. */ + if ((usage->wal_records > 0) || (usage->wal_num_fpw > 0) || + (usage->wal_bytes > 0)) + { + ExplainIndentText(es); + appendStringInfoString(es->str, "WAL:"); + + if (usage->wal_records > 0) + appendStringInfo(es->str, " records=%ld", + usage->wal_records); + if (usage->wal_num_fpw > 0) + appendStringInfo(es->str, " full page writes=%ld", + usage->wal_num_fpw); + if (usage->wal_bytes > 0) + appendStringInfo(es->str, " bytes=" UINT64_FORMAT, + usage->wal_bytes); + appendStringInfoChar(es->str, '\n'); + } + } + else + { + ExplainPropertyInteger("WAL records", NULL, + usage->wal_records, es); + ExplainPropertyInteger("WAL full page writes", NULL, + usage->wal_num_fpw, es); + ExplainPropertyUInteger("WAL bytes", NULL, + usage->wal_bytes, es); + } +} + /* * Add some additional details about an IndexScan or IndexOnlyScan */ @@ -3871,6 +3924,19 @@ ExplainPropertyInteger(const char *qlabel, const char *unit, int64 value, ExplainProperty(qlabel, unit, buf, true, es); } +/* + * Explain an unsigned integer-valued property. + */ +void +ExplainPropertyUInteger(const char *qlabel, const char *unit, uint64 value, + ExplainState *es) +{ + char buf[32]; + + snprintf(buf, sizeof(buf), UINT64_FORMAT, value); + ExplainProperty(qlabel, unit, buf, true, es); +} + /* * Explain a float-valued property, using the specified number of * fractional digits. diff --git a/src/bin/psql/tab-complete.c b/src/bin/psql/tab-complete.c index 5fec59723c..0e7a373caf 100644 --- a/src/bin/psql/tab-complete.c +++ b/src/bin/psql/tab-complete.c @@ -3045,8 +3045,8 @@ psql_completion(const char *text, int start, int end) */ if (ends_with(prev_wd, '(') || ends_with(prev_wd, ',')) COMPLETE_WITH("ANALYZE", "VERBOSE", "COSTS", "SETTINGS", - "BUFFERS", "TIMING", "SUMMARY", "FORMAT"); - else if (TailMatches("ANALYZE|VERBOSE|COSTS|SETTINGS|BUFFERS|TIMING|SUMMARY")) + "BUFFERS", "WAL", "TIMING", "SUMMARY", "FORMAT"); + else if (TailMatches("ANALYZE|VERBOSE|COSTS|SETTINGS|BUFFERS|WAL|TIMING|SUMMARY")) COMPLETE_WITH("ON", "OFF"); else if (TailMatches("FORMAT")) COMPLETE_WITH("TEXT", "XML", "JSON", "YAML"); diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index 739c1d0b42..ba661d32a6 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -42,6 +42,7 @@ typedef struct ExplainState bool analyze; /* print actual times */ bool costs; /* print estimated costs */ bool buffers; /* print buffer usage */ + bool wal; /* print WAL usage */ bool timing; /* print detailed node timing */ bool summary; /* print total planning and execution timing */ bool settings; /* print modified settings */ @@ -111,6 +112,8 @@ extern void ExplainPropertyText(const char *qlabel, const char *value, ExplainState *es); extern void ExplainPropertyInteger(const char *qlabel, const char *unit, int64 value, ExplainState *es); +extern void ExplainPropertyUInteger(const char *qlabel, const char *unit, + uint64 value, ExplainState *es); extern void ExplainPropertyFloat(const char *qlabel, const char *unit, double value, int ndigits, ExplainState *es); extern void ExplainPropertyBool(const char *qlabel, bool value,