Content-Type: multipart/alternative;
 boundary="------------iqwljct00uroWIpBw4jEEx2r"
Message-ID: <e1cf52d2-c344-4dfd-a918-e5f20ff04fa2@gmail.com>
Date: Fri, 13 Feb 2026 22:00:01 +0200
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Subject: Re: BUG: Former primary node might stuck when started as a standby
To: "Hayato Kuroda (Fujitsu)" <kuroda.hayato@fujitsu.com>
Cc: pgsql-hackers <pgsql-hackers@postgresql.org>,
 Aleksander Alekseev <aleksander@timescale.com>
References: <b0102688-6d6c-c86a-db79-e0e91d245b1a@gmail.com>
 <CAJ7c6TOqnv7cZ53RfBv9towSDzNOUVQ74WzPeN7LwoKMuW4tOA@mail.gmail.com>
 <74ea5e7e-9aa0-4d7a-85df-71a9d200a8d8@gmail.com>
 <CAJ7c6TO-_=rfN0Mb1RrChmrQvLtXoWw9aDezwC9g48-Va3E2EQ@mail.gmail.com>
 <180bf13e-235d-46a9-9788-7d6cee40bcdc@gmail.com>
 <OS9PR01MB12149E6917AAC1560150B918BF565A@OS9PR01MB12149.jpnprd01.prod.outlook.com>
 <cfd35cfb-3216-42b1-814b-cc658fd0f099@gmail.com>
 <OS9PR01MB12149C0F968A40BA54BD4C16FF561A@OS9PR01MB12149.jpnprd01.prod.outlook.com>
Content-Language: en-US
From: Alexander Lakhin <exclusion@gmail.com>
In-Reply-To: 
 <OS9PR01MB12149C0F968A40BA54BD4C16FF561A@OS9PR01MB12149.jpnprd01.prod.outlook.com>
Archived-At: 
 <https://www.postgresql.org/message-id/e1cf52d2-c344-4dfd-a918-e5f20ff04fa2%40gmail.com>
Precedence: bulk

This is a multi-part message in MIME format.
--------------iqwljct00uroWIpBw4jEEx2r
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit

Dear Kuroda-san,

13.02.2026 04:03, Hayato Kuroda (Fujitsu) wrote:
> Dear Alexander,
>
> I checked your test and reproduced the issue with it.
> Was it possible that INSERT happened in-between wait_for_replay_catchup and
> teardown_node? In this case we may not ensure WAL records generated in the time
> window were reached, right?
> Similar stuff won7t happen in 009_twophase.pl because it does not have the bg activities.

 From my old records, 009_twophase.pl failed exactly due to background (
namely, bgwriter's) activity.

I modified bgwriter.c to reproduce the failure easier:
--- a/src/backend/postmaster/bgwriter.c
+++ b/src/backend/postmaster/bgwriter.c
@@ -67,7 +67,7 @@ int            BgWriterDelay = 200;
   * Interval in which standby snapshots are logged into the WAL stream, in
   * milliseconds.
   */
-#define LOG_SNAPSHOT_INTERVAL_MS 15000
+#define LOG_SNAPSHOT_INTERVAL_MS 1

  /*
   * LSN and timestamp at which we last issued a LogStandbySnapshot(), to avoid
@@ -306,7 +306,7 @@ BackgroundWriterMain(const void *startup_data, size_t startup_data_len)
           */
          rc = WaitLatch(MyLatch,
                         WL_LATCH_SET | WL_TIMEOUT | WL_EXIT_ON_PM_DEATH,
-                       BgWriterDelay /* ms */ , WAIT_EVENT_BGWRITER_MAIN);
+                       1 /* ms */ , WAIT_EVENT_BGWRITER_MAIN);

          /*
           * If no latch event and BgBufferSync says nothing's happening, extend
@@ -339,6 +339,5 @@ BackgroundWriterMain(const void *startup_data, size_t startup_data_len)
              StrategyNotifyBgWriter(-1);
          }

-        prev_hibernate = can_hibernate;
      }
  }

multiplied the test to increase probability of the failure:
for i in {1..20}; do cp -r src/test/recovery/ src/test/recovery_$i/; sed "s|src/test/recovery|src/test/recovery_$i|" -i 
src/test/recovery_$i/Makefile; done

and executed it in a loop:
for i in {1..100}; do echo "ITERATION $i"; parallel --halt now,fail=1 -j20 --linebuffer --tag PROVE_TESTS="t/009*" 
NO_TEMP_INSTALL=1 timeout 60 make check -s -C src/test/recovery_{} ::: `seq 20` || break; done

It failed for me on iterations 27, 4, 22 as below:
ITERATION 22
...
18      t/009_twophase.pl .. ok
18      All tests successful.
18      Files=1, Tests=30, 12 wallclock secs ( 0.01 usr  0.01 sys + 0.26 cusr  0.58 csys =  0.86 CPU)
18      Result: PASS
5       make: *** wait: No child processes.  Stop.
5       make: *** Waiting for unfinished jobs....
5       make: *** wait: No child processes.  Stop.
parallel: This job failed:
PROVE_TESTS=t/009* NO_TEMP_INSTALL=1 timeout 60 make check -s -C src/test/recovery_5

src/test/recovery_5/tmp_check/log/009_twophase_london.log contains:
2026-02-13 21:03:28.248 EET [3987222] LOG:  new timeline 2 forked off current database system timeline 1 before current 
recovery point 0/3029190
...

(Without "timeout 60", the test just hangs — we can see the same in [1],
the test was killed with SIGTERM after 15000 seconds...)

[1] https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=skink&dt=2026-02-04%2013%3A36%3A40&stg=recovery-check

Best regards,
Alexander
--------------iqwljct00uroWIpBw4jEEx2r
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: 8bit

<!DOCTYPE html>
<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
  </head>
  <body>
    <div class="moz-cite-prefix">Dear Kuroda-san,<br>
      <br>
      13.02.2026 04:03, Hayato Kuroda (Fujitsu) wrote:<br>
    </div>
    <blockquote type="cite"
cite="mid:OS9PR01MB12149C0F968A40BA54BD4C16FF561A@OS9PR01MB12149.jpnprd01.prod.outlook.com">
      <pre wrap="" class="moz-quote-pre">Dear Alexander,

I checked your test and reproduced the issue with it.
Was it possible that INSERT happened in-between wait_for_replay_catchup and
teardown_node? In this case we may not ensure WAL records generated in the time
window were reached, right?
Similar stuff won7t happen in 009_twophase.pl because it does not have the bg activities.
</pre>
    </blockquote>
    <br>
    From my old records, 009_twophase.pl failed exactly due to
    background (<br>
    namely, bgwriter's) activity.<br>
    <br>
    I modified bgwriter.c to reproduce the failure easier:<br>
    --- a/src/backend/postmaster/bgwriter.c<br>
    +++ b/src/backend/postmaster/bgwriter.c<br>
    @@ -67,7 +67,7 @@ int            BgWriterDelay = 200;<br>
      * Interval in which standby snapshots are logged into the WAL
    stream, in<br>
      * milliseconds.<br>
      */<br>
    -#define LOG_SNAPSHOT_INTERVAL_MS 15000<br>
    +#define LOG_SNAPSHOT_INTERVAL_MS 1<br>
     <br>
     /*<br>
      * LSN and timestamp at which we last issued a
    LogStandbySnapshot(), to avoid<br>
    @@ -306,7 +306,7 @@ BackgroundWriterMain(const void *startup_data,
    size_t startup_data_len)<br>
              */<br>
             rc = WaitLatch(MyLatch,<br>
                            WL_LATCH_SET | WL_TIMEOUT |
    WL_EXIT_ON_PM_DEATH,<br>
    -                       BgWriterDelay /* ms */ ,
    WAIT_EVENT_BGWRITER_MAIN);<br>
    +                       1 /* ms */ , WAIT_EVENT_BGWRITER_MAIN);<br>
     <br>
             /*<br>
              * If no latch event and BgBufferSync says nothing's
    happening, extend<br>
    @@ -339,6 +339,5 @@ BackgroundWriterMain(const void *startup_data,
    size_t startup_data_len)<br>
                 StrategyNotifyBgWriter(-1);<br>
             }<br>
     <br>
    -        prev_hibernate = can_hibernate;<br>
         }<br>
     }<br>
    <br>
    multiplied the test to increase probability of the failure:<br>
    for i in {1..20}; do cp -r src/test/recovery/ src/test/recovery_$i/;
    sed "s|src/test/recovery|src/test/recovery_$i|" -i
    src/test/recovery_$i/Makefile; done<br>
    <br>
    and executed it in a loop:<br>
    for i in {1..100}; do echo "ITERATION $i"; parallel --halt
    now,fail=1 -j20 --linebuffer --tag PROVE_TESTS="t/009*"
    NO_TEMP_INSTALL=1 timeout 60 make check -s -C src/test/recovery_{}
    ::: `seq 20` || break; done<br>
    <br>
    It failed for me on iterations 27, 4, 22 as below:<br>
    ITERATION 22<br>
    ...<br>
    18      t/009_twophase.pl .. ok<br>
    18      All tests successful.<br>
    18      Files=1, Tests=30, 12 wallclock secs ( 0.01 usr  0.01 sys + 
    0.26 cusr  0.58 csys =  0.86 CPU)<br>
    18      Result: PASS<br>
    5       make: *** wait: No child processes.  Stop.<br>
    5       make: *** Waiting for unfinished jobs....<br>
    5       make: *** wait: No child processes.  Stop.<br>
    parallel: This job failed:<br>
    PROVE_TESTS=t/009* NO_TEMP_INSTALL=1 timeout 60 make check -s -C
    src/test/recovery_5<br>
    <br>
    src/test/recovery_5/tmp_check/log/009_twophase_london.log contains:<br>
    2026-02-13 21:03:28.248 EET [3987222] LOG:  new timeline 2 forked
    off current database system timeline 1 before current recovery point
    0/3029190<br>
    ...<br>
    <br>
    (Without "timeout 60", the test just hangs — we can see the same in
    [1],<br>
    the test was killed with SIGTERM after 15000 seconds...)<br>
    <br>
    [1]
<a class="moz-txt-link-freetext" href="https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=skink&amp;dt=2026-02-04%2013%3A36%3A40&amp;stg=recovery-check">https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=skink&amp;dt=2026-02-04%2013%3A36%3A40&amp;stg=recovery-check</a><br>
    <br>
    Best regards,<br>
    Alexander<br>
  </body>
</html>

--------------iqwljct00uroWIpBw4jEEx2r--