From 149631ce5c8c5cb5b05c92a7df1de3d8e431a3c2 Mon Sep 17 00:00:00 2001 From: "Imseih (AWS), Sami" Date: Tue, 28 Dec 2021 22:00:43 +0000 Subject: [PATCH 1/1] Add index scan progress to pg_stat_progress_vacuum. Expose progress for the "vacuuming indexes" phase of a VACUUM operation. Author: Sami Imseih, based on suggestions by Nathan Bossart, Peter Geoghegan and Masahiko Sawada Discussion: https://www.postgresql.org/message-id/5478DFCD-2333-401A-B2F0-0D186AB09228%40amazon.com --- src/backend/access/gin/ginvacuum.c | 4 ++ src/backend/access/gist/gistvacuum.c | 4 ++ src/backend/access/hash/hash.c | 4 ++ src/backend/access/heap/vacuumlazy.c | 32 ++++++++++++++- src/backend/access/nbtree/nbtree.c | 4 ++ src/backend/access/spgist/spgvacuum.c | 4 ++ src/backend/catalog/system_views.sql | 15 ++++++- src/backend/commands/vacuumparallel.c | 22 +++++++++-- src/backend/utils/misc/pg_rusage.c | 56 ++++++++++++++++++++------- src/include/commands/progress.h | 20 ++++++---- src/include/utils/pg_rusage.h | 1 + 11 files changed, 137 insertions(+), 29 deletions(-) diff --git a/src/backend/access/gin/ginvacuum.c b/src/backend/access/gin/ginvacuum.c index a276eb020b..07fd5271a1 100644 --- a/src/backend/access/gin/ginvacuum.c +++ b/src/backend/access/gin/ginvacuum.c @@ -24,6 +24,8 @@ #include "storage/lmgr.h" #include "storage/predicate.h" #include "utils/memutils.h" +#include "commands/progress.h" +#include "pgstat.h" struct GinVacuumState { @@ -60,6 +62,8 @@ ginVacuumItemPointers(GinVacuumState *gvs, ItemPointerData *items, if (gvs->callback(items + i, gvs->callback_state)) { gvs->result->tuples_removed += 1; + pgstat_progress_update_param(PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED, gvs->result->tuples_removed); + if (!tmpitems) { /* diff --git a/src/backend/access/gist/gistvacuum.c b/src/backend/access/gist/gistvacuum.c index 0663193531..ee77e5e405 100644 --- a/src/backend/access/gist/gistvacuum.c +++ b/src/backend/access/gist/gistvacuum.c @@ -23,6 +23,8 @@ #include "storage/indexfsm.h" #include "storage/lmgr.h" #include "utils/memutils.h" +#include "commands/progress.h" +#include "pgstat.h" /* Working state needed by gistbulkdelete */ typedef struct @@ -375,6 +377,8 @@ restart: END_CRIT_SECTION(); vstate->stats->tuples_removed += ntodelete; + pgstat_progress_update_param(PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED, vstate->stats->tuples_removed); + /* must recompute maxoff */ maxoff = PageGetMaxOffsetNumber(page); } diff --git a/src/backend/access/hash/hash.c b/src/backend/access/hash/hash.c index 81c7da7ec6..0ac59fdb7e 100644 --- a/src/backend/access/hash/hash.c +++ b/src/backend/access/hash/hash.c @@ -31,6 +31,8 @@ #include "utils/builtins.h" #include "utils/index_selfuncs.h" #include "utils/rel.h" +#include "commands/progress.h" +#include "pgstat.h" /* Working state for hashbuild and its callback */ typedef struct @@ -631,6 +633,8 @@ loop_top: stats->estimated_count = false; stats->num_index_tuples = num_index_tuples; stats->tuples_removed += tuples_removed; + pgstat_progress_update_param(PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED, stats->tuples_removed); + /* hashvacuumcleanup will fill in num_pages */ return stats; diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index cd603e6aa4..f0cda3d162 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -167,6 +167,8 @@ typedef struct LVRelState /* VACUUM operation's cutoff for freezing XIDs and MultiXactIds */ TransactionId FreezeLimit; MultiXactId MultiXactCutoff; + /* VACCUM operation's longest index scan cycle */ + int64 max_index_cycle_time; /* Error reporting state */ char *relnamespace; @@ -343,6 +345,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, pgstat_progress_start_command(PROGRESS_COMMAND_VACUUM, RelationGetRelid(rel)); + pgstat_progress_update_param(PROGRESS_VACUUM_LEADER_PID, MyProcPid); vacuum_set_xid_limits(rel, params->freeze_min_age, @@ -2038,6 +2041,8 @@ static bool lazy_vacuum_all_indexes(LVRelState *vacrel) { bool allindexes = true; + PGRUsage ru0; + int64 index_cycle_elapsed_ms = 0; Assert(vacrel->nindexes > 0); Assert(vacrel->do_index_vacuuming); @@ -2056,6 +2061,10 @@ lazy_vacuum_all_indexes(LVRelState *vacrel) pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_VACUUM_INDEX); + pgstat_progress_update_param(PROGRESS_VACUUM_TOTAL_INDEX_VACUUM, vacrel->nindexes); + + pg_rusage_init(&ru0); + if (!ParallelVacuumIsActive(vacrel)) { for (int idx = 0; idx < vacrel->nindexes; idx++) @@ -2063,14 +2072,22 @@ lazy_vacuum_all_indexes(LVRelState *vacrel) Relation indrel = vacrel->indrels[idx]; IndexBulkDeleteResult *istat = vacrel->indstats[idx]; + /* Advertise the index that is being vacuumed and the vacuum order of the index */ + pgstat_progress_update_param(PROGRESS_VACUUM_CURRENT_INDRELID, indrel->rd_id); + pgstat_progress_update_param(PROGRESS_VACUUM_INDEX_ORDINAL, idx + 1); + vacrel->indstats[idx] = lazy_vacuum_one_index(indrel, istat, vacrel->old_live_tuples, vacrel); + /* Advertise that we are done vacuuming the index */ + pgstat_progress_update_param(PROGRESS_VACUUM_CURRENT_INDRELID, 0); + if (lazy_check_wraparound_failsafe(vacrel)) { /* Wraparound emergency -- end current index scan */ allindexes = false; + pgstat_progress_update_param(PROGRESS_VACUUM_TOTAL_INDEX_VACUUM, 0); break; } } @@ -2085,8 +2102,10 @@ lazy_vacuum_all_indexes(LVRelState *vacrel) * Do a postcheck to consider applying wraparound failsafe now. Note * that parallel VACUUM only gets the precheck and this postcheck. */ - if (lazy_check_wraparound_failsafe(vacrel)) + if (lazy_check_wraparound_failsafe(vacrel)) { allindexes = false; + pgstat_progress_update_param(PROGRESS_VACUUM_TOTAL_INDEX_VACUUM, 0); + } } /* @@ -2110,6 +2129,17 @@ lazy_vacuum_all_indexes(LVRelState *vacrel) pgstat_progress_update_param(PROGRESS_VACUUM_NUM_INDEX_VACUUMS, vacrel->num_index_scans); + /* + * Set the Maximum index vacuum cycle time. + * + * If this cycle took longer than any previous cycle, reset the max_index_cycle_time time. + */ + index_cycle_elapsed_ms = pg_rusage_elapsed_ms(&ru0); + if (index_cycle_elapsed_ms > vacrel->max_index_cycle_time) { + vacrel->max_index_cycle_time = index_cycle_elapsed_ms; + pgstat_progress_update_param(PROGRESS_VACUUM_MAX_CYCLE_TIME, index_cycle_elapsed_ms); + } + return allindexes; } diff --git a/src/backend/access/nbtree/nbtree.c b/src/backend/access/nbtree/nbtree.c index dfce06dc49..ed6e6ac42c 100644 --- a/src/backend/access/nbtree/nbtree.c +++ b/src/backend/access/nbtree/nbtree.c @@ -36,6 +36,8 @@ #include "utils/builtins.h" #include "utils/index_selfuncs.h" #include "utils/memutils.h" +#include "commands/progress.h" +#include "pgstat.h" /* @@ -1272,6 +1274,8 @@ backtrack: nupdatable); stats->tuples_removed += nhtidsdead; + pgstat_progress_update_param(PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED, stats->tuples_removed); + /* must recompute maxoff */ maxoff = PageGetMaxOffsetNumber(page); diff --git a/src/backend/access/spgist/spgvacuum.c b/src/backend/access/spgist/spgvacuum.c index 76fb0374c4..6040761f33 100644 --- a/src/backend/access/spgist/spgvacuum.c +++ b/src/backend/access/spgist/spgvacuum.c @@ -27,6 +27,8 @@ #include "storage/indexfsm.h" #include "storage/lmgr.h" #include "utils/snapmgr.h" +#include "commands/progress.h" +#include "pgstat.h" /* Entry in pending-list of TIDs we need to revisit */ @@ -160,6 +162,7 @@ vacuumLeafPage(spgBulkDeleteState *bds, Relation index, Buffer buffer, bds->stats->tuples_removed += 1; deletable[i] = true; nDeletable++; + pgstat_progress_update_param(PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED, bds->stats->tuples_removed); } else { @@ -430,6 +433,7 @@ vacuumLeafRoot(spgBulkDeleteState *bds, Relation index, Buffer buffer) bds->stats->tuples_removed += 1; toDelete[xlrec.nDelete] = i; xlrec.nDelete++; + pgstat_progress_update_param(PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED, bds->stats->tuples_removed); } else { diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql index 61b515cdb8..70f35092f6 100644 --- a/src/backend/catalog/system_views.sql +++ b/src/backend/catalog/system_views.sql @@ -1124,9 +1124,20 @@ CREATE VIEW pg_stat_progress_vacuum AS END AS phase, S.param2 AS heap_blks_total, S.param3 AS heap_blks_scanned, S.param4 AS heap_blks_vacuumed, S.param5 AS index_vacuum_count, - S.param6 AS max_dead_tuples, S.param7 AS num_dead_tuples + S.param6 AS max_dead_tuples, S.param7 AS num_dead_tuples, + S.param11 AS total_index_vacuum, S.param12 AS max_index_vacuum_cycle_time FROM pg_stat_get_progress_info('VACUUM') AS S - LEFT JOIN pg_database D ON S.datid = D.oid; + LEFT JOIN pg_database D ON S.datid = D.oid + WHERE S.pid = S.param9; -- show vacuum progress for the leader PID only + +CREATE VIEW pg_stat_progress_vacuum_index AS + SELECT + S.pid AS pid, S.param9 AS leader_pid, + S.param8 AS indrelid, S.param10 vacuum_cycle_ordinal_position, + S.param13 index_rows_vacuumed + FROM pg_stat_get_progress_info('VACUUM') AS S + LEFT JOIN pg_database D ON S.datid = D.oid + WHERE S.param8 > 0; -- show vacuum progress for a PID that has advertised an index relid CREATE VIEW pg_stat_progress_cluster AS SELECT diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c index 0d61c8ec74..983fc823bb 100644 --- a/src/backend/commands/vacuumparallel.c +++ b/src/backend/commands/vacuumparallel.c @@ -35,6 +35,7 @@ #include "storage/bufmgr.h" #include "tcop/tcopprot.h" #include "utils/lsyscache.h" +#include "commands/progress.h" /* * DSM keys for parallel vacuum. Unlike other parallel execution code, since @@ -206,7 +207,7 @@ static void parallel_vacuum_process_all_indexes(ParallelVacuumState *pvs, int nu static void parallel_vacuum_process_safe_indexes(ParallelVacuumState *pvs); static void parallel_vacuum_process_unsafe_indexes(ParallelVacuumState *pvs); static void parallel_vacuum_process_one_index(ParallelVacuumState *pvs, Relation indrel, - PVIndStats *indstats); + PVIndStats *indstats, int ordinal_position); static bool parallel_vacuum_index_is_parallel_safe(Relation indrel, int num_index_scans, bool vacuum); static void parallel_vacuum_error_callback(void *arg); @@ -754,7 +755,7 @@ parallel_vacuum_process_safe_indexes(ParallelVacuumState *pvs) continue; /* Do vacuum or cleanup of the index */ - parallel_vacuum_process_one_index(pvs, pvs->indrels[idx], indstats); + parallel_vacuum_process_one_index(pvs, pvs->indrels[idx], indstats, idx + 1); } /* @@ -795,7 +796,7 @@ parallel_vacuum_process_unsafe_indexes(ParallelVacuumState *pvs) continue; /* Do vacuum or cleanup of the index */ - parallel_vacuum_process_one_index(pvs, pvs->indrels[i], indstats); + parallel_vacuum_process_one_index(pvs, pvs->indrels[i], indstats, i + 1); } /* @@ -814,7 +815,7 @@ parallel_vacuum_process_unsafe_indexes(ParallelVacuumState *pvs) */ static void parallel_vacuum_process_one_index(ParallelVacuumState *pvs, Relation indrel, - PVIndStats *indstats) + PVIndStats *indstats, int ordinal_position) { IndexBulkDeleteResult *istat = NULL; IndexBulkDeleteResult *istat_res; @@ -842,7 +843,14 @@ parallel_vacuum_process_one_index(ParallelVacuumState *pvs, Relation indrel, switch (indstats->status) { case PARALLEL_INDVAC_STATUS_NEED_BULKDELETE: + /* Advertise the index that is being vacuumed and the vacuum order of the index */ + pgstat_progress_update_param(PROGRESS_VACUUM_CURRENT_INDRELID, indrel->rd_id); + pgstat_progress_update_param(PROGRESS_VACUUM_INDEX_ORDINAL, ordinal_position); + istat_res = vac_bulkdel_one_index(&ivinfo, istat, pvs->dead_items); + + /* Advertise that we are done vacuuming the index */ + pgstat_progress_update_param(PROGRESS_VACUUM_CURRENT_INDRELID, 0); break; case PARALLEL_INDVAC_STATUS_NEED_CLEANUP: istat_res = vac_cleanup_one_index(&ivinfo, istat); @@ -942,6 +950,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc) int nindexes; char *sharedquery; ErrorContextCallback errcallback; + PGPROC *leader = MyProc->lockGroupLeader; /* * A parallel vacuum worker must have only PROC_IN_VACUUM flag since we @@ -965,6 +974,10 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc) */ rel = table_open(shared->relid, ShareUpdateExclusiveLock); + pgstat_progress_start_command(PROGRESS_COMMAND_VACUUM, + RelationGetRelid(rel)); + pgstat_progress_update_param(PROGRESS_VACUUM_LEADER_PID, leader->pid); + /* * Open all indexes. indrels are sorted in order by OID, which should be * matched to the leader's one. @@ -1035,6 +1048,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc) vac_close_indexes(nindexes, indrels, RowExclusiveLock); table_close(rel, ShareUpdateExclusiveLock); FreeAccessStrategy(pvs.bstrategy); + pgstat_progress_end_command(); } /* diff --git a/src/backend/utils/misc/pg_rusage.c b/src/backend/utils/misc/pg_rusage.c index bb5d9e7c85..14362d7d65 100644 --- a/src/backend/utils/misc/pg_rusage.c +++ b/src/backend/utils/misc/pg_rusage.c @@ -19,6 +19,27 @@ #include "utils/pg_rusage.h" +void rusage_adjust(const PGRUsage *ru0, PGRUsage *ru1); + +void +rusage_adjust(const PGRUsage *ru0, PGRUsage *ru1) +{ + if (ru1->tv.tv_usec < ru0->tv.tv_usec) + { + ru1->tv.tv_sec--; + ru1->tv.tv_usec += 1000000; + } + if (ru1->ru.ru_stime.tv_usec < ru0->ru.ru_stime.tv_usec) + { + ru1->ru.ru_stime.tv_sec--; + ru1->ru.ru_stime.tv_usec += 1000000; + } + if (ru1->ru.ru_utime.tv_usec < ru0->ru.ru_utime.tv_usec) + { + ru1->ru.ru_utime.tv_sec--; + ru1->ru.ru_utime.tv_usec += 1000000; + } +} /* * Initialize usage snapshot. @@ -44,21 +65,7 @@ pg_rusage_show(const PGRUsage *ru0) pg_rusage_init(&ru1); - if (ru1.tv.tv_usec < ru0->tv.tv_usec) - { - ru1.tv.tv_sec--; - ru1.tv.tv_usec += 1000000; - } - if (ru1.ru.ru_stime.tv_usec < ru0->ru.ru_stime.tv_usec) - { - ru1.ru.ru_stime.tv_sec--; - ru1.ru.ru_stime.tv_usec += 1000000; - } - if (ru1.ru.ru_utime.tv_usec < ru0->ru.ru_utime.tv_usec) - { - ru1.ru.ru_utime.tv_sec--; - ru1.ru.ru_utime.tv_usec += 1000000; - } + rusage_adjust(ru0, &ru1); snprintf(result, sizeof(result), _("CPU: user: %d.%02d s, system: %d.%02d s, elapsed: %d.%02d s"), @@ -71,3 +78,22 @@ pg_rusage_show(const PGRUsage *ru0) return result; } + +/* + * Compute elapsed time since ru0 usage snapshot, and return the + * value in Milliseconds. + */ +const int64 +pg_rusage_elapsed_ms(const PGRUsage *ru0) +{ + static int64 result; + PGRUsage ru1; + + pg_rusage_init(&ru1); + + rusage_adjust(ru0, &ru1); + + result = (int64) (ru1.tv.tv_sec - ru0->tv.tv_sec) * 1000 + ((int64) (ru1.tv.tv_usec - ru0->tv.tv_usec) / 1000); + + return result; +} diff --git a/src/include/commands/progress.h b/src/include/commands/progress.h index d7bf16368b..1d25a6b345 100644 --- a/src/include/commands/progress.h +++ b/src/include/commands/progress.h @@ -18,13 +18,19 @@ #define PROGRESS_H /* Progress parameters for (lazy) vacuum */ -#define PROGRESS_VACUUM_PHASE 0 -#define PROGRESS_VACUUM_TOTAL_HEAP_BLKS 1 -#define PROGRESS_VACUUM_HEAP_BLKS_SCANNED 2 -#define PROGRESS_VACUUM_HEAP_BLKS_VACUUMED 3 -#define PROGRESS_VACUUM_NUM_INDEX_VACUUMS 4 -#define PROGRESS_VACUUM_MAX_DEAD_TUPLES 5 -#define PROGRESS_VACUUM_NUM_DEAD_TUPLES 6 +#define PROGRESS_VACUUM_PHASE 0 +#define PROGRESS_VACUUM_TOTAL_HEAP_BLKS 1 +#define PROGRESS_VACUUM_HEAP_BLKS_SCANNED 2 +#define PROGRESS_VACUUM_HEAP_BLKS_VACUUMED 3 +#define PROGRESS_VACUUM_NUM_INDEX_VACUUMS 4 +#define PROGRESS_VACUUM_MAX_DEAD_TUPLES 5 +#define PROGRESS_VACUUM_NUM_DEAD_TUPLES 6 +#define PROGRESS_VACUUM_CURRENT_INDRELID 7 +#define PROGRESS_VACUUM_LEADER_PID 8 +#define PROGRESS_VACUUM_INDEX_ORDINAL 9 +#define PROGRESS_VACUUM_TOTAL_INDEX_VACUUM 10 +#define PROGRESS_VACUUM_MAX_CYCLE_TIME 11 +#define PROGRESS_VACUUM_DEAD_TUPLES_VACUUMED 12 /* Phases of vacuum (as advertised via PROGRESS_VACUUM_PHASE) */ #define PROGRESS_VACUUM_PHASE_SCAN_HEAP 1 diff --git a/src/include/utils/pg_rusage.h b/src/include/utils/pg_rusage.h index c0def804ee..026f823155 100644 --- a/src/include/utils/pg_rusage.h +++ b/src/include/utils/pg_rusage.h @@ -33,5 +33,6 @@ typedef struct PGRUsage extern void pg_rusage_init(PGRUsage *ru0); extern const char *pg_rusage_show(const PGRUsage *ru0); +extern const int64 pg_rusage_elapsed_ms(const PGRUsage *ru0); #endif /* PG_RUSAGE_H */ -- 2.32.0