MIME-Version: 1.0
From: Jeremy Schneider <schneider@ardentperf.com>
Date: Sun, 5 Jul 2026 14:54:42 -0700
Message-ID: 
 <CA+fnDAa8Kbbx3KkqpfxutTx41RchJsT3Lykqwcedm0CVr5Tw=A@mail.gmail.com>
Subject: hang during shutdown
To: PostgreSQL mailing lists <pgsql-hackers@postgresql.org>
Content-Type: multipart/alternative; boundary="0000000000002e57b90655e43504"
Archived-At: 
 <https://www.postgresql.org/message-id/CA%2BfnDAa8Kbbx3KkqpfxutTx41RchJsT3Lykqwcedm0CVr5Tw%3DA%40mail.gmail.com>
Precedence: bulk

--0000000000002e57b90655e43504
Content-Type: text/plain; charset="UTF-8"

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.  :)

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.

i'm pretty stumped!

my plan right now is to work on the automation that fires the SIGKILL and
just have it collect and log everything it can from /proc/pid/* before the
kill. if this happens again we should get a little more info to go on.

if anyone else has thoughts or ideas to add, lmk

-Jeremy

-- 
http://about.me/jeremy_schneider

--0000000000002e57b90655e43504
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div>i recently saw a hung shutdown on a busy multi-TB pro=
duction database. the hung shutdown had some unexpected downstream impacts =
unrelated to core postgres which turned a routine maintenance operation int=
o a long dramatic overnight incident... blowing way past our planned maint =
window and spoiling my weekend... but that&#39;s another story and mainly j=
ust explains my stubborn persistence slowly following the dominoes backward=
s over this past month. =C2=A0:)<br><br>so far, it all started with this po=
stgres 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 postgre=
s hang is very peculiar. i&#39;m working on some automation to gather more =
diagnostics if there is a recurrence. in the meantime i wanted to share wha=
t i do know, in case anyone else has seen something similar.<br><br>postgre=
s version 16.13<br>Ubuntu 22.04.5 LTS<br>kernel 5.15.0-1110-azure<br><br>be=
tween log messages and wal contents, it appears PostmasterStateMachine tran=
sitioned 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 wa=
s shut down before maint started, at hang time there were only three open &=
quot;postgres&quot; user connections from platform automation.<br><br>here&=
#39;s what i have:<br><br>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 &amp; visibility.<br><br>04:25:09.403 immediat=
e checkpoint (explicit from automation), same running xid<br><br>04:25:09.8=
08 pg logs the fast shutdown req (pg_ctl stop -m fast from automation)<br><=
br>04:25:09.815 both autovac workers log &quot;terminating autovacuum proce=
ss&quot;: die() -&gt; ProcessInterrupts() -&gt; ereport()<br><br>04:30:09 X=
LOG_SWITCH and archiver uploads segment 0x30<br><br>04:30:10 checkpooint_ti=
meout=3D300s fires, 72 dirty buffers written. RUNNING_XACTS at this time sh=
ows xid 2121426339 is still open.<br><br>04:35:10 XLOG_SWITCH and archiver =
uploads segment 0x31<br><br>04:55:08 external automation SIGKILL<br><br><br=
>based on the fact that we saw checkpoints and archivals a full 10 minutes =
later, that&#39;s why i think it never left PM_WAIT_BACKENDS. also, there w=
as never any XLOG_CHECKPOINT_SHUTDOWN record or any XLOG_XACT_ABORT record =
written in the whole 30 minutes.<br><br>AI tells me autovac process needs t=
o call AbortTransaction() which calls ProcArrayEndTransaction() to remove x=
id from PGPROC and also calls RecordTransactionAbort() which should write t=
he abort WAL record. neither of these happen, which suggests autovac was st=
uck 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 obviou=
s places where theres disk or network calls or anything else that could han=
g.<br><br>successful checkpoints suggest that both the data and the wal dis=
ks 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.<br><br>i&#39;m pretty stumped!<br><br>my plan right n=
ow is to work on the automation that fires the SIGKILL and just have it col=
lect and log everything it can from /proc/pid/* before the kill. if this ha=
ppens again we should get a little more info to go on.<br><br>if anyone els=
e has thoughts or ideas to add, lmk<br><br>-Jeremy<br></div><div><br></div>=
<span class=3D"gmail_signature_prefix">-- </span><br><div dir=3D"ltr" class=
=3D"gmail_signature" data-smartmail=3D"gmail_signature"><a href=3D"http://a=
bout.me/jeremy_schneider" target=3D"_blank">http://about.me/jeremy_schneide=
r</a></div></div>

--0000000000002e57b90655e43504--