>From 7b6664ca9ac5fe944a7aa1d5c19113fb322732c5 Mon Sep 17 00:00:00 2001 From: Manu Date: Tue, 22 Sep 2026 20:59:30 -0300 Subject: [PATCH] Check the documented progress phases against the reported ones A progress phase lives in three places that nothing keeps in sync: its value in progress.h, the text system_views.sql gives it, and its row in the table in monitoring.sgml, whose order a reader takes as the order the phases happen in. Add DocPhases.pm, which reads the last two, and a test that runs the commands and compares. A phase value the view or the documentation does not know about fails the test. A phase first reached out of the documented order is reported instead, since that is a documentation bug rather than a server one. Going back to a phase that already happened is not reported: several commands loop on purpose, and VACUUM returning to "scanning heap" for each round of index vacuuming is covered by the test. --- src/test/modules/test_progress/DocPhases.pm | 265 ++++++++++++++++++ src/test/modules/test_progress/Makefile | 5 + src/test/modules/test_progress/meson.build | 3 + .../modules/test_progress/t/002_doc_phases.pl | 110 ++++++++ 4 files changed, 383 insertions(+) create mode 100644 src/test/modules/test_progress/DocPhases.pm create mode 100644 src/test/modules/test_progress/t/002_doc_phases.pl diff --git a/src/test/modules/test_progress/DocPhases.pm b/src/test/modules/test_progress/DocPhases.pm new file mode 100644 index 00000000000..7485c5f07ca --- /dev/null +++ b/src/test/modules/test_progress/DocPhases.pm @@ -0,0 +1,265 @@ +# Copyright (c) 2026, PostgreSQL Global Development Group + +=pod + +=head1 NAME + +DocPhases - cross-check the documented phases against the ones a command +really reports + +=head1 SYNOPSIS + + use DocPhases; + + my $doc = DocPhases::load($share_dir); + my @problems = DocPhases::check_against_trace($doc, 'VACUUM', \@phases_seen); + +=head1 DESCRIPTION + +A progress phase exists in three places in the tree, and nothing checks +that the three agree: + +=over + +=item * F defines the value +(C is 1). + +=item * F turns the value into the +text the user sees (C). + +=item * F lists the phases, in a table whose +row order is what a reader takes as the order the phases happen in. + +=back + +This module reads the last two and compares them with what a command +actually reported, so that a phase that is documented but never reached, a +phase reported but not documented, and a documented order that does not +match the real one, all become visible. + +Nothing here is hardcoded: adding a phase in the three places keeps the +check quiet, adding it in two of them does not. + +=cut + +package DocPhases; + +use strict; +use warnings FATAL => 'all'; + +use Carp; + +# view name -> the phase table in monitoring.sgml +our %PHASE_TABLE = ( + pg_stat_progress_vacuum => 'vacuum-phases', + pg_stat_progress_analyze => 'analyze-phases', + pg_stat_progress_cluster => 'cluster-phases', + pg_stat_progress_repack => 'repack-phases', + pg_stat_progress_create_index => 'create-index-phases', + pg_stat_progress_basebackup => 'basebackup-phases', +); + +# command name as PROGRESS_DEBUG logs it -> view name +our %COMMAND_VIEW = ( + VACUUM => 'pg_stat_progress_vacuum', + ANALYZE => 'pg_stat_progress_analyze', + CLUSTER => 'pg_stat_progress_cluster', + REPACK => 'pg_stat_progress_repack', + # progress.h calls it CREATE_INDEX, which is how PROGRESS_DEBUG logs it + CREATE_INDEX => 'pg_stat_progress_create_index', + BASEBACKUP => 'pg_stat_progress_basebackup', +); + +=pod + +=head2 load($system_views_sql, $monitoring_sgml) + +Read the phase texts from system_views.sql and their documented order from +monitoring.sgml. Returns a hashref keyed by view name, each holding + + value_to_text { 0 => 'initializing', 1 => 'scanning heap', ... } + doc_order [ 'initializing', 'scanning heap', ... ] + +The two paths come from the Makefile, the same way the module that reads +progress.h gets its own. + +=cut + +sub load +{ + my ($system_views_sql, $monitoring_sgml) = @_; + my %out; + + my $views = _slurp($system_views_sql); + my $sgml = _slurp($monitoring_sgml); + + for my $view (keys %PHASE_TABLE) + { + # the CASE that maps the phase parameter to its text + next unless $views =~ /CREATE VIEW \Q$view\E AS(.*?);\n/s; + my $body = $1; + # The phase CASE, and only it: some views have another CASE just + # before it (create_index maps param1 to a command name), so the + # match must not run from one CASE into the next one's END. The + # keyword case varies too ("END as phase"). + next + unless $body =~ + /CASE \s+ S\.param\d+ ((?: (?! \bEND\s+AS\b ) . )*?) \s+ END \s+ AS \s+ phase/isx; + my $case = $1; + + my %v2t; + while ($case =~ /WHEN\s+(\d+)\s+THEN\s+'([^']*)'/g) + { + $v2t{$1} = $2; + } + next unless %v2t; + + # the documented order is the row order of the phase table + my $id = $PHASE_TABLE{$view}; + my @doc; + if ($sgml =~ /(.*?)<\/table>/s) + { + my $table = $1; + while ($table =~ /([^<]*)<\/literal><\/entry>/g) + { + push @doc, $1; + } + } + + $out{$view} = { value_to_text => \%v2t, doc_order => \@doc }; + } + + return \%out; +} + +=pod + +=head2 check_against_trace($doc, $command, $phases) + +$phases is the sequence of phase values a single command run reported, as +ProgressCheck::phases_of() returns it. Returns a list of problems, each a +hashref with 'kind' and 'detail'. + +Three kinds are reported: + + undocumented a value was reported that system_views.sql or the + documentation does not know about + out_of_order a phase was reported after one that the documentation + lists later, which means the table's row order is not the + order of execution + never_reached reported only by unreached_phases(), see below + +A phase repeating, or the sequence going back to an earlier phase, is +normal for commands that loop (VACUUM revisits the heap), so a backwards +step is only reported the first time a pair is seen, and the caller +decides whether that pair is a real loop or a documentation bug. + +=cut + +sub check_against_trace +{ + my ($doc, $command, $phases) = @_; + my @problems; + + my $view = $COMMAND_VIEW{$command} or return (); + my $d = $doc->{$view} or return (); + + my %rank; + my $i = 0; + $rank{$_} = $i++ for @{ $d->{doc_order} }; + + my $prev; + my %seen_pair; + my %already; + for my $val (@$phases) + { + my $text = $d->{value_to_text}{$val}; + + if (!defined $text) + { + push @problems, + { + kind => 'undocumented', + detail => "$command reported phase value $val, which " + . "system_views.sql does not map to any text" + }; + next; + } + + if (!exists $rank{$text}) + { + push @problems, + { + kind => 'undocumented', + detail => "$command reported phase \"$text\", which is not " + . "listed in the documentation table" + }; + } + elsif (defined $prev + && exists $rank{$prev} + && $rank{$text} < $rank{$prev} + && !$already{$text} + && !$seen_pair{"$prev|$text"}++) + { + # Going back to a phase that already happened is a loop, and + # several commands loop on purpose: VACUUM returns to "scanning + # heap" for each round of index vacuuming, and the documentation + # says so. What is reported here is the other case: a phase + # reached for the FIRST time although the table lists it earlier, + # which means the row order is not the order of execution. + push @problems, + { + kind => 'out_of_order', + detail => "$command went from \"$prev\" to \"$text\", but the " + . "documentation lists \"$text\" before \"$prev\"" + }; + } + + if (defined $text) + { + $already{$text} = 1; + $prev = $text; + } + } + + return @problems; +} + +=pod + +=head2 unreached_phases($doc, $command, $phases) + +The documented phases that the run never reported. A phase can be +legitimately unreachable in a given run (an index-less table never +vacuums indexes), so this is information for the caller, not a failure. + +=cut + +sub unreached_phases +{ + my ($doc, $command, $phases) = @_; + + my $view = $COMMAND_VIEW{$command} or return (); + my $d = $doc->{$view} or return (); + + my %seen; + for my $val (@$phases) + { + my $t = $d->{value_to_text}{$val}; + $seen{$t} = 1 if defined $t; + } + + return grep { !$seen{$_} } @{ $d->{doc_order} }; +} + +sub _slurp +{ + my ($path) = @_; + open my $fh, '<', $path or croak "could not open $path: $!"; + local $/; + my $c = <$fh>; + close $fh; + return $c; +} + +1; diff --git a/src/test/modules/test_progress/Makefile b/src/test/modules/test_progress/Makefile index f5dbca84920..835acc0ae0f 100644 --- a/src/test/modules/test_progress/Makefile +++ b/src/test/modules/test_progress/Makefile @@ -18,3 +18,8 @@ endif # The test checks its description of the progress parameters against this. export PROGRESS_H := $(abs_top_srcdir)/src/include/commands/progress.h + +# ... and the phases a command reports against the text the view gives them +# and the order the documentation lists them in. +export SYSTEM_VIEWS_SQL := $(abs_top_srcdir)/src/backend/catalog/system_views.sql +export MONITORING_SGML := $(abs_top_srcdir)/doc/src/sgml/monitoring.sgml diff --git a/src/test/modules/test_progress/meson.build b/src/test/modules/test_progress/meson.build index 0f8a6d86dba..0743267d106 100644 --- a/src/test/modules/test_progress/meson.build +++ b/src/test/modules/test_progress/meson.build @@ -7,9 +7,12 @@ tests += { 'tap': { 'env': { 'PROGRESS_H': meson.project_source_root() / 'src/include/commands/progress.h', + 'SYSTEM_VIEWS_SQL': meson.project_source_root() / 'src/backend/catalog/system_views.sql', + 'MONITORING_SGML': meson.project_source_root() / 'doc/src/sgml/monitoring.sgml', }, 'tests': [ 't/001_progress.pl', + 't/002_doc_phases.pl', ], # The test reads the server log, which is cluster-wide. 'runningcheck': false, diff --git a/src/test/modules/test_progress/t/002_doc_phases.pl b/src/test/modules/test_progress/t/002_doc_phases.pl new file mode 100644 index 00000000000..23d6085cad9 --- /dev/null +++ b/src/test/modules/test_progress/t/002_doc_phases.pl @@ -0,0 +1,110 @@ +# Copyright (c) 2026, PostgreSQL Global Development Group + +# Check the progress phases a command really reports against the phases the +# documentation lists for it. +# +# A phase lives in three places that nothing keeps in sync: its value in +# progress.h, its text in system_views.sql, and its row in the table in +# monitoring.sgml. This test runs the commands and compares. + +use strict; +use warnings FATAL => 'all'; + +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +use FindBin; +use lib $FindBin::RealBin . '/..'; + +use ProgressCheck; +use DocPhases; + +if (!$ENV{PROGRESS_DEBUG_BUILD}) +{ + plan skip_all => + 'test requires a build with PROGRESS_DEBUG (set PROGRESS_DEBUG_BUILD=1)'; +} + +my $system_views = $ENV{SYSTEM_VIEWS_SQL} + or plan skip_all => 'SYSTEM_VIEWS_SQL is not set'; +my $monitoring = $ENV{MONITORING_SGML} + or plan skip_all => 'MONITORING_SGML is not set'; + +my $node = PostgreSQL::Test::Cluster->new('doc_phases'); +$node->init; +# one round of index vacuuming per small batch of dead tuples, so that VACUUM +# really goes back to "scanning heap" and the check has a loop to not trip on +$node->append_conf('postgresql.conf', 'maintenance_work_mem = 1024'); +# REPACK (CONCURRENTLY) refuses to run below "replica" +$node->append_conf('postgresql.conf', 'wal_level = replica'); +$node->start; + +$node->safe_psql('postgres', + q{CREATE TABLE phases_tab (a int primary key, b text)}); +$node->safe_psql('postgres', + q{INSERT INTO phases_tab SELECT g, repeat('y', 40) FROM generate_series(1, 200000) g}); +$node->safe_psql('postgres', q{CREATE INDEX phases_b ON phases_tab (b)}); +$node->safe_psql('postgres', q{DELETE FROM phases_tab}); + +my $doc = DocPhases::load($system_views, $monitoring); +ok(keys %$doc, 'found phase tables in the documentation'); + +my $spec = ProgressCheck::load_spec($ENV{PROGRESS_H}); + +my @commands = ( + [ 'VACUUM' => 'VACUUM phases_tab' ], + [ 'ANALYZE' => 'ANALYZE phases_tab' ], + [ 'CLUSTER' => 'CLUSTER phases_tab USING phases_tab_pkey' ], + [ 'CREATE INDEX CONCURRENTLY' => + 'CREATE INDEX CONCURRENTLY phases_c ON phases_tab (a)' ], + [ 'REPACK (CONCURRENTLY)' => 'REPACK (CONCURRENTLY) phases_tab' ], +); + +my @out_of_order; + +for my $c (@commands) +{ + my ($name, $sql) = @$c; + + my $offset = -s $node->logfile; + $node->safe_psql('postgres', $sql); + + my $contents = slurp_file($node->logfile, $offset); + my $trace = ProgressCheck::parse_log($contents); + + my %ran = ProgressCheck::commands_run($trace); + for my $command (sort keys %ran) + { + next unless defined $spec->{$command}{phase_param}; + + for my $phases (ProgressCheck::phases_of($trace, $spec, $command, undef)) + { + next unless @$phases; + + my @problems = + DocPhases::check_against_trace($doc, $command, $phases); + + # A value the view or the documentation does not know about is a + # plain bug: the three places have drifted apart. + my @undocumented = grep { $_->{kind} eq 'undocumented' } @problems; + is(scalar @undocumented, 0, + "$name: every phase $command reports is documented") + or diag($_->{detail}) for @undocumented; + + # A phase first reached out of the documented order means the + # table's row order is not the order of execution. That is a + # documentation bug, not a server one, so it is reported rather + # than failed, until the table is fixed. + push @out_of_order, $_->{detail} + for grep { $_->{kind} eq 'out_of_order' } @problems; + } + } +} + +my %seen; +my @unique = grep { !$seen{$_}++ } @out_of_order; +diag("documented order does not match execution order:\n " . join("\n ", @unique)) + if @unique; + +done_testing(); -- 2.55.0