hang during shutdown

Hi Jeremy,

On Mon, Jul 6, 2026 at 3:25 AM Jeremy Schneider <schneider@ardentperf.com>
wrote:

i recently saw a hung shutdown on a busy multi-TB production database. the
hung shutdown had some unexpected downstream impacts unrelated to core
postgres which turned a routine maintenance operation into a long dramatic
overnight incident... blowing way past our planned maint window and
spoiling my weekend... but that's another story and mainly just explains my
stubborn persistence slowly following the dominoes backwards over this past
month. :)

sorry for ruining your weekend ;)

so far, it all started with this postgres hang during a shutdown. we didnt
capture enough diagnostics to root-cause the domino before the hang, but
the data i do have about this postgres hang is very peculiar. i'm working
on some automation to gather more diagnostics if there is a recurrence. in
the meantime i wanted to share what i do know, in case anyone else has seen
something similar.

postgres version 16.13
Ubuntu 22.04.5 LTS
kernel 5.15.0-1110-azure

between log messages and wal contents, it appears PostmasterStateMachine
transitioned into PM_WAIT_BACKENDS but never progressed beyond this for a
full 30 minutes until external automation finally killed the processes. i
think the evidence most strongly supports the idea that an autovacuum
worker was somehow wedged, but no idea where it possibly could have been
stuck. app was shut down before maint started, at hang time there were only
three open "postgres" user connections from platform automation.

here's what i have:

04:24:07 wal checkpoint. two in-progress autovacs, one is writing
FREEZE_PAGE and VISIBLE records, AI tells me this requires an xid.
RUNNING_XACTS shows single open xact 2121426339 - this must belong to the
autovac doing freeze & visibility.

04:25:09.403 immediate checkpoint (explicit from automation), same running
xid

04:25:09.808 pg logs the fast shutdown req (pg_ctl stop -m fast from
automation)

04:25:09.815 both autovac workers log "terminating autovacuum process":
die() -> ProcessInterrupts() -> ereport()

04:30:09 XLOG_SWITCH and archiver uploads segment 0x30

04:30:10 checkpooint_timeout=300s fires, 72 dirty buffers written.
RUNNING_XACTS at this time shows xid 2121426339 is still open.

04:35:10 XLOG_SWITCH and archiver uploads segment 0x31

04:55:08 external automation SIGKILL

based on the fact that we saw checkpoints and archivals a full 10 minutes
later, that's why i think it never left PM_WAIT_BACKENDS. also, there was
never any XLOG_CHECKPOINT_SHUTDOWN record or any XLOG_XACT_ABORT record
written in the whole 30 minutes.

AI tells me autovac process needs to call AbortTransaction() which calls
ProcArrayEndTransaction() to remove xid from PGPROC and also calls
RecordTransactionAbort() which should write the abort WAL record. neither
of these happen, which suggests autovac was stuck after it logs its
termination message and before it performs either of these actions. this is
not a lot of code, and my AI couldnt find any obvious places where theres
disk or network calls or anything else that could hang.

successful checkpoints suggest that both the data and the wal disks were
accepting writes, and IO was not hung on the whole. if there was a D-state
hang then it would have been just one process, while others on same device
did not hang.

your autovac analysis makes sense, i think that after worker's fatal ->
proc_exit(1)->
proc_exit_prepare->calls a shmem_exit and stuck there, maybe because
of any extension's shmem callback, idk, it would be awesome if you
get the backtrace using gdb by connecting to the PID of autovacuum
which got stuck , if it was not stuck then it goes to the ShutdownPostgres ,
a InitPostgres before_shmem_exit callback and would have called
AbortTransaction and write the WAL record, which is not the case as
you mentioned.

--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/

Hi,

On Sun, Jul 5, 2026 at 11:55 PM Jeremy Schneider
<schneider@ardentperf.com> wrote:

so far, it all started with this postgres hang during a shutdown. we didnt capture enough diagnostics to root-cause the domino before the hang, but the data i do have about this postgres hang is very peculiar. i'm working on some automation to gather more diagnostics if there is a recurrence. in the meantime i wanted to share what i do know, in case anyone else has seen something similar.

postgres version 16.13
Ubuntu 22.04.5 LTS
kernel 5.15.0-1110-azure

between log messages and wal contents, it appears PostmasterStateMachine transitioned into PM_WAIT_BACKENDS but never progressed beyond this for a full 30 minutes until external automation finally killed the processes.

Did you have an active logical replication stream at the time of the
shutdown? If so, it's very likely due to a bug in the logical
walsender that can be stuck in an infinite loop when the WAL is in a
specific state (last record is a rollback crossing the WAL page
boundary).

A fix for that was released in the latest 16.14 minor release[0]https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=82935467a.

[0]: https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=82935467a

Regards,
Anthonin Bonnefoy

On Mon, Jul 6, 2026 at 8:30 AM Anthonin Bonnefoy
<anthonin.bonnefoy@datadoghq.com> wrote:

Hi,

On Sun, Jul 5, 2026 at 11:55 PM Jeremy Schneider
<schneider@ardentperf.com> wrote:

so far, it all started with this postgres hang during a shutdown. we didnt capture enough diagnostics to root-cause the domino before the hang, but the data i do have about this postgres hang is very peculiar. i'm working on some automation to gather more diagnostics if there is a recurrence. in the meantime i wanted to share what i do know, in case anyone else has seen something similar.

postgres version 16.13
Ubuntu 22.04.5 LTS
kernel 5.15.0-1110-azure

between log messages and wal contents, it appears PostmasterStateMachine transitioned into PM_WAIT_BACKENDS but never progressed beyond this for a full 30 minutes until external automation finally killed the processes.

Did you have an active logical replication stream at the time of the
shutdown? If so, it's very likely due to a bug in the logical
walsender[..]

Aren't walsenders in general problematic for shutdowns? (not just logical, of
course it might be this). The PG 19 is going to have
wal_sender_shutdown_timeout, and from description it seems to match [0]https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=a8f45dee91768cf1447ffaf2527e499e75a194c3 to
something like that. 'netstat -ntpo' would help to see from such hanged
system (if walsenders running there at this point at all).

-J.

[0]: https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=a8f45dee91768cf1447ffaf2527e499e75a194c3

On Mon, 6 Jul 2026 14:42:10 +0200
Jakub Wartak <jakub.wartak@enterprisedb.com> wrote:

On Mon, Jul 6, 2026 at 8:30 AM Anthonin Bonnefoy
<anthonin.bonnefoy@datadoghq.com> wrote:

Hi,

On Sun, Jul 5, 2026 at 11:55 PM Jeremy Schneider
<schneider@ardentperf.com> wrote:

Did you have an active logical replication stream at the time of the
shutdown? If so, it's very likely due to a bug in the logical
walsender[..]

Aren't walsenders in general problematic for shutdowns? (not just
logical, of course it might be this). The PG 19 is going to have
wal_sender_shutdown_timeout, and from description it seems to match
[0] to something like that. 'netstat -ntpo' would help to see from
such hanged system (if walsenders running there at this point at all).

Between log messages and wal contents, it appears
PostmasterStateMachine transitioned into PM_WAIT_BACKENDS but never
progressed beyond this. I don't think walsenders are involved until it
transitions into PM_WAIT_XLOG_SHUTDOWN which doesn't start until after
the shutdown checkpoint (which never arrived in the wal).

I remain pretty stumped :)

I have put some code together that can automatically capture cmdline,
comm, status, wchan, io, syscall, stack and sched from /proc for every
single process in the postgres namespace/container. If privs are
missing (stack is probably usually blocked) then it'll still capture
other files. My initial prototype does three captures, with 3 seconds
in between each. This can help determine whether processes or stuck or
slow.

I'm still figuring out how to trigger it at the right time, because the
SIGKILL was triggered by terminationGracePeriodSeconds on kubernetes. I
didn't find an obvious way to just run diag at the end (I think preStop
hook fires at the beginning). I'll figure something out.

-Jeremy

--
To know the thoughts and deeds that have marked man's progress is to
feel the great heart throbs of humanity through the centuries; and if
one does not feel in these pulsations a heavenward striving, one must
indeed be deaf to the harmonies of life.

Helen Keller, The Story Of My Life, 1902, 1903, 1905, introduction by
Ralph Barton Perry (Garden City, NY: Doubleday & Company, 1954), p90.

On Thu, Jul 9, 2026 at 4:49 AM Jeremy Schneider
<schneider@ardentperf.com> wrote:

Between log messages and wal contents, it appears
PostmasterStateMachine transitioned into PM_WAIT_BACKENDS but never
progressed beyond this. I don't think walsenders are involved until it
transitions into PM_WAIT_XLOG_SHUTDOWN which doesn't start until after
the shutdown checkpoint (which never arrived in the wal).

I remain pretty stumped :)

The walsender logical bug happens when pmState is in PM_SHUTDOWN,
after sending a SIGUSR2 to the checkpointer.
The checkpointer then asks the walsender to stop through
WalSndInitStopping() in ShutdownXLOG and wait for them to finish,
before creating the shutdown checkpoint. If the walsender is stuck in
an infinite loop, the shutdown sequence is stuck in this state.

As you didn't have a shutdown checkpoint, the symptoms look very
similar (though you didn't confirm whether you were using logical
replication, so I'm gonna assume you do).

Just looking at the logs won't tell you much, the most visible symptom
would be the walsender process stuck at 100%. Another signal would be
a OVERWRITE_CONTRECORD record written just after restart, as the last
record would have been partially. Looking at the last WAL record when
the instance was stuck could be interesting, though if it's a partial
record, it won't be visible with pg_waldump.

If you want to compare, you can reproduce the walsender bug with this
query (you also need an active logical walsender):

-- Start from a fresh segment
SELECT pg_switch_wal();
BEGIN;
-- A logical message record is:
-- 24 bytes of record header
-- 5 bytes fragment header
-- 24 bytes xl_logical_message
-- 2 bytes NULL for prefix + message
-- x bytes message length
-- Total size of a WAL logical message is 55 bytes + message length
-- With WAL long header, the first page has 8152 bytes available
-- With WAL short header, the second page has 8168 bytes available
-- We need to write 16320 bytes (+/- 8 bytes of alignment)
SELECT pg_logical_emit_message(false, '', repeat('a', 16294));
ROLLBACK;

And immediately try to restart (this needs to be the last WAL record),
the shutdown should hang.

Regards,
Anthonin Bonnefoy

On Thu, 9 Jul 2026 09:09:25 +0200
Anthonin Bonnefoy <anthonin.bonnefoy@datadoghq.com> wrote:

As you didn't have a shutdown checkpoint, the symptoms look very
similar (though you didn't confirm whether you were using logical
replication, so I'm gonna assume you do).

No logical replication. Are we sure this only impacts logical and not
physical? Thanks for the pointer - interesting one.

We do use physical replication. Replicas were shut down and they closed
their connections to this writer instance around 04:25 just before
pg_ctl stop was executed on the writer itself.

Something was on the writer DB's CPU before shutdown; metrics show total
CPU for that linux namespace (k8s pod) around 0.86 cores until 04:24 and
then the CPU starts dropping when the database shuts down. Bu 04:28 the
CPU is under 0.01 cores and the CPU remains effectively zero until the
processes are SIGKILL'd 30 minutes later.

-Jeremy

--
To know the thoughts and deeds that have marked man's progress is to
feel the great heart throbs of humanity through the centuries; and if
one does not feel in these pulsations a heavenward striving, one must
indeed be deaf to the harmonies of life.

Helen Keller, The Story Of My Life, 1902, 1903, 1905, introduction by
Ralph Barton Perry (Garden City, NY: Doubleday & Company, 1954), p90.

On Fri, Jul 10, 2026 at 7:20 AM Jeremy Schneider
<schneider@ardentperf.com> wrote:

On Thu, 9 Jul 2026 09:09:25 +0200
Anthonin Bonnefoy <anthonin.bonnefoy@datadoghq.com> wrote:

As you didn't have a shutdown checkpoint, the symptoms look very
similar (though you didn't confirm whether you were using logical
replication, so I'm gonna assume you do).

No logical replication. Are we sure this only impacts logical and not
physical? Thanks for the pointer - interesting one.

Yeah, this is only for logical replication. If you didn't have one,
then it's unrelated.

We do use physical replication. Replicas were shut down and they closed
their connections to this writer instance around 04:25 just before
pg_ctl stop was executed on the writer itself.

Something was on the writer DB's CPU before shutdown; metrics show total
CPU for that linux namespace (k8s pod) around 0.86 cores until 04:24 and
then the CPU starts dropping when the database shuts down. Bu 04:28 the
CPU is under 0.01 cores and the CPU remains effectively zero until the
processes are SIGKILL'd 30 minutes later.

Looking at the last WAL record that was on the whole during shutdown
could be interesting information, if you have it available. If the
shutdown was stuck due to a specific state of the WAL, it could give
you some leads.
Other information could be useful, like the types of writes that
happened after you started the shutdown, or to confirm whether the
RUNNING_XACT you mention is indeed from the autovac and whether it
closed the transaction or not.