From c2848a3da107254b8d40324738335b53066b1226 Mon Sep 17 00:00:00 2001 From: Alena Rybakina Date: Mon, 20 Jul 2026 16:57:07 +0300 Subject: [PATCH v42 2/9] Track vacuum times for indexes and databases, and vacuum delay, in pg_stat views. Vacuum currently keeps cumulative time only per table (total_(auto)vacuum_time in pg_stat_all_tables), where the time spent in a bloated index is indistinguishable from heap time, and the sleep in cost-based delay points is visible only transiently in pg_stat_progress_vacuum and in the log line. Add: * pg_stat_all_indexes: total_vacuum_time, total_autovacuum_time, total_vacuum_delay_time, total_autovacuum_delay_time - accumulated per pass (a bulkdelete pass per index scan cycle plus a final cleanup pass, including passes in parallel workers; workers classify autovacuum via the leader's DSM flag); * pg_stat_all_tables: total_vacuum_delay_time, total_autovacuum_delay_time - covering the whole heap_vacuum_rel() run, matching the scope of total_vacuum_time; * pg_stat_database: total_vacuum_time, total_autovacuum_time, total_vacuum_delay_time, total_autovacuum_delay_time - the database-wide totals of the table runs (index processing happens inside the owning table's run and is not added again). Delay times advance only when track_cost_delay_timing is enabled, accumulated in the new VacuumDelayTime process counter. --- doc/src/sgml/monitoring.sgml | 109 ++++++++++++++++++ src/backend/access/heap/vacuumlazy.c | 33 +++++- src/backend/catalog/system_views.sql | 10 ++ src/backend/commands/vacuum.c | 7 ++ src/backend/commands/vacuumparallel.c | 16 +++ src/backend/utils/activity/pgstat_database.c | 4 + src/backend/utils/activity/pgstat_relation.c | 69 ++++++++++- src/backend/utils/adt/pgstatfuncs.c | 18 +++ src/include/catalog/pg_proc.dat | 24 ++++ src/include/commands/vacuum.h | 1 + src/include/pgstat.h | 26 ++++- src/test/modules/test_misc/meson.build | 1 + .../test_misc/t/016_index_vacuum_time.pl | 72 ++++++++++++ src/test/regress/expected/rules.out | 22 ++++ 14 files changed, 409 insertions(+), 3 deletions(-) create mode 100644 src/test/modules/test_misc/t/016_index_vacuum_time.pl diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index d1a20d001e9..d298877949e 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -4079,6 +4079,49 @@ description | Waiting for a newly initialized WAL file to reach durable storage + + + total_vacuum_time double precision + + + Total time manually invoked vacuums spent processing tables of this + database, in milliseconds (index processing is included in the owning + table's run) + + + + + + total_autovacuum_time double precision + + + Total time the autovacuum daemon spent processing tables of this + database, in milliseconds + + + + + + total_vacuum_delay_time double precision + + + Total time manually invoked vacuums of this database spent sleeping in + cost-based delay points, in milliseconds (counted only when + is enabled) + + + + + + total_autovacuum_delay_time double precision + + + Total time autovacuums of this database spent sleeping in cost-based + delay points, in milliseconds (counted only when + is enabled) + + + session_time double precision @@ -4426,6 +4469,50 @@ description | Waiting for a newly initialized WAL file to reach durable storage + + + total_vacuum_time double precision + + + Total time this index has been processed by manually invoked vacuums, + in milliseconds. (This includes the time spent sleeping due to + cost-based delays.) + + + + + + total_autovacuum_time double precision + + + Total time this index has been processed by the autovacuum daemon, + in milliseconds. (This includes the time spent sleeping due to + cost-based delays.) + + + + + + total_vacuum_delay_time double precision + + + Total time manually invoked vacuums spent sleeping in cost-based delay + points while processing this index, in milliseconds (counted only when + is enabled) + + + + + + total_autovacuum_delay_time double precision + + + Total time the autovacuum daemon spent sleeping in cost-based delay + points while processing this index, in milliseconds (counted only when + is enabled) + + + n_tup_ins bigint @@ -4639,6 +4726,28 @@ description | Waiting for a newly initialized WAL file to reach durable storage + + + total_vacuum_delay_time double precision + + + Total time this table's vacuums spent sleeping in cost-based delay + points, in milliseconds (counted only when + is enabled) + + + + + + total_autovacuum_delay_time double precision + + + Total time autovacuums of this table spent sleeping in cost-based + delay points, in milliseconds (counted only when + is enabled) + + + stats_reset timestamp with time zone diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index d6c763baeb9..bdd22cbeba8 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -129,6 +129,8 @@ */ #include "postgres.h" +#include + #include "access/genam.h" #include "access/heapam.h" #include "access/htup_details.h" @@ -638,6 +640,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params, TimestampTz starttime = 0; PgStat_Counter startreadtime = 0, startwritetime = 0; + double startdelaytime; WalUsage startwalusage = pgWalUsage; BufferUsage startbufferusage = pgBufferUsage; ErrorContextCallback errcallback; @@ -659,6 +662,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params, /* Used for instrumentation and stats report */ starttime = GetCurrentTimestamp(); + startdelaytime = VacuumDelayTime; pgstat_progress_start_command(PROGRESS_COMMAND_VACUUM, RelationGetRelid(rel)); @@ -985,11 +989,18 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params, * soon in cases where the failsafe prevented significant amounts of heap * vacuuming. */ + /* + * The delay counter covers the whole heap_vacuum_rel() run, matching the + * scope of total_vacuum_time. In a parallel vacuum it covers the + * leader's sleeps only; parallel workers account their own sleeps to the + * indexes they process. + */ pgstat_report_vacuum(rel, Max(vacrel->new_live_tuples, 0), vacrel->recently_dead_tuples + vacrel->missed_dead_tuples, - starttime); + starttime, + (PgStat_Counter) rint(VacuumDelayTime - startdelaytime)); pgstat_progress_end_command(); if (instrument) @@ -3016,6 +3027,8 @@ lazy_vacuum_one_index(Relation indrel, IndexBulkDeleteResult *istat, { IndexVacuumInfo ivinfo; LVSavedErrInfo saved_err_info; + TimestampTz istarttime = GetCurrentTimestamp(); + double startdelaytime = VacuumDelayTime; ivinfo.index = indrel; ivinfo.heaprel = vacrel->rel; @@ -3042,6 +3055,14 @@ lazy_vacuum_one_index(Relation indrel, IndexBulkDeleteResult *istat, istat = vac_bulkdel_one_index(&ivinfo, istat, vacrel->dead_items, vacrel->dead_items_info); + /* Accumulate this pass into the index's cumulative vacuum times */ + pgstat_report_index_vacuum_time(indrel, + TimestampDifferenceMilliseconds(istarttime, + GetCurrentTimestamp()), + (PgStat_Counter) rint(VacuumDelayTime - + startdelaytime), + AmAutoVacuumWorkerProcess()); + /* Revert to the previous phase information for error traceback */ restore_vacuum_error_info(vacrel, &saved_err_info); pfree(vacrel->indname); @@ -3066,6 +3087,8 @@ lazy_cleanup_one_index(Relation indrel, IndexBulkDeleteResult *istat, { IndexVacuumInfo ivinfo; LVSavedErrInfo saved_err_info; + TimestampTz istarttime = GetCurrentTimestamp(); + double startdelaytime = VacuumDelayTime; ivinfo.index = indrel; ivinfo.heaprel = vacrel->rel; @@ -3091,6 +3114,14 @@ lazy_cleanup_one_index(Relation indrel, IndexBulkDeleteResult *istat, istat = vac_cleanup_one_index(&ivinfo, istat); + /* Accumulate this pass into the index's cumulative vacuum times */ + pgstat_report_index_vacuum_time(indrel, + TimestampDifferenceMilliseconds(istarttime, + GetCurrentTimestamp()), + (PgStat_Counter) rint(VacuumDelayTime - + startdelaytime), + AmAutoVacuumWorkerProcess()); + /* Revert to the previous phase information for error traceback */ restore_vacuum_error_info(vacrel, &saved_err_info); pfree(vacrel->indname); diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql index 090281a03dd..1e9bb3c3bba 100644 --- a/src/backend/catalog/system_views.sql +++ b/src/backend/catalog/system_views.sql @@ -747,6 +747,8 @@ CREATE VIEW pg_stat_all_tables AS pg_stat_get_total_autovacuum_time(C.oid) AS total_autovacuum_time, pg_stat_get_total_analyze_time(C.oid) AS total_analyze_time, pg_stat_get_total_autoanalyze_time(C.oid) AS total_autoanalyze_time, + pg_stat_get_total_vacuum_delay_time(C.oid) AS total_vacuum_delay_time, + pg_stat_get_total_autovacuum_delay_time(C.oid) AS total_autovacuum_delay_time, pg_stat_get_stat_reset_time(C.oid) AS stats_reset FROM pg_class C LEFT JOIN pg_index I ON C.oid = I.indrelid @@ -869,6 +871,10 @@ CREATE VIEW pg_stat_all_indexes AS pg_stat_get_lastscan(I.oid) AS last_idx_scan, pg_stat_get_tuples_returned(I.oid) AS idx_tup_read, pg_stat_get_tuples_fetched(I.oid) AS idx_tup_fetch, + pg_stat_get_total_vacuum_time(I.oid) AS total_vacuum_time, + pg_stat_get_total_autovacuum_time(I.oid) AS total_autovacuum_time, + pg_stat_get_total_vacuum_delay_time(I.oid) AS total_vacuum_delay_time, + pg_stat_get_total_autovacuum_delay_time(I.oid) AS total_autovacuum_delay_time, pg_stat_get_stat_reset_time(I.oid) AS stats_reset FROM pg_class C JOIN pg_index X ON C.oid = X.indrelid JOIN @@ -1172,6 +1178,10 @@ CREATE VIEW pg_stat_database AS pg_stat_get_db_checksum_last_failure(D.oid) AS checksum_last_failure, pg_stat_get_db_blk_read_time(D.oid) AS blk_read_time, pg_stat_get_db_blk_write_time(D.oid) AS blk_write_time, + pg_stat_get_db_total_vacuum_time(D.oid) AS total_vacuum_time, + pg_stat_get_db_total_autovacuum_time(D.oid) AS total_autovacuum_time, + pg_stat_get_db_total_vacuum_delay_time(D.oid) AS total_vacuum_delay_time, + pg_stat_get_db_total_autovacuum_delay_time(D.oid) AS total_autovacuum_delay_time, pg_stat_get_db_session_time(D.oid) AS session_time, pg_stat_get_db_active_time(D.oid) AS active_time, pg_stat_get_db_idle_in_transaction_time(D.oid) AS idle_in_transaction_time, diff --git a/src/backend/commands/vacuum.c b/src/backend/commands/vacuum.c index 38539a6fd3d..ee01768a3e6 100644 --- a/src/backend/commands/vacuum.c +++ b/src/backend/commands/vacuum.c @@ -95,6 +95,12 @@ int vacuum_cost_limit = 200; /* Variable for reporting cost-based vacuum delay from parallel workers. */ int64 parallel_vacuum_worker_delay_ns = 0; +/* + * Cumulative time this process has slept in cost-based vacuum delay points, + * in milliseconds. Only advances when track_cost_delay_timing is enabled. + */ +double VacuumDelayTime = 0; + /* * VacuumFailsafeActive is a defined as a global so that we can determine * whether or not to re-enable cost-based vacuum delay when vacuuming a table. @@ -2516,6 +2522,7 @@ vacuum_delay_point(bool is_analyze) INSTR_TIME_SET_CURRENT(delay_end); INSTR_TIME_SET_ZERO(delay); INSTR_TIME_ACCUM_DIFF(delay, delay_end, delay_start); + VacuumDelayTime += INSTR_TIME_GET_MILLISEC(delay); /* * For parallel workers, we only report the delay time every once diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c index 41cefcfde54..82e1e12501a 100644 --- a/src/backend/commands/vacuumparallel.c +++ b/src/backend/commands/vacuumparallel.c @@ -35,6 +35,8 @@ */ #include "postgres.h" +#include + #include "access/amapi.h" #include "access/table.h" #include "access/xact.h" @@ -1076,6 +1078,8 @@ parallel_vacuum_process_one_index(ParallelVacuumState *pvs, Relation indrel, IndexBulkDeleteResult *istat = NULL; IndexBulkDeleteResult *istat_res; IndexVacuumInfo ivinfo; + TimestampTz istarttime = GetCurrentTimestamp(); + double startdelaytime = VacuumDelayTime; /* * Update the pointer to the corresponding bulk-deletion result if someone @@ -1112,6 +1116,18 @@ parallel_vacuum_process_one_index(ParallelVacuumState *pvs, Relation indrel, RelationGetRelationName(indrel)); } + /* + * Accumulate this pass into the index's cumulative vacuum times. Use the + * leader's DSM flag to classify autovacuum: a parallel worker of an + * autovacuum leader is a regular background worker. + */ + pgstat_report_index_vacuum_time(indrel, + TimestampDifferenceMilliseconds(istarttime, + GetCurrentTimestamp()), + (PgStat_Counter) rint(VacuumDelayTime - + startdelaytime), + pvs->shared->is_autovacuum); + /* * Copy the index bulk-deletion result returned from ambulkdelete and * amvacuumcleanup to the DSM segment if it's the first cycle because they diff --git a/src/backend/utils/activity/pgstat_database.c b/src/backend/utils/activity/pgstat_database.c index 7f3bc016593..c906f16eb1b 100644 --- a/src/backend/utils/activity/pgstat_database.c +++ b/src/backend/utils/activity/pgstat_database.c @@ -480,6 +480,10 @@ pgstat_database_flush_cb(PgStat_EntryRef *entry_ref, bool nowait) PGSTAT_ACCUM_DBCOUNT(blk_read_time); PGSTAT_ACCUM_DBCOUNT(blk_write_time); + PGSTAT_ACCUM_DBCOUNT(total_vacuum_time); + PGSTAT_ACCUM_DBCOUNT(total_autovacuum_time); + PGSTAT_ACCUM_DBCOUNT(total_vacuum_delay_time); + PGSTAT_ACCUM_DBCOUNT(total_autovacuum_delay_time); PGSTAT_ACCUM_DBCOUNT(sessions); PGSTAT_ACCUM_DBCOUNT(session_time); diff --git a/src/backend/utils/activity/pgstat_relation.c b/src/backend/utils/activity/pgstat_relation.c index 04f2eb21d0b..1b913f2777c 100644 --- a/src/backend/utils/activity/pgstat_relation.c +++ b/src/backend/utils/activity/pgstat_relation.c @@ -209,7 +209,8 @@ pgstat_drop_relation(Relation rel) */ void pgstat_report_vacuum(Relation rel, PgStat_Counter livetuples, - PgStat_Counter deadtuples, TimestampTz starttime) + PgStat_Counter deadtuples, TimestampTz starttime, + PgStat_Counter delaytime) { PgStat_EntryRef *entry_ref; PgStatShared_Relation *shtabentry; @@ -252,16 +253,39 @@ pgstat_report_vacuum(Relation rel, PgStat_Counter livetuples, tabentry->last_autovacuum_time = ts; tabentry->autovacuum_count++; tabentry->total_autovacuum_time += elapsedtime; + tabentry->total_autovacuum_delay_time += delaytime; } else { tabentry->last_vacuum_time = ts; tabentry->vacuum_count++; tabentry->total_vacuum_time += elapsedtime; + tabentry->total_vacuum_delay_time += delaytime; } pgstat_unlock_entry(entry_ref); + /* + * Accumulate the same times into the database-wide totals. Index + * processing happens inside the table's run, so per-index times reported + * via pgstat_report_index_vacuum_time() are not added here again. The + * database entry is stored in microseconds, as its other time counters. + */ + { + PgStat_StatDBEntry *dbentry = pgstat_prep_database_pending(dboid); + + if (AmAutoVacuumWorkerProcess()) + { + dbentry->total_autovacuum_time += elapsedtime * 1000; + dbentry->total_autovacuum_delay_time += delaytime * 1000; + } + else + { + dbentry->total_vacuum_time += elapsedtime * 1000; + dbentry->total_vacuum_delay_time += delaytime * 1000; + } + } + /* * Flush IO statistics now. pgstat_report_stat() will flush IO stats, * however this will not be called until after an entire autovacuum cycle @@ -272,6 +296,49 @@ pgstat_report_vacuum(Relation rel, PgStat_Counter livetuples, (void) pgstat_flush_backend(false, PGSTAT_BACKEND_FLUSH_IO); } +/* + * Report the time spent vacuuming an index. + * + * Vacuum may process an index several times: a bulkdelete pass per index + * scan cycle plus a final cleanup pass, possibly spread across parallel + * workers. Each pass adds its elapsed and delay time here, accumulating + * into the index's total_vacuum_time or total_autovacuum_time, mirroring + * the table-level counters. The caller says whether this is autovacuum: + * parallel workers of an autovacuum leader are regular background workers, + * so AmAutoVacuumWorkerProcess() cannot be relied upon here. + */ +void +pgstat_report_index_vacuum_time(Relation rel, PgStat_Counter elapsedtime, + PgStat_Counter delaytime, bool is_autovacuum) +{ + PgStat_EntryRef *entry_ref; + PgStatShared_Relation *shtabentry; + PgStat_StatTabEntry *tabentry; + Oid dboid = (rel->rd_rel->relisshared ? InvalidOid : MyDatabaseId); + + if (!pgstat_track_counts) + return; + + /* block acquiring lock for the same reason as pgstat_report_autovac() */ + entry_ref = pgstat_get_entry_ref_locked(PGSTAT_KIND_RELATION, dboid, + RelationGetRelid(rel), false); + shtabentry = (PgStatShared_Relation *) entry_ref->shared_stats; + tabentry = &shtabentry->stats; + + if (is_autovacuum) + { + tabentry->total_autovacuum_time += elapsedtime; + tabentry->total_autovacuum_delay_time += delaytime; + } + else + { + tabentry->total_vacuum_time += elapsedtime; + tabentry->total_vacuum_delay_time += delaytime; + } + + pgstat_unlock_entry(entry_ref); +} + /* * Report that the table was just analyzed and flush IO statistics. * diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c index 565d0e70768..1af3b4758af 100644 --- a/src/backend/utils/adt/pgstatfuncs.c +++ b/src/backend/utils/adt/pgstatfuncs.c @@ -136,6 +136,12 @@ PG_STAT_GET_RELENTRY_FLOAT8(total_analyze_time) /* pg_stat_get_total_autoanalyze_time */ PG_STAT_GET_RELENTRY_FLOAT8(total_autoanalyze_time) +/* pg_stat_get_total_vacuum_delay_time */ +PG_STAT_GET_RELENTRY_FLOAT8(total_vacuum_delay_time) + +/* pg_stat_get_total_autovacuum_delay_time */ +PG_STAT_GET_RELENTRY_FLOAT8(total_autovacuum_delay_time) + #define PG_STAT_GET_RELENTRY_TIMESTAMPTZ(stat) \ Datum \ CppConcat(pg_stat_get_,stat)(PG_FUNCTION_ARGS) \ @@ -1239,6 +1245,18 @@ PG_STAT_GET_DBENTRY_FLOAT8_MS(blk_write_time) /* pg_stat_get_db_idle_in_transaction_time */ PG_STAT_GET_DBENTRY_FLOAT8_MS(idle_in_transaction_time) +/* pg_stat_get_db_total_vacuum_time */ +PG_STAT_GET_DBENTRY_FLOAT8_MS(total_vacuum_time) + +/* pg_stat_get_db_total_autovacuum_time */ +PG_STAT_GET_DBENTRY_FLOAT8_MS(total_autovacuum_time) + +/* pg_stat_get_db_total_vacuum_delay_time */ +PG_STAT_GET_DBENTRY_FLOAT8_MS(total_vacuum_delay_time) + +/* pg_stat_get_db_total_autovacuum_delay_time */ +PG_STAT_GET_DBENTRY_FLOAT8_MS(total_autovacuum_delay_time) + /* pg_stat_get_db_session_time */ PG_STAT_GET_DBENTRY_FLOAT8_MS(session_time) diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat index 3cb84359adf..479c0bb236e 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -5929,6 +5929,30 @@ proname => 'pg_stat_get_db_blk_write_time', provolatile => 's', proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', prosrc => 'pg_stat_get_db_blk_write_time' }, +{ oid => '8685', descr => 'total vacuum delay time, in milliseconds', + proname => 'pg_stat_get_total_vacuum_delay_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_total_vacuum_delay_time' }, +{ oid => '8686', descr => 'total autovacuum delay time, in milliseconds', + proname => 'pg_stat_get_total_autovacuum_delay_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_total_autovacuum_delay_time' }, +{ oid => '8687', descr => 'statistics: total vacuum time of tables in database, in milliseconds', + proname => 'pg_stat_get_db_total_vacuum_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_db_total_vacuum_time' }, +{ oid => '8688', descr => 'statistics: total autovacuum time of tables in database, in milliseconds', + proname => 'pg_stat_get_db_total_autovacuum_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_db_total_autovacuum_time' }, +{ oid => '8689', descr => 'statistics: total vacuum delay time in database, in milliseconds', + proname => 'pg_stat_get_db_total_vacuum_delay_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_db_total_vacuum_delay_time' }, +{ oid => '8690', descr => 'statistics: total autovacuum delay time in database, in milliseconds', + proname => 'pg_stat_get_db_total_autovacuum_delay_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_db_total_autovacuum_delay_time' }, { oid => '6185', descr => 'statistics: session time, in milliseconds', proname => 'pg_stat_get_db_session_time', provolatile => 's', proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h index 956d9cea36d..fbc20fe2047 100644 --- a/src/include/commands/vacuum.h +++ b/src/include/commands/vacuum.h @@ -359,6 +359,7 @@ extern PGDLLIMPORT double vacuum_cost_delay; extern PGDLLIMPORT int vacuum_cost_limit; extern PGDLLIMPORT int64 parallel_vacuum_worker_delay_ns; +extern PGDLLIMPORT double VacuumDelayTime; /* in commands/vacuum.c */ extern void ExecVacuum(ParseState *pstate, VacuumStmt *vacstmt, bool isTopLevel); diff --git a/src/include/pgstat.h b/src/include/pgstat.h index 58a44857f13..7a17787b717 100644 --- a/src/include/pgstat.h +++ b/src/include/pgstat.h @@ -399,6 +399,17 @@ typedef struct PgStat_StatDBEntry PgStat_Counter parallel_workers_to_launch; PgStat_Counter parallel_workers_launched; + /* + * Cumulative time vacuums spent processing tables of this database and + * sleeping in cost-based delay points, in microseconds (the delay parts + * advance only when track_cost_delay_timing is enabled). Times of index + * processing are included in the owning table's run. + */ + PgStat_Counter total_vacuum_time; + PgStat_Counter total_autovacuum_time; + PgStat_Counter total_vacuum_delay_time; + PgStat_Counter total_autovacuum_delay_time; + TimestampTz stat_reset_timestamp; } PgStat_StatDBEntry; @@ -484,6 +495,14 @@ typedef struct PgStat_StatTabEntry PgStat_Counter total_analyze_time; PgStat_Counter total_autoanalyze_time; + /* + * Time slept in cost-based vacuum delay points while vacuuming this + * relation, in milliseconds; nonzero only when track_cost_delay_timing + * is enabled. + */ + PgStat_Counter total_vacuum_delay_time; + PgStat_Counter total_autovacuum_delay_time; + TimestampTz stat_reset_time; } PgStat_StatTabEntry; @@ -711,7 +730,12 @@ extern void pgstat_unlink_relation(Relation rel); extern void pgstat_report_vacuum(Relation rel, PgStat_Counter livetuples, PgStat_Counter deadtuples, - TimestampTz starttime); + TimestampTz starttime, + PgStat_Counter delaytime); +extern void pgstat_report_index_vacuum_time(Relation rel, + PgStat_Counter elapsedtime, + PgStat_Counter delaytime, + bool is_autovacuum); extern void pgstat_report_analyze(Relation rel, PgStat_Counter livetuples, PgStat_Counter deadtuples, bool resetcounter, TimestampTz starttime); diff --git a/src/test/modules/test_misc/meson.build b/src/test/modules/test_misc/meson.build index ee290698b31..4429c780418 100644 --- a/src/test/modules/test_misc/meson.build +++ b/src/test/modules/test_misc/meson.build @@ -23,6 +23,7 @@ tests += { 't/012_ddlutils.pl', 't/013_temp_obj_multisession.pl', 't/014_log_statement_max_length.pl', + 't/016_index_vacuum_time.pl', ], # The injection points are cluster-wide, so disable installcheck 'runningcheck': false, diff --git a/src/test/modules/test_misc/t/016_index_vacuum_time.pl b/src/test/modules/test_misc/t/016_index_vacuum_time.pl new file mode 100644 index 00000000000..36360b40a07 --- /dev/null +++ b/src/test/modules/test_misc/t/016_index_vacuum_time.pl @@ -0,0 +1,72 @@ +# Copyright (c) 2026, PostgreSQL Global Development Group + +# Test the total_vacuum_time counter of pg_stat_all_indexes: the time vacuum +# spent processing each index, accumulated over bulkdelete and cleanup passes, +# mirroring the table-level counter in pg_stat_all_tables. + +use strict; +use warnings FATAL => 'all'; +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +my $node = PostgreSQL::Test::Cluster->new('main'); +$node->init; +$node->append_conf( + 'postgresql.conf', qq[ +autovacuum = off +track_cost_delay_timing = on +]); +$node->start; + +# Enough rows that the bulkdelete pass over the index takes measurable time; +# a small vacuum_cost_delay adds deterministic delay time on fast machines. +$node->safe_psql( + 'postgres', qq[ +CREATE TABLE vactime_t (id int PRIMARY KEY, v text) WITH (autovacuum_enabled = off); +INSERT INTO vactime_t SELECT g, repeat('x', 10) FROM generate_series(1, 100000) g; +DELETE FROM vactime_t WHERE id % 2 = 0; +]); +$node->safe_psql( + 'postgres', qq[ +SET vacuum_cost_delay = '1ms'; +SET vacuum_cost_limit = 200; +VACUUM vactime_t; +]); + +# The upper bound guards against garbage such as an epoch-based elapsed time +# leaking into the counter. +is( $node->safe_psql( + 'postgres', qq[ +SELECT total_vacuum_time > 0 AND total_vacuum_time < 600000 + FROM pg_stat_all_indexes WHERE indexrelname = 'vactime_t_pkey']), + 't', + 'total_vacuum_time advanced sanely for the index in pg_stat_all_indexes'); + +is( $node->safe_psql( + 'postgres', qq[ +SELECT total_vacuum_delay_time > 0 AND total_vacuum_delay_time <= total_vacuum_time + FROM pg_stat_all_indexes WHERE indexrelname = 'vactime_t_pkey']), + 't', + 'total_vacuum_delay_time advanced and not above total_vacuum_time'); + +is( $node->safe_psql( + 'postgres', qq[ +SELECT total_autovacuum_time = 0 FROM pg_stat_all_indexes + WHERE indexrelname = 'vactime_t_pkey']), + 't', + 'manual vacuum did not count into total_autovacuum_time'); + +# The same run must have accumulated into the database-wide totals. +is( $node->safe_psql( + 'postgres', qq[ +SELECT total_vacuum_time > 0 AND total_vacuum_time < 600000 + AND total_vacuum_delay_time > 0 + AND total_vacuum_delay_time <= total_vacuum_time + FROM pg_stat_database WHERE datname = current_database()]), + 't', + 'database-wide vacuum times advanced sanely in pg_stat_database'); + +$node->stop; + +done_testing(); diff --git a/src/test/regress/expected/rules.out b/src/test/regress/expected/rules.out index 6a3341356da..bd9eca0dcef 100644 --- a/src/test/regress/expected/rules.out +++ b/src/test/regress/expected/rules.out @@ -1810,6 +1810,10 @@ pg_stat_all_indexes| SELECT c.oid AS relid, pg_stat_get_lastscan(i.oid) AS last_idx_scan, pg_stat_get_tuples_returned(i.oid) AS idx_tup_read, pg_stat_get_tuples_fetched(i.oid) AS idx_tup_fetch, + pg_stat_get_total_vacuum_time(i.oid) AS total_vacuum_time, + pg_stat_get_total_autovacuum_time(i.oid) AS total_autovacuum_time, + pg_stat_get_total_vacuum_delay_time(i.oid) AS total_vacuum_delay_time, + pg_stat_get_total_autovacuum_delay_time(i.oid) AS total_autovacuum_delay_time, pg_stat_get_stat_reset_time(i.oid) AS stats_reset FROM (((pg_class c JOIN pg_index x ON ((c.oid = x.indrelid))) @@ -1846,6 +1850,8 @@ pg_stat_all_tables| SELECT c.oid AS relid, pg_stat_get_total_autovacuum_time(c.oid) AS total_autovacuum_time, pg_stat_get_total_analyze_time(c.oid) AS total_analyze_time, pg_stat_get_total_autoanalyze_time(c.oid) AS total_autoanalyze_time, + pg_stat_get_total_vacuum_delay_time(c.oid) AS total_vacuum_delay_time, + pg_stat_get_total_autovacuum_delay_time(c.oid) AS total_autovacuum_delay_time, pg_stat_get_stat_reset_time(c.oid) AS stats_reset FROM ((pg_class c LEFT JOIN pg_index i ON ((c.oid = i.indrelid))) @@ -1913,6 +1919,10 @@ pg_stat_database| SELECT oid AS datid, pg_stat_get_db_checksum_last_failure(oid) AS checksum_last_failure, pg_stat_get_db_blk_read_time(oid) AS blk_read_time, pg_stat_get_db_blk_write_time(oid) AS blk_write_time, + pg_stat_get_db_total_vacuum_time(oid) AS total_vacuum_time, + pg_stat_get_db_total_autovacuum_time(oid) AS total_autovacuum_time, + pg_stat_get_db_total_vacuum_delay_time(oid) AS total_vacuum_delay_time, + pg_stat_get_db_total_autovacuum_delay_time(oid) AS total_autovacuum_delay_time, pg_stat_get_db_session_time(oid) AS session_time, pg_stat_get_db_active_time(oid) AS active_time, pg_stat_get_db_idle_in_transaction_time(oid) AS idle_in_transaction_time, @@ -2335,6 +2345,10 @@ pg_stat_sys_indexes| SELECT relid, last_idx_scan, idx_tup_read, idx_tup_fetch, + total_vacuum_time, + total_autovacuum_time, + total_vacuum_delay_time, + total_autovacuum_delay_time, stats_reset FROM pg_stat_all_indexes WHERE ((schemaname = ANY (ARRAY['pg_catalog'::name, 'information_schema'::name])) OR (schemaname ~ '^pg_toast'::text)); @@ -2368,6 +2382,8 @@ pg_stat_sys_tables| SELECT relid, total_autovacuum_time, total_analyze_time, total_autoanalyze_time, + total_vacuum_delay_time, + total_autovacuum_delay_time, stats_reset FROM pg_stat_all_tables WHERE ((schemaname = ANY (ARRAY['pg_catalog'::name, 'information_schema'::name])) OR (schemaname ~ '^pg_toast'::text)); @@ -2390,6 +2406,10 @@ pg_stat_user_indexes| SELECT relid, last_idx_scan, idx_tup_read, idx_tup_fetch, + total_vacuum_time, + total_autovacuum_time, + total_vacuum_delay_time, + total_autovacuum_delay_time, stats_reset FROM pg_stat_all_indexes WHERE ((schemaname <> ALL (ARRAY['pg_catalog'::name, 'information_schema'::name])) AND (schemaname !~ '^pg_toast'::text)); @@ -2423,6 +2443,8 @@ pg_stat_user_tables| SELECT relid, total_autovacuum_time, total_analyze_time, total_autoanalyze_time, + total_vacuum_delay_time, + total_autovacuum_delay_time, stats_reset FROM pg_stat_all_tables WHERE ((schemaname <> ALL (ARRAY['pg_catalog'::name, 'information_schema'::name])) AND (schemaname !~ '^pg_toast'::text)); -- 2.39.5 (Apple Git-154)