Reduce logging during prepared transaction recovery - Mailing list pgsql-hackers

From Ashutosh Sharma
Subject Reduce logging during prepared transaction recovery
Date
Msg-id CAE9k0Pmq1qQEvTKqsBTwUAWrNw+191zcTBPVKmmP5E3X2C+_Xw@mail.gmail.com
Whole thread
List pgsql-hackers
Hi,

RecoverPreparedTransactions() currently emits one LOG message for
every prepared transaction restored at the end of recovery.

With many unresolved prepared transactions, this produces substantial
log output during promotion. Writing these messages can also delay
completion of recovery.

This patch moves the per-transaction message from LOG to DEBUG1. The
transaction ID and epoch remain available when detailed logging is
enabled. After recovery, one LOG message reports the total number of
successfully recovered prepared transactions.

For example:

    LOG:  recovered 50000 prepared transactions

I performed preliminary tests using a physical standby and empty
prepared transactions on my local VM and here are the results that I
could see:

    Prepared xacts    Without patch    With patch    Time saved
    ---------------      ------------    -----------------------    ----------
         10,000          1.544 s         0.615 s                 0.929 s
         25,000          3.936 s         2.433 s                 1.503 s
         50,000          9.788 s         6.263 s                 3.525 s

The patched version reduced recovery time in both tests while avoiding
thousands of repetitive LOG messages.

The patch does not change prepared transaction recovery or on disk state.

Transaction level diagnostics remain available with log_min_messages = debug1.

Please take a look at the attached patch and let me know your
thoughts. I have also attached the test-script I used to create
prepared transactions for the test results shown above.

The test scripts can be used as follows:

./create_prepared_transactions.sh <prepared_transactions_count> <primary_port>

--
With Regards,
Ashutosh Sharma.

Attachment

pgsql-hackers by date:

Previous
From: Alvaro Herrera
Date:
Subject: Re: REPACK (CONCURRENTLY) can't complete after ~105M concurrent updates/deletes
Next
From: Nitin Jadhav
Date:
Subject: Re: Disable startup progress timeout during standby WAL replay