Thread: Postgres 16 unexpected shutdown
Hello, We experienced something strange last weekend when all of a sudden the Postgres service was unexpectedly stopped (see logs below). No maintenance or scripts were running at the time, just our usual traffic over the network doing SELECTS/INSERTS/UPDATES on the server. The server is a Mac Mini M2 with Postgres 16.6 running on macOS Sequoia 15.3.1. The data is stored on a Promise Pegasus32 R8 RAID. The machine has only been active for a little over week, when we replaced an older Intel Mini. It had been running fine for about 8 days, when the issue occurred. In the past, we have noticed a similar issue with external drives on macOS. That issue would briefly change the permissions of certain (or all) files on the drive and cause Postgres to log "Operation not permitted" errors on the postmaster.pid. I believe that issue was caused by the macOS Spotlight features, and we circumvent it now by excluding the drive in the System Settings. This issue seems a little different, since this time the Postgres process was stopped altogether. Does this sound familiar anyone? Any ideas what might prompt Postgres to stop? Below are the log entries from right before the issue occurred. We have started Postgres again since then, and it has been running for 3 days now, without any issues. Thank you, Nick Renders 2025-02-22 07:55:02.449 CET [36988] LOG: checkpoint starting: time 2025-02-22 07:55:58.761 CET [36988] LOG: checkpoint complete: wrote 553 buffers (3.4%); 0 WAL file(s) added, 0 removed, 0 recycled; write=56.297 s, sync=0.004 s, total=56.312 s; sync files=95, longest=0.001 s, average=0.001 s; distance=6687 kB, estimate=6687 kB; lsn=7DA/F373D898, redo lsn=7DA/F350CAE0 2025-02-22 08:00:02.764 CET [36988] LOG: checkpoint starting: time 2025-02-22 08:01:30.018 CET [36988] LOG: checkpoint complete: wrote 849 buffers (5.2%); 1 WAL file(s) added, 0 removed, 0 recycled; write=87.225 s, sync=0.008 s, total=87.255 s; sync files=123, longest=0.001 s, average=0.001 s; distance=6839 kB, estimate=6839 kB; lsn=7DA/F4F604F0, redo lsn=7DA/F3BBA748 2025-02-22 08:05:02.019 CET [36988] LOG: checkpoint starting: time 2025-02-22 08:05:49.427 CET [30566] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.427 CET [30566] STATEMENT: SET application_name = 'JSN4101_190147128' 2025-02-22 08:05:49.427 CET [30566] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.427 CET [30566] STATEMENT: SET application_name = 'JSN4101_190147128' 2025-02-22 08:05:49.433 CET [12639] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.433 CET [12639] STATEMENT: SET application_name = 'SYN4304_41252765' 2025-02-22 08:05:49.433 CET [12639] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.433 CET [12639] STATEMENT: SET application_name = 'SYN4304_41252765' 2025-02-22 08:05:49.438 CET [12639] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.438 CET [12639] STATEMENT: SET application_name = 'SYN4304_41252765' 2025-02-22 08:05:49.438 CET [12639] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.438 CET [12639] STATEMENT: SET application_name = 'SYN4304_41252765' 2025-02-22 08:05:49.474 CET [30600] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.474 CET [30600] STATEMENT: SET application_name = 'JSN4106_190147133' 2025-02-22 08:05:49.474 CET [30600] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.474 CET [30600] STATEMENT: SET application_name = 'JSN4106_190147133' 2025-02-22 08:05:49.512 CET [30531] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.512 CET [30531] STATEMENT: SET application_name = 'JSN4116_190147135' 2025-02-22 08:05:49.512 CET [30531] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.512 CET [30531] STATEMENT: SET application_name = 'JSN4116_190147135' 2025-02-22 08:05:49.545 CET [30580] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.545 CET [30580] STATEMENT: SET application_name = 'JSN4103_190147137' 2025-02-22 08:05:49.545 CET [30580] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.545 CET [30580] STATEMENT: SET application_name = 'JSN4103_190147137' 2025-02-22 08:05:49.639 CET [30524] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.639 CET [30524] STATEMENT: SET application_name = 'JSN4115_190147143' 2025-02-22 08:05:49.639 CET [30524] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.639 CET [30524] STATEMENT: SET application_name = 'JSN4115_190147143' 2025-02-22 08:05:49.644 CET [30559] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.644 CET [30559] STATEMENT: SET application_name = 'JSN4110_190147143' 2025-02-22 08:05:49.644 CET [30559] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.644 CET [30559] STATEMENT: SET application_name = 'JSN4110_190147143' 2025-02-22 08:05:49.708 CET [30574] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.708 CET [30574] STATEMENT: SET application_name = 'JSN4108_190147147' 2025-02-22 08:05:49.708 CET [30574] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.708 CET [30574] STATEMENT: SET application_name = 'JSN4108_190147147' 2025-02-22 08:05:49.757 CET [30514] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.757 CET [30514] STATEMENT: SET application_name = 'JSN4105_190147150' 2025-02-22 08:05:49.757 CET [30514] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.757 CET [30514] STATEMENT: SET application_name = 'JSN4105_190147150' 2025-02-22 08:05:49.792 CET [30542] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.792 CET [30542] STATEMENT: SET application_name = 'JSN4102_190147152' 2025-02-22 08:05:49.792 CET [30542] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.792 CET [30542] STATEMENT: SET application_name = 'JSN4102_190147152' 2025-02-22 08:05:49.839 CET [30544] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.839 CET [30544] STATEMENT: SET application_name = 'JSN4111_190147155' 2025-02-22 08:05:49.839 CET [30544] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.839 CET [30544] STATEMENT: SET application_name = 'JSN4111_190147155' 2025-02-22 08:05:49.958 CET [30566] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.958 CET [30566] STATEMENT: SET application_name = 'JSN4101_190147162' 2025-02-22 08:05:49.958 CET [30566] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.958 CET [30566] STATEMENT: SET application_name = 'JSN4101_190147162' 2025-02-22 08:05:49.999 CET [30600] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.999 CET [30600] STATEMENT: SET application_name = 'JSN4106_190147164' 2025-02-22 08:05:49.999 CET [30600] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:49.999 CET [30600] STATEMENT: SET application_name = 'JSN4106_190147164' 2025-02-22 08:05:50.035 CET [30531] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:50.035 CET [30531] STATEMENT: SET application_name = 'JSN4116_190147167' 2025-02-22 08:05:50.035 CET [30531] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:50.035 CET [30531] STATEMENT: SET application_name = 'JSN4116_190147167' 2025-02-22 08:05:50.039 CET [30580] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:50.039 CET [30580] STATEMENT: SET application_name = 'JSN4103_190147167' 2025-02-22 08:05:50.039 CET [30580] LOG: could not write file "pg_stat_tmp/pgss_query_texts.stat": Operation not permitted 2025-02-22 08:05:50.039 CET [30580] STATEMENT: SET application_name = 'JSN4103_190147167' 2025-02-22 08:05:50.096 CET [30518] LOG: could not create archive status file "pg_wal/archive_status/00000001000007DA000000F8.ready": Operation not permitted 2025-02-22 08:05:50.096 CET [30518] PANIC: could not create file "pg_wal/xlogtemp.30518": Operation not permitted 2025-02-22 08:05:50.097 CET [36986] LOG: server process (PID 30518) was terminated by signal 6: Abort trap: 6 2025-02-22 08:05:50.097 CET [36986] DETAIL: Failed process was running: UPDATE f_gsxws_schedule SET gwsc_date = $1 , gwsc_status = $2 , gwsc_result_bin = $3 , gwsc_result_json = $4 ::json, gwsc_result_int = $5 , gwsc_initiated_flag = $6 , gwsc_initiated_platform = $7 , gwsc_initiated_date = $8 , gwsc_edit_date = now() WHERE gwsc_number = 18286370 2025-02-22 08:05:50.097 CET [36986] LOG: terminating any other active server processes 2025-02-22 08:05:50.191 CET [36986] LOG: all server processes terminated; reinitializing 2025-02-22 08:05:50.191 CET [36986] LOG: could not open directory "base/pgsql_tmp": Operation not permitted 2025-02-22 08:05:50.191 CET [36986] LOG: could not open directory "base": Operation not permitted 2025-02-22 08:05:50.191 CET [36986] LOG: could not open directory "pg_tblspc": Operation not permitted 2025-02-22 08:05:50.192 CET [36986] PANIC: could not open file "global/pg_control": Operation not permitted
On Tue, Feb 25, 2025 at 8:51 AM <postgres@arcict.com> wrote:
Does this sound familiar anyone? Any ideas what might prompt Postgres to stop?
Postgres needs full read and write access to its own data directory. If it doesn't, it will eventually PANIC, as your logs show.
See if you can figure out what else happened around 2025-02-22 08:05:49.427 CET, which seems to be when the problem started according to your logs.
Cheers,
Greg
--
Crunchy Data - https://www.crunchydata.com
Enterprise Postgres Software Products & Tech Support