public inbox for [email protected]help / color / mirror / Atom feed
hang during shutdown 6+ messages / 4 participants [nested] [flat]
* hang during shutdown @ 2026-07-05 21:54 Jeremy Schneider <[email protected]> 2026-07-06 05:29 ` Re: hang during shutdown Srinath Reddy Sadipiralla <[email protected]> 0 siblings, 1 reply; 6+ messages in thread From: Jeremy Schneider @ 2026-07-05 21:54 UTC (permalink / raw) To: pgsql-hackers 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 ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: hang during shutdown 2026-07-05 21:54 hang during shutdown Jeremy Schneider <[email protected]> @ 2026-07-06 05:29 ` Srinath Reddy Sadipiralla <[email protected]> 2026-07-06 06:30 ` Re: hang during shutdown Anthonin Bonnefoy <[email protected]> 0 siblings, 1 reply; 6+ messages in thread From: Srinath Reddy Sadipiralla @ 2026-07-06 05:29 UTC (permalink / raw) To: Jeremy Schneider <[email protected]>; +Cc: pgsql-hackers Hi Jeremy, On Mon, Jul 6, 2026 at 3:25 AM Jeremy Schneider <[email protected]> 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/ ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: hang during shutdown 2026-07-05 21:54 hang during shutdown Jeremy Schneider <[email protected]> 2026-07-06 05:29 ` Re: hang during shutdown Srinath Reddy Sadipiralla <[email protected]> @ 2026-07-06 06:30 ` Anthonin Bonnefoy <[email protected]> 2026-07-06 12:42 ` Re: hang during shutdown Jakub Wartak <[email protected]> 0 siblings, 1 reply; 6+ messages in thread From: Anthonin Bonnefoy @ 2026-07-06 06:30 UTC (permalink / raw) To: Srinath Reddy Sadipiralla <[email protected]>; +Cc: Jeremy Schneider <[email protected]>; pgsql-hackers Hi, On Sun, Jul 5, 2026 at 11:55 PM Jeremy Schneider <[email protected]> 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]. [0]: https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=82935467a Regards, Anthonin Bonnefoy ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: hang during shutdown 2026-07-05 21:54 hang during shutdown Jeremy Schneider <[email protected]> 2026-07-06 05:29 ` Re: hang during shutdown Srinath Reddy Sadipiralla <[email protected]> 2026-07-06 06:30 ` Re: hang during shutdown Anthonin Bonnefoy <[email protected]> @ 2026-07-06 12:42 ` Jakub Wartak <[email protected]> 2026-07-09 02:49 ` Re: hang during shutdown Jeremy Schneider <[email protected]> 0 siblings, 1 reply; 6+ messages in thread From: Jakub Wartak @ 2026-07-06 12:42 UTC (permalink / raw) To: Anthonin Bonnefoy <[email protected]>; +Cc: Srinath Reddy Sadipiralla <[email protected]>; Jeremy Schneider <[email protected]>; pgsql-hackers On Mon, Jul 6, 2026 at 8:30 AM Anthonin Bonnefoy <[email protected]> wrote: > > Hi, > > On Sun, Jul 5, 2026 at 11:55 PM Jeremy Schneider > <[email protected]> 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] 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=a8f45dee91768cf1447ffaf2527e499e7... ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: hang during shutdown 2026-07-05 21:54 hang during shutdown Jeremy Schneider <[email protected]> 2026-07-06 05:29 ` Re: hang during shutdown Srinath Reddy Sadipiralla <[email protected]> 2026-07-06 06:30 ` Re: hang during shutdown Anthonin Bonnefoy <[email protected]> 2026-07-06 12:42 ` Re: hang during shutdown Jakub Wartak <[email protected]> @ 2026-07-09 02:49 ` Jeremy Schneider <[email protected]> 2026-07-09 07:09 ` Re: hang during shutdown Anthonin Bonnefoy <[email protected]> 0 siblings, 1 reply; 6+ messages in thread From: Jeremy Schneider @ 2026-07-09 02:49 UTC (permalink / raw) To: Jakub Wartak <[email protected]>; +Cc: Anthonin Bonnefoy <[email protected]>; Srinath Reddy Sadipiralla <[email protected]>; pgsql-hackers On Mon, 6 Jul 2026 14:42:10 +0200 Jakub Wartak <[email protected]> wrote: > On Mon, Jul 6, 2026 at 8:30 AM Anthonin Bonnefoy > <[email protected]> wrote: > > > > Hi, > > > > On Sun, Jul 5, 2026 at 11:55 PM Jeremy Schneider > > <[email protected]> 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. ^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: hang during shutdown 2026-07-05 21:54 hang during shutdown Jeremy Schneider <[email protected]> 2026-07-06 05:29 ` Re: hang during shutdown Srinath Reddy Sadipiralla <[email protected]> 2026-07-06 06:30 ` Re: hang during shutdown Anthonin Bonnefoy <[email protected]> 2026-07-06 12:42 ` Re: hang during shutdown Jakub Wartak <[email protected]> 2026-07-09 02:49 ` Re: hang during shutdown Jeremy Schneider <[email protected]> @ 2026-07-09 07:09 ` Anthonin Bonnefoy <[email protected]> 0 siblings, 0 replies; 6+ messages in thread From: Anthonin Bonnefoy @ 2026-07-09 07:09 UTC (permalink / raw) To: Jeremy Schneider <[email protected]>; +Cc: Jakub Wartak <[email protected]>; Srinath Reddy Sadipiralla <[email protected]>; pgsql-hackers On Thu, Jul 9, 2026 at 4:49 AM Jeremy Schneider <[email protected]> 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 ^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2026-07-09 07:09 UTC | newest] Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed) -- links below jump to the message on this page -- 2026-07-05 21:54 hang during shutdown Jeremy Schneider <[email protected]> 2026-07-06 05:29 ` Srinath Reddy Sadipiralla <[email protected]> 2026-07-06 06:30 ` Anthonin Bonnefoy <[email protected]> 2026-07-06 12:42 ` Jakub Wartak <[email protected]> 2026-07-09 02:49 ` Jeremy Schneider <[email protected]> 2026-07-09 07:09 ` Anthonin Bonnefoy <[email protected]>
This inbox is served by agora; see mirroring instructions for how to clone and mirror all data and code used for this inbox