From a9e98d2d98277236bbcd03c4ef58b25ddace7ce6 Mon Sep 17 00:00:00 2001 From: Ashutosh Sharma Date: Thu, 29 Oct 2026 05:21:03 +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 DEBUG2. 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 Reviewed-by: Chao Li --- src/backend/access/transam/twophase.c | 16 ++++++++++++---- src/test/recovery/t/009_twophase.pl | 15 +++++++++++++-- 2 files changed, 25 insertions(+), 6 deletions(-) diff --git a/src/backend/access/transam/twophase.c b/src/backend/access/transam/twophase.c index 48a83501ee9..dd236b06a14 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,10 +2147,9 @@ RecoverPreparedTransactions(void) if (buf == NULL) continue; - ereport(LOG, - (errmsg("recovering prepared transaction %u of epoch %u from shared memory", - XidFromFullTransactionId(gxact->fxid), - EpochFromFullTransactionId(gxact->fxid)))); + elog(DEBUG2, "recovering prepared transaction %u of epoch %u from shared memory", + XidFromFullTransactionId(gxact->fxid), + EpochFromFullTransactionId(gxact->fxid)); hdr = (TwoPhaseFileHeader *) buf; Assert(TransactionIdEquals(hdr->xid, @@ -2201,11 +2201,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