From 456325d581a1a28b49e82de48172b19fca8b204a Mon Sep 17 00:00:00 2001 From: Michael Paquier Date: Mon, 27 Jan 2025 09:23:55 +0900 Subject: [PATCH v7] Track per relation cumulative time spent in [auto]vacuum and [auto]analyze This commit adds four fields to the statistics of relations, aggregating the amount of time spent for each operation on a relation: - total_vacuum_time, for manual vacuum. - total_autovacuum_time, for autovacuum. - total_analyze_time, for manual analyze. - total_autoanalyze_time, for autoanalyze. This gives users the option to derive the average time spent for these operations with the help of the related "count" fields. XXX: catversion bump XXX: stats version bump Author: Sami Imseih Reviewed-by: Bertrand Drouvot, Michael Paquier Discussion: https://www.postgresql.org/message-id/CAA5RZ0uVOGBYmPEeGF2d1B_67tgNjKx_bKDuL%2BoUftuoz%2B%3DY1g%40mail.gmail.com --- src/include/catalog/pg_proc.dat | 16 +++++++++ src/include/pgstat.h | 10 ++++-- src/backend/access/heap/vacuumlazy.c | 7 ++-- src/backend/catalog/system_views.sql | 6 +++- src/backend/commands/analyze.c | 12 ++++--- src/backend/utils/activity/pgstat_relation.c | 21 ++++++++--- src/backend/utils/adt/pgstatfuncs.c | 28 +++++++++++++++ src/test/regress/expected/rules.out | 18 ++++++++-- doc/src/sgml/monitoring.sgml | 38 ++++++++++++++++++++ 9 files changed, 139 insertions(+), 17 deletions(-) diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat index 2aafdbc3e93..5b8c2ad2a54 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -5543,6 +5543,22 @@ proname => 'pg_stat_get_autoanalyze_count', provolatile => 's', proparallel => 'r', prorettype => 'int8', proargtypes => 'oid', prosrc => 'pg_stat_get_autoanalyze_count' }, +{ oid => '8406', descr => 'total vacuum time, in milliseconds', + proname => 'pg_stat_get_total_vacuum_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_total_vacuum_time' }, +{ oid => '8407', descr => 'total autovacuum time, in milliseconds', + proname => 'pg_stat_get_total_autovacuum_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_total_autovacuum_time' }, +{ oid => '8408', descr => 'total analyze time, in milliseconds', + proname => 'pg_stat_get_total_analyze_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_total_analyze_time' }, +{ oid => '8409', descr => 'total autoanalyze time, in milliseconds', + proname => 'pg_stat_get_total_autoanalyze_time', provolatile => 's', + proparallel => 'r', prorettype => 'float8', proargtypes => 'oid', + prosrc => 'pg_stat_get_total_autoanalyze_time' }, { oid => '1936', descr => 'statistics: currently active backend IDs', proname => 'pg_stat_get_backend_idset', prorows => '100', proretset => 't', provolatile => 's', proparallel => 'r', prorettype => 'int4', diff --git a/src/include/pgstat.h b/src/include/pgstat.h index d0d45150977..ea6889d7090 100644 --- a/src/include/pgstat.h +++ b/src/include/pgstat.h @@ -465,6 +465,11 @@ typedef struct PgStat_StatTabEntry PgStat_Counter analyze_count; TimestampTz last_autoanalyze_time; /* autovacuum initiated */ PgStat_Counter autoanalyze_count; + + PgStat_Counter total_vacuum_time; /* times in milliseconds */ + PgStat_Counter total_autovacuum_time; + PgStat_Counter total_analyze_time; + PgStat_Counter total_autoanalyze_time; } PgStat_StatTabEntry; typedef struct PgStat_WalStats @@ -649,10 +654,11 @@ extern void pgstat_assoc_relation(Relation rel); extern void pgstat_unlink_relation(Relation rel); extern void pgstat_report_vacuum(Oid tableoid, bool shared, - PgStat_Counter livetuples, PgStat_Counter deadtuples); + PgStat_Counter livetuples, PgStat_Counter deadtuples, + TimestampTz starttime); extern void pgstat_report_analyze(Relation rel, PgStat_Counter livetuples, PgStat_Counter deadtuples, - bool resetcounter); + bool resetcounter, TimestampTz starttime); /* * If stats are enabled, but pending data hasn't been prepared yet, call diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index 5b0e790e121..5ed43e43914 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -386,7 +386,6 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, if (instrument) { pg_rusage_init(&ru0); - starttime = GetCurrentTimestamp(); if (track_io_timing) { startreadtime = pgStatBlockReadTime; @@ -394,6 +393,9 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, } } + /* Used for instrumentation and stats report */ + starttime = GetCurrentTimestamp(); + pgstat_progress_start_command(PROGRESS_COMMAND_VACUUM, RelationGetRelid(rel)); @@ -659,7 +661,8 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, rel->rd_rel->relisshared, Max(vacrel->new_live_tuples, 0), vacrel->recently_dead_tuples + - vacrel->missed_dead_tuples); + vacrel->missed_dead_tuples, + starttime); pgstat_progress_end_command(); if (instrument) diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql index 46868bf7e89..cddc3ea9b53 100644 --- a/src/backend/catalog/system_views.sql +++ b/src/backend/catalog/system_views.sql @@ -696,7 +696,11 @@ CREATE VIEW pg_stat_all_tables AS pg_stat_get_vacuum_count(C.oid) AS vacuum_count, pg_stat_get_autovacuum_count(C.oid) AS autovacuum_count, pg_stat_get_analyze_count(C.oid) AS analyze_count, - pg_stat_get_autoanalyze_count(C.oid) AS autoanalyze_count + pg_stat_get_autoanalyze_count(C.oid) AS autoanalyze_count, + pg_stat_get_total_vacuum_time(C.oid) AS total_vacuum_time, + 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 FROM pg_class C LEFT JOIN pg_index I ON C.oid = I.indrelid LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c index 2a7769b1fd1..f8da32e9aef 100644 --- a/src/backend/commands/analyze.c +++ b/src/backend/commands/analyze.c @@ -344,8 +344,8 @@ do_analyze_rel(Relation onerel, VacuumParams *params, RestrictSearchPath(); /* - * measure elapsed time if called with verbose or if autovacuum logging - * requires it + * When verbose or autovacuum logging is used, initialize a resource usage + * snapshot and optionally track I/O timing. */ if (instrument) { @@ -356,9 +356,11 @@ do_analyze_rel(Relation onerel, VacuumParams *params, } pg_rusage_init(&ru0); - starttime = GetCurrentTimestamp(); } + /* Used for instrumentation and stats report */ + starttime = GetCurrentTimestamp(); + /* * Determine which columns to analyze * @@ -693,9 +695,9 @@ do_analyze_rel(Relation onerel, VacuumParams *params, */ if (!inh) pgstat_report_analyze(onerel, totalrows, totaldeadrows, - (va_cols == NIL)); + (va_cols == NIL), starttime); else if (onerel->rd_rel->relkind == RELKIND_PARTITIONED_TABLE) - pgstat_report_analyze(onerel, 0, 0, (va_cols == NIL)); + pgstat_report_analyze(onerel, 0, 0, (va_cols == NIL), starttime); /* * If this isn't part of VACUUM ANALYZE, let index AMs do cleanup. diff --git a/src/backend/utils/activity/pgstat_relation.c b/src/backend/utils/activity/pgstat_relation.c index 965a7fe2c64..d64595a165c 100644 --- a/src/backend/utils/activity/pgstat_relation.c +++ b/src/backend/utils/activity/pgstat_relation.c @@ -208,19 +208,22 @@ pgstat_drop_relation(Relation rel) */ void pgstat_report_vacuum(Oid tableoid, bool shared, - PgStat_Counter livetuples, PgStat_Counter deadtuples) + PgStat_Counter livetuples, PgStat_Counter deadtuples, + TimestampTz starttime) { PgStat_EntryRef *entry_ref; PgStatShared_Relation *shtabentry; PgStat_StatTabEntry *tabentry; Oid dboid = (shared ? InvalidOid : MyDatabaseId); TimestampTz ts; + PgStat_Counter elapsedtime; if (!pgstat_track_counts) return; /* Store the data in the table's hash table entry. */ ts = GetCurrentTimestamp(); + elapsedtime = TimestampDifferenceMilliseconds(starttime, ts); /* block acquiring lock for the same reason as pgstat_report_autovac() */ entry_ref = pgstat_get_entry_ref_locked(PGSTAT_KIND_RELATION, @@ -248,11 +251,13 @@ pgstat_report_vacuum(Oid tableoid, bool shared, { tabentry->last_autovacuum_time = ts; tabentry->autovacuum_count++; + tabentry->total_autovacuum_time += elapsedtime; } else { tabentry->last_vacuum_time = ts; tabentry->vacuum_count++; + tabentry->total_vacuum_time += elapsedtime; } pgstat_unlock_entry(entry_ref); @@ -276,12 +281,14 @@ pgstat_report_vacuum(Oid tableoid, bool shared, void pgstat_report_analyze(Relation rel, PgStat_Counter livetuples, PgStat_Counter deadtuples, - bool resetcounter) + bool resetcounter, TimestampTz starttime) { PgStat_EntryRef *entry_ref; PgStatShared_Relation *shtabentry; PgStat_StatTabEntry *tabentry; Oid dboid = (rel->rd_rel->relisshared ? InvalidOid : MyDatabaseId); + TimestampTz ts; + PgStat_Counter elapsedtime; if (!pgstat_track_counts) return; @@ -315,6 +322,10 @@ pgstat_report_analyze(Relation rel, deadtuples = Max(deadtuples, 0); } + /* Store the data in the table's hash table entry. */ + ts = GetCurrentTimestamp(); + elapsedtime = TimestampDifferenceMilliseconds(starttime, ts); + /* block acquiring lock for the same reason as pgstat_report_autovac() */ entry_ref = pgstat_get_entry_ref_locked(PGSTAT_KIND_RELATION, dboid, RelationGetRelid(rel), @@ -338,13 +349,15 @@ pgstat_report_analyze(Relation rel, if (AmAutoVacuumWorkerProcess()) { - tabentry->last_autoanalyze_time = GetCurrentTimestamp(); + tabentry->last_autoanalyze_time = ts; tabentry->autoanalyze_count++; + tabentry->total_autoanalyze_time += elapsedtime; } else { - tabentry->last_analyze_time = GetCurrentTimestamp(); + tabentry->last_analyze_time = ts; tabentry->analyze_count++; + tabentry->total_analyze_time += elapsedtime; } pgstat_unlock_entry(entry_ref); diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c index 0f5e0a9778d..e9096a88492 100644 --- a/src/backend/utils/adt/pgstatfuncs.c +++ b/src/backend/utils/adt/pgstatfuncs.c @@ -106,6 +106,34 @@ PG_STAT_GET_RELENTRY_INT64(tuples_updated) /* pg_stat_get_vacuum_count */ PG_STAT_GET_RELENTRY_INT64(vacuum_count) +#define PG_STAT_GET_RELENTRY_FLOAT8(stat) \ +Datum \ +CppConcat(pg_stat_get_,stat)(PG_FUNCTION_ARGS) \ +{ \ + Oid relid = PG_GETARG_OID(0); \ + double result; \ + PgStat_StatTabEntry *tabentry; \ + \ + if ((tabentry = pgstat_fetch_stat_tabentry(relid)) == NULL) \ + result = 0; \ + else \ + result = (double) (tabentry->stat); \ + \ + PG_RETURN_FLOAT8(result); \ +} + +/* pg_stat_get_total_vacuum_time */ +PG_STAT_GET_RELENTRY_FLOAT8(total_vacuum_time) + +/* pg_stat_get_total_autovacuum_time */ +PG_STAT_GET_RELENTRY_FLOAT8(total_autovacuum_time) + +/* pg_stat_get_total_analyze_time */ +PG_STAT_GET_RELENTRY_FLOAT8(total_analyze_time) + +/* pg_stat_get_total_autoanalyze_time */ +PG_STAT_GET_RELENTRY_FLOAT8(total_autoanalyze_time) + #define PG_STAT_GET_RELENTRY_TIMESTAMPTZ(stat) \ Datum \ CppConcat(pg_stat_get_,stat)(PG_FUNCTION_ARGS) \ diff --git a/src/test/regress/expected/rules.out b/src/test/regress/expected/rules.out index 856a8349c50..3361f6a69c9 100644 --- a/src/test/regress/expected/rules.out +++ b/src/test/regress/expected/rules.out @@ -1804,7 +1804,11 @@ pg_stat_all_tables| SELECT c.oid AS relid, pg_stat_get_vacuum_count(c.oid) AS vacuum_count, pg_stat_get_autovacuum_count(c.oid) AS autovacuum_count, pg_stat_get_analyze_count(c.oid) AS analyze_count, - pg_stat_get_autoanalyze_count(c.oid) AS autoanalyze_count + pg_stat_get_autoanalyze_count(c.oid) AS autoanalyze_count, + pg_stat_get_total_vacuum_time(c.oid) AS total_vacuum_time, + 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 FROM ((pg_class c LEFT JOIN pg_index i ON ((c.oid = i.indrelid))) LEFT JOIN pg_namespace n ON ((n.oid = c.relnamespace))) @@ -2190,7 +2194,11 @@ pg_stat_sys_tables| SELECT relid, vacuum_count, autovacuum_count, analyze_count, - autoanalyze_count + autoanalyze_count, + total_vacuum_time, + total_autovacuum_time, + total_analyze_time, + total_autoanalyze_time FROM pg_stat_all_tables WHERE ((schemaname = ANY (ARRAY['pg_catalog'::name, 'information_schema'::name])) OR (schemaname ~ '^pg_toast'::text)); pg_stat_user_functions| SELECT p.oid AS funcid, @@ -2238,7 +2246,11 @@ pg_stat_user_tables| SELECT relid, vacuum_count, autovacuum_count, analyze_count, - autoanalyze_count + autoanalyze_count, + total_vacuum_time, + total_autovacuum_time, + total_analyze_time, + total_autoanalyze_time FROM pg_stat_all_tables WHERE ((schemaname <> ALL (ARRAY['pg_catalog'::name, 'information_schema'::name])) AND (schemaname !~ '^pg_toast'::text)); pg_stat_wal| SELECT wal_records, diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index e5888fae2b5..0bdb51eedb9 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -4053,6 +4053,44 @@ description | Waiting for a newly initialized WAL file to reach durable storage daemon + + + + total_vacuum_time double precision + + + Total time this table has been vacuumed, in milliseconds + + + + + + total_autovacuum_time double precision + + + Total time this table has been vacuumed by the autovacuum daemon, + in milliseconds + + + + + + total_analyze_time double precision + + + Total time this table has been analyzed, in milliseconds + + + + + + total_autoanalyze_time double precision + + + Total time this table has been analyzed by the autovacuum daemon, + in milliseconds + + -- 2.47.2