Thread

Commits

Same data as JSON: GET /api/v1/messages/:b64id/commits the thread's linked commits as JSON, with link sources. API reference →
  1. Lift shutdown assertion in pgstats for WAL senders

  1. BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    PG Bug reporting form <noreply@postgresql.org> — 2023-10-16T09:00:00Z

    The following bug has been logged on the website:
    
    Bug reference:      18158
    Logged by:          Alexander Lakhin
    Email address:      exclusion@gmail.com
    PostgreSQL version: 16.0
    Operating system:   Ubuntu 22.04
    Description:        
    
    When running check-world in a loop on a rather slow device, I observed
    an interesting case. All tests passed successfully, but in the system
    journal I found a message about postgres crash during the run.
    I reproduced the issue and found in src/test/recovery/tmp_check/log/
    012_subtransactions_primary.log:
    TRAP: failed Assert("!pgStatLocal.shmem->is_shutdown"), File: "pgstat.c",
    Line: 616, PID: 23770
    
    My analysis shows that this Assert failed in a backend (walsender, in my
    case) when it has pending stats entries on a server shutdown.
    In absence of such entries pgstat_report_stats() exits before the Assert:
    	/* Don't expend a clock check if nothing to do */
    	if (dlist_is_empty(&pgStatPending) &&
    		!have_iostats &&
    		!have_slrustats &&
    		!pgstat_have_pending_wal())
    	{
    		Assert(pending_since == 0);
    		return 0;
    	}
    	/*
    	 * There should never be stats to report once stats are shut down. Can't
    	 * assert that before the checks above, as there is an unconditional
    	 * pgstat_report_stat() call in pgstat_shutdown_hook() - which at least
    	 * the process that ran pgstat_before_server_shutdown() will still call.
    	 */
    	Assert(!pgStatLocal.shmem->is_shutdown);
    
    With the following modification in pgstat_flush_pending_entries():
    +if (nowait && (rand() % 10 == 0))
    +        did_flush = false;
    +else
    +{
             did_flush = kind_info->flush_pending_cb(entry_ref, nowait);
    +}
    
    the issue reproduced easily:
    make -s check -C src/test/recovery/ PROVE_TESTS="t/012_subtransactions.pl"
    grep TRAP -r src/test/recovery/tmp_check/log
    
    # +++ tap check in src/test/recovery +++
    t/012_subtransactions.pl .. ok    
    All tests successful.
    Files=1, Tests=12,  3 wallclock secs ( 0.01 usr  0.00 sys +  0.19 cusr  0.27
    csys =  0.47 CPU)
    Result: PASS
    src/test/recovery/tmp_check/log/012_subtransactions_primary.log:
    TRAP: failed Assert("!pgStatLocal.shmem->is_shutdown"), File: "pgstat.c",
    Line: 616, PID: 2410126
    
    The stack trace from the log:
    postgres: primary: walsender law [local] streaming
    0/3019C78(ExceptionalCondition+0xbb)[0x5616c7b58b89]
    postgres: primary: walsender law [local] streaming
    0/3019C78(pgstat_report_stat+0xef)[0x5616c7991ff1]
    postgres: primary: walsender law [local] streaming
    0/3019C78(+0x6a9e57)[0x5616c7991e57]
    postgres: primary: walsender law [local] streaming
    0/3019C78(shmem_exit+0xa6)[0x5616c792d852]
    postgres: primary: walsender law [local] streaming
    0/3019C78(+0x6456f6)[0x5616c792d6f6]
    postgres: primary: walsender law [local] streaming
    0/3019C78(proc_exit+0x19)[0x5616c792d63a]
    postgres: primary: walsender law [local] streaming
    0/3019C78(+0x607cec)[0x5616c78efcec]
    postgres: primary: walsender law [local] streaming
    0/3019C78(+0x606e47)[0x5616c78eee47]
    postgres: primary: walsender law [local] streaming
    0/3019C78(+0x6043c8)[0x5616c78ec3c8]
    postgres: primary: walsender law [local] streaming
    0/3019C78(exec_replication_command+0x4cc)[0x5616c78edfa5]
    postgres: primary: walsender law [local] streaming
    0/3019C78(PostgresMain+0x7df)[0x5616c796d54b]
    ...
    
    
  2. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Alexander Lakhin <exclusion@gmail.com> — 2026-05-12T20:00:00Z

    Hello hackers,
    
    16.10.2023 12:00, PG Bug reporting form wrote:
    > The following bug has been logged on the website:
    >
    > Bug reference:      18158
    > Logged by:          Alexander Lakhin
    > Email address:exclusion@gmail.com
    > PostgreSQL version: 16.0
    > Operating system:   Ubuntu 22.04
    > Description:
    > ...
    > With the following modification in pgstat_flush_pending_entries():
    > +if (nowait && (rand() % 10 == 0))
    > +        did_flush = false;
    > +else
    > +{
    >           did_flush = kind_info->flush_pending_cb(entry_ref, nowait);
    > +}
    >
    > the issue reproduced easily:
    > make -s check -C src/test/recovery/ PROVE_TESTS="t/012_subtransactions.pl"
    > grep TRAP -r src/test/recovery/tmp_check/log
    >
    > # +++ tap check in src/test/recovery +++
    > t/012_subtransactions.pl .. ok
    > All tests successful.
    > Files=1, Tests=12,  3 wallclock secs ( 0.01 usr  0.00 sys +  0.19 cusr  0.27
    > csys =  0.47 CPU)
    > Result: PASS
    > src/test/recovery/tmp_check/log/012_subtransactions_primary.log:
    > TRAP: failed Assert("!pgStatLocal.shmem->is_shutdown"), File: "pgstat.c",
    > Line: 616, PID: 2410126
    
    It looks like skink produced this failure yesterday [1]:
    241/316 recovery - postgresql:recovery/027_stream_regress ERROR           4374.08s   exit status 1
    ...
    stderr:
    #   Failed test 'check contents of pg_stat_statements on regression database'
    #   at /home/bf/bf-build/skink/REL_17_STABLE/pgsql/src/test/recovery/t/027_stream_regress.pl line 177.
    #          got: 'CREATE|f
    # SELECT|t'
    #     expected: 'CREATE|t
    # DELETE|t
    # INSERT|t
    # SELECT|t
    # UPDATE|t'
    # Looks like you failed 1 test of 9.
    
      pgsql.build/testrun/recovery/027_stream_regress/log/027_stream_regress_primary.log
    
    2026-05-11 14:09:34.397 CEST [4064132][walsender][40/0:0] LOG: released physical replication slot "standby_1"
    TRAP: failed Assert("!pgStatLocal.shmem->is_shutdown"), File: "../pgsql/src/backend/utils/activity/pgstat.c", Line: 612, 
    PID: 4064132
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(ExceptionalCondition+0x5f) [0x45ae268]
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(pgstat_report_stat+0x14d) [0x4492fe2]
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(+0x49315c) [0x449315c]
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(shmem_exit+0x78) [0x4448f00]
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(+0x449020) [0x4449020]
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(proc_exit+0x22) [0x44490c1]
    postgres: primary: walsender bf [local] streaming 0/15B4FC98(+0x3f5dbd) [0x43f5dbd]
    ...
    2026-05-11 14:09:34.629 CEST [4063470][postmaster][:0] LOG:  server process (PID 4064132) was terminated by signal 6: 
    Aborted
    2026-05-11 14:09:34.629 CEST [4063470][postmaster][:0] DETAIL: Failed process was running: START_REPLICATION SLOT 
    "standby_1" 0/3000000 TIMELINE 1
    2026-05-11 14:09:34.631 CEST [4063470][postmaster][:0] LOG: terminating any other active server processes
    
    And perhaps (I can't find the full log now) one year ago [2]:
    227/305 postgresql:recovery / recovery/027_stream_regress ERROR           3364.50s   exit status 1
    
    [01:19:39.781](0.108s) not ok 9 - check contents of pg_stat_statements on regression database
    [01:19:39.781](0.000s) #   Failed test 'check contents of pg_stat_statements on regression database'
    #   at /home/bf/bf-build/skink/REL_17_STABLE/pgsql/src/test/recovery/t/027_stream_regress.pl line 173.
    [01:19:39.781](0.000s) #          got: 'CREATE|f
    # SELECT|t'
    #     expected: 'CREATE|t
    # DELETE|t
    # INSERT|t
    # SELECT|t
    # UPDATE|t'
    
    I've reproduced such failures with the above modification applied, just
    running:
    for i in {1..20}; do PROVE_TESTS="t/027*" make -s check -C src/test/recovery/ || break; done
    
    Reproduced on REL_17_STABLE and REL_16_STABLE (starting from dd8008e8e,
    which updated 027_stream_regress.pl).
    
    Not reproduced on REL_18_STABLE after 87a6690cc (coming from [3]).
    
    [1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2026-05-11%2010%3A25%3A22
    [2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2025-03-18%2023%3A39%3A44
    [3] https://www.postgresql.org/message-id/yegnemsijlrhocsfgs7gs7irnczjgkom6fmk2a5u2b66pbvzwi%40ph2h3wppcvdy
    
    Best regards,
    Alexander
  3. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Xuneng Zhou <xunengzhou@gmail.com> — 2026-05-13T00:46:25Z

    Hi Alexander,
    
    On Wed, May 13, 2026 at 4:00 AM Alexander Lakhin <exclusion@gmail.com> wrote:
    >
    > Hello hackers,
    >
    > 16.10.2023 12:00, PG Bug reporting form wrote:
    >
    > The following bug has been logged on the website:
    >
    > Bug reference:      18158
    > Logged by:          Alexander Lakhin
    > Email address:      exclusion@gmail.com
    > PostgreSQL version: 16.0
    > Operating system:   Ubuntu 22.04
    > Description:
    > ...
    > With the following modification in pgstat_flush_pending_entries():
    > +if (nowait && (rand() % 10 == 0))
    > +        did_flush = false;
    > +else
    > +{
    >          did_flush = kind_info->flush_pending_cb(entry_ref, nowait);
    > +}
    >
    > the issue reproduced easily:
    > make -s check -C src/test/recovery/ PROVE_TESTS="t/012_subtransactions.pl"
    > grep TRAP -r src/test/recovery/tmp_check/log
    >
    > # +++ tap check in src/test/recovery +++
    > t/012_subtransactions.pl .. ok
    > All tests successful.
    > Files=1, Tests=12,  3 wallclock secs ( 0.01 usr  0.00 sys +  0.19 cusr  0.27
    > csys =  0.47 CPU)
    > Result: PASS
    > src/test/recovery/tmp_check/log/012_subtransactions_primary.log:
    > TRAP: failed Assert("!pgStatLocal.shmem->is_shutdown"), File: "pgstat.c",
    > Line: 616, PID: 2410126
    >
    >
    > It looks like skink produced this failure yesterday [1]:
    > 241/316 recovery - postgresql:recovery/027_stream_regress                               ERROR           4374.08s   exit status 1
    > ...
    > stderr:
    > #   Failed test 'check contents of pg_stat_statements on regression database'
    > #   at /home/bf/bf-build/skink/REL_17_STABLE/pgsql/src/test/recovery/t/027_stream_regress.pl line 177.
    > #          got: 'CREATE|f
    > # SELECT|t'
    > #     expected: 'CREATE|t
    > # DELETE|t
    > # INSERT|t
    > # SELECT|t
    > # UPDATE|t'
    > # Looks like you failed 1 test of 9.
    >
    >  pgsql.build/testrun/recovery/027_stream_regress/log/027_stream_regress_primary.log
    >
    > 2026-05-11 14:09:34.397 CEST [4064132][walsender][40/0:0] LOG:  released physical replication slot "standby_1"
    > TRAP: failed Assert("!pgStatLocal.shmem->is_shutdown"), File: "../pgsql/src/backend/utils/activity/pgstat.c", Line: 612, PID: 4064132
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(ExceptionalCondition+0x5f) [0x45ae268]
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(pgstat_report_stat+0x14d) [0x4492fe2]
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(+0x49315c) [0x449315c]
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(shmem_exit+0x78) [0x4448f00]
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(+0x449020) [0x4449020]
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(proc_exit+0x22) [0x44490c1]
    > postgres: primary: walsender bf [local] streaming 0/15B4FC98(+0x3f5dbd) [0x43f5dbd]
    > ...
    > 2026-05-11 14:09:34.629 CEST [4063470][postmaster][:0] LOG:  server process (PID 4064132) was terminated by signal 6: Aborted
    > 2026-05-11 14:09:34.629 CEST [4063470][postmaster][:0] DETAIL:  Failed process was running: START_REPLICATION SLOT "standby_1" 0/3000000 TIMELINE 1
    > 2026-05-11 14:09:34.631 CEST [4063470][postmaster][:0] LOG:  terminating any other active server processes
    >
    > And perhaps (I can't find the full log now) one year ago [2]:
    > 227/305 postgresql:recovery / recovery/027_stream_regress                               ERROR           3364.50s   exit status 1
    >
    > [01:19:39.781](0.108s) not ok 9 - check contents of pg_stat_statements on regression database
    > [01:19:39.781](0.000s) #   Failed test 'check contents of pg_stat_statements on regression database'
    > #   at /home/bf/bf-build/skink/REL_17_STABLE/pgsql/src/test/recovery/t/027_stream_regress.pl line 173.
    > [01:19:39.781](0.000s) #          got: 'CREATE|f
    > # SELECT|t'
    > #     expected: 'CREATE|t
    > # DELETE|t
    > # INSERT|t
    > # SELECT|t
    > # UPDATE|t'
    >
    > I've reproduced such failures with the above modification applied, just
    > running:
    > for i in {1..20}; do PROVE_TESTS="t/027*" make -s check -C src/test/recovery/ || break; done
    >
    > Reproduced on REL_17_STABLE and REL_16_STABLE (starting from dd8008e8e,
    > which updated 027_stream_regress.pl).
    >
    > Not reproduced on REL_18_STABLE after 87a6690cc (coming from [3]).
    >
    > [1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2026-05-11%2010%3A25%3A22
    > [2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2025-03-18%2023%3A39%3A44
    > [3] https://www.postgresql.org/message-id/yegnemsijlrhocsfgs7gs7irnczjgkom6fmk2a5u2b66pbvzwi%40ph2h3wppcvdy
    >
    > Best regards,
    > Alexander
    
    Thanks for reporting this. It appears like backpatching an equivalent
    of 87a6690cc69 to REL_17/REL_16 would resolve this issue.
    
    --
    Regards,
    Xuneng Zhou
    HighGo Software Co., Ltd.
    
    
    
    
  4. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Michael Paquier <michael@paquier.xyz> — 2026-05-13T06:55:32Z

    On Wed, May 13, 2026 at 08:46:25AM +0800, Xuneng Zhou wrote:
    > Thanks for reporting this. It appears like backpatching an equivalent
    > of 87a6690cc69 to REL_17/REL_16 would resolve this issue.
    
    FWIW, I fear such a change in the stable branches based on its
    invasiveness, particularly because the area of the code dealing with
    shutdown sequences has been reworked a lot lately as far as I recall.
    
    I am seriously wondering if we should just let it go and remove the
    assertion on v15~v17.  It's not perfect, of course, but I value much
    more this assertion in terms of any future work that can be done with
    pgstats, not in terms of what we could detect for bug fixes.
    --
    Michael
    
  5. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Xuneng Zhou <xunengzhou@gmail.com> — 2026-05-14T07:19:34Z

    On Wed, May 13, 2026 at 2:55 PM Michael Paquier <michael@paquier.xyz> wrote:
    >
    > On Wed, May 13, 2026 at 08:46:25AM +0800, Xuneng Zhou wrote:
    > > Thanks for reporting this. It appears like backpatching an equivalent
    > > of 87a6690cc69 to REL_17/REL_16 would resolve this issue.
    >
    > FWIW, I fear such a change in the stable branches based on its
    > invasiveness, particularly because the area of the code dealing with
    > shutdown sequences has been reworked a lot lately as far as I recall.
    >
    > I am seriously wondering if we should just let it go and remove the
    > assertion on v15~v17.  It's not perfect, of course, but I value much
    > more this assertion in terms of any future work that can be done with
    > pgstats, not in terms of what we could detect for bug fixes.
    
    I agree that applying the change wholesale could be too invasive. If
    we decide not to address the ordering issue, removing this assertion
    seems reasonable, since the non-assert path does not actually provide
    the required guarantee.
    
    -- 
    Regards,
    Xuneng Zhou
    HighGo Software Co., Ltd.
    
    
    
    
  6. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Michael Paquier <michael@paquier.xyz> — 2026-06-05T02:14:31Z

    On Thu, May 14, 2026 at 03:19:34PM +0800, Xuneng Zhou wrote:
    > I agree that applying the change wholesale could be too invasive. If
    > we decide not to address the ordering issue, removing this assertion
    > seems reasonable, since the non-assert path does not actually provide
    > the required guarantee.
    
    Attached is a patch for 15~17 that is able to achieve this goal:
    - Lift the assertion on shutdown for WAL senders, but keep it
    everywhere else.
    - Secondary trick in pgstat_shutdown_hook to cope with the fact that
    some stats make still be around at shutdown for a WAL sender.
    
    I cannot reproduce the failure re-using the trick sent by Alexander at
    the top of the thread.
    
    Thoughts or objections?
    --
    Michael
    
  7. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Alexander Lakhin <exclusion@gmail.com> — 2026-06-05T05:00:00Z

    Hello Michael,
    
    05.06.2026 05:14, Michael Paquier wrote:
    > On Thu, May 14, 2026 at 03:19:34PM +0800, Xuneng Zhou wrote:
    >> I agree that applying the change wholesale could be too invasive. If
    >> we decide not to address the ordering issue, removing this assertion
    >> seems reasonable, since the non-assert path does not actually provide
    >> the required guarantee.
    > Attached is a patch for 15~17 that is able to achieve this goal:
    > - Lift the assertion on shutdown for WAL senders, but keep it
    > everywhere else.
    > - Secondary trick in pgstat_shutdown_hook to cope with the fact that
    > some stats make still be around at shutdown for a WAL sender.
    >
    > I cannot reproduce the failure re-using the trick sent by Alexander at
    > the top of the thread.
    
    Please try the following:
    --- a/src/backend/utils/activity/pgstat.c
    +++ b/src/backend/utils/activity/pgstat.c
    @@ -107,2 +107,3 @@
    
    +#include "common/pg_prng.h"
    
    @@ -1212,3 +1213,8 @@ pgstat_flush_pending_entries(bool nowait)
              /* flush the stats, if possible */
    +if (nowait && (pg_prng_double(&pg_global_prng_state) < 0.1))
    +        did_flush = false;
    +else
    +{
              did_flush = kind_info->flush_pending_cb(entry_ref, nowait);
    +}
    
    As far as I can see, that rand() gives the same sequence on macOS each run,
    while on Linux I see different sequences.
    
    The patch works for me test-wise.
    
    Thank you for the fix!
    
    Best regards,
    Alexander
    
    
    
    
  8. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Michael Paquier <michael@paquier.xyz> — 2026-06-05T05:03:53Z

    On Fri, Jun 05, 2026 at 08:00:00AM +0300, Alexander Lakhin wrote:
    > As far as I can see, that rand() gives the same sequence on macOS each run,
    > while on Linux I see different sequences.
    
    Aye.  I have used that before sending the patch, reproducing the
    failure before-patch, getting things to work after-patch.
    --
    Michael
    
  9. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Michael Paquier <michael@paquier.xyz> — 2026-06-06T00:13:44Z

    On Fri, Jun 05, 2026 at 08:00:00AM +0300, Alexander Lakhin wrote:
    > Thank you for the fix!
    
    Applied as of 4801610f7c66 in the v15~17 range.
    --
    Michael
    
  10. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Xuneng Zhou <xunengzhou@gmail.com> — 2026-06-06T12:45:26Z

    Hi Michael,
    
    On Sat, Jun 6, 2026 at 8:13 AM Michael Paquier <michael@paquier.xyz> wrote:
    >
    > On Fri, Jun 05, 2026 at 08:00:00AM +0300, Alexander Lakhin wrote:
    > > Thank you for the fix!
    >
    > Applied as of 4801610f7c66 in the v15~17 range.
    
    Sorry for being late. One nit for the patch -- would it be better to
    use AmWalSenderProcess() for identification to save the include?
    +#include "replication/walsender.h"
    
    --
    Regards,
    Xuneng Zhou
    HighGo Software Co., Ltd.
    
    
    
    
  11. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Michael Paquier <michael@paquier.xyz> — 2026-06-08T05:48:55Z

    On Sat, Jun 06, 2026 at 08:45:26PM +0800, Xuneng Zhou wrote:
    > Sorry for being late. One nit for the patch -- would it be better to
    > use AmWalSenderProcess() for identification to save the include?
    > +#include "replication/walsender.h"
    
    In the startup sequence, MyBackendType is updated to B_WAL_SENDER a
    couple of lines after am_walsender.  One or the other don't really
    matter; they're both right.
    --
    Michael
    
  12. Re: BUG #18158: Assert in pgstat_report_stat() fails when a backend shutting down with stats pending

    Xuneng Zhou <xunengzhou@gmail.com> — 2026-06-08T08:43:31Z

    On Mon, Jun 8, 2026 at 1:49 PM Michael Paquier <michael@paquier.xyz> wrote:
    >
    > On Sat, Jun 06, 2026 at 08:45:26PM +0800, Xuneng Zhou wrote:
    > > Sorry for being late. One nit for the patch -- would it be better to
    > > use AmWalSenderProcess() for identification to save the include?
    > > +#include "replication/walsender.h"
    >
    > In the startup sequence, MyBackendType is updated to B_WAL_SENDER a
    > couple of lines after am_walsender.  One or the other don't really
    > matter; they're both right.
    
    Yeah, both of them work well.  To use AmWalSenderProcess(), we would
    need to include src/include/miscadmin.h, whereas using am_walsender
    requires including “replication/walsender.h”. I’m just wondering
    whether using AmWalSenderProcess() would result in less coupling
    between pgstat and replication.
    
    
    --
    Regards,
    Xuneng Zhou
    HighGo Software Co., Ltd.