From 93af6507fbdae3aba27bf61294b0c9a26a8e9f60 Mon Sep 17 00:00:00 2001 From: Ashutosh Sharma Date: Wed, 7 Oct 2026 06:39:02 +0000 Subject: [PATCH] Reduce logging during prepared transaction recovery Logging every prepared transaction at LOG level can produce a large amount of output and delay the end of recovery when many prepared transactions remain unresolved. Keep transaction-level details available at DEBUG1. Emit one LOG message reporting the number of successfully recovered transactions, only when at least one transaction was recovered. Extend the two-phase recovery TAP tests to check the absence of a summary when no transactions are recovered, singular and plural summaries after promotion and restart, and the absence of per-transaction messages at LOG level. Reviewed-by: Jakub Wartak Reviewed-by: Fujii Masao Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- src/backend/access/transam/twophase.c | 11 ++++++++++- src/test/recovery/t/009_twophase.pl | 15 +++++++++++++-- 2 files changed, 23 insertions(+), 3 deletions(-) diff --git a/src/backend/access/transam/twophase.c b/src/backend/access/transam/twophase.c index 48a83501ee9..ed7c4acbbe3 100644 --- a/src/backend/access/transam/twophase.c +++ b/src/backend/access/transam/twophase.c @@ -2119,6 +2119,7 @@ void RecoverPreparedTransactions(void) { int i; + int recovered_xacts = 0; LWLockAcquire(TwoPhaseStateLock, LW_EXCLUSIVE); for (i = 0; i < TwoPhaseState->numPrepXacts; i++) @@ -2146,7 +2147,7 @@ RecoverPreparedTransactions(void) if (buf == NULL) continue; - ereport(LOG, + ereport(DEBUG1, (errmsg("recovering prepared transaction %u of epoch %u from shared memory", XidFromFullTransactionId(gxact->fxid), EpochFromFullTransactionId(gxact->fxid)))); @@ -2201,11 +2202,19 @@ RecoverPreparedTransactions(void) PostPrepare_Twophase(); pfree(buf); + recovered_xacts++; LWLockAcquire(TwoPhaseStateLock, LW_EXCLUSIVE); } LWLockRelease(TwoPhaseStateLock); + + if (recovered_xacts > 0) + ereport(LOG, + (errmsg_plural("recovered %d prepared transaction", + "recovered %d prepared transactions", + recovered_xacts, + recovered_xacts))); } /* diff --git a/src/test/recovery/t/009_twophase.pl b/src/test/recovery/t/009_twophase.pl index aa73d3e106c..aedb4c279dc 100644 --- a/src/test/recovery/t/009_twophase.pl +++ b/src/test/recovery/t/009_twophase.pl @@ -39,6 +39,10 @@ $node_london->append_conf( log_checkpoints = true )); $node_london->start; +$node_london->log_check( + 'No prepared transactions at startup', + 0, + log_unlike => [qr/LOG: recovered \d+ prepared transaction/]); $node_london->backup('london_backup'); # Setup paris node @@ -82,8 +86,9 @@ $cur_primary->psql( SAVEPOINT s1; INSERT INTO t_009_tbl VALUES (4, 'issued to ${cur_primary_name}'); PREPARE TRANSACTION 'xact_009_2';"); -$cur_primary->stop; -$cur_primary->start; +$cur_primary->restart( + log_like => qr/LOG: recovered 2 prepared transactions\r?$/m, + log_unlike => qr/LOG: recovering prepared transaction /); $psql_rc = $cur_primary->psql('postgres', "COMMIT PREPARED 'xact_009_1'"); is($psql_rc, '0', 'Commit prepared transaction after restart'); @@ -223,6 +228,7 @@ $cur_primary->psql( INSERT INTO t_009_tbl VALUES (22, 'issued to ${cur_primary_name}'); PREPARE TRANSACTION 'xact_009_10';"); $cur_primary->stop; +my $log_offset = -s $cur_standby->logfile; $cur_standby->promote; # change roles @@ -235,6 +241,11 @@ $cur_primary_name = $cur_primary->name; $psql_rc = $cur_primary->psql('postgres', "SET synchronous_commit = off; COMMIT PREPARED 'xact_009_10'"); is($psql_rc, '0', "Restore of prepared transaction on promoted standby"); +$cur_primary->log_check( + 'Prepared transaction recovery logging after promotion', + $log_offset, + log_like => [qr/LOG: recovered 1 prepared transaction\r?$/m], + log_unlike => [qr/LOG: recovering prepared transaction /]); # restart old primary as new standby $cur_standby->enable_streaming($cur_primary); -- 2.43.0