Re: Postgres 9.2.13 on AIX 7.1

From: Rainer Tammer <pgsql(at)spg(dot)schulergroup(dot)com>
To: "David G(dot) Johnston" <david(dot)g(dot)johnston(at)gmail(dot)com>
Cc: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, PostgreSQL mailing lists <pgsql-bugs(at)lists(dot)postgresql(dot)org>
Subject: Re: Postgres 9.2.13 on AIX 7.1
Date: 2021-08-25 15:06:56
Message-ID: fe2f0005-da96-1508-6139-d6ac3d99af59@spg.schulergroup.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Hello,
After re-enabling auto vacuum the postmaster exited after several hours:

processes:

postgres(at)host rc:0 $ ps -ef | grep 23265700 | grep -v grep
postgres 14483960 23265700   0 08:12:29      -  0:00 postgres: wal
writer process
postgres 18415902 23265700   0 08:12:29      -  0:00 postgres: stats
collector process
postgres 21889394 23265700   0 08:12:29      -  0:00 postgres:
checkpointer process
postgres 23265700        1   0 08:12:29  pts/0  0:00
/usr/local/pgsql-9.2.13/bin/postgres -D /usr/local/pgsql/data -i
postgres 23789942 23265700   0 08:12:29      -  0:00 postgres:
autovacuum launcher process
postgres 24903996 23265700   0 08:12:29      -  0:00 postgres: writer
process

This is the debug5 log:

2021-08-25 08:12:29 CEST  DEBUG:  postgres: PostmasterMain: initial
environment dump:
2021-08-25 08:12:29 CEST  DEBUG: -----------------------------------------
2021-08-25 08:12:29 CEST  DEBUG: _=/usr/local/pgsql-9.2.13/bin/postgres
2021-08-25 08:12:29 CEST  DEBUG:
MANPATH=/usr/dt/man:/usr/share/man:/usr/lpp/info:/opt/freeware/man:/usr/local/man:/usr/local/ssl/man:/usr/local/pgsql/man
2021-08-25 08:12:29 CEST  DEBUG:      myid=postgres
2021-08-25 08:12:29 CEST  DEBUG:      LANG=en_US
2021-08-25 08:12:29 CEST  DEBUG:      PGTZ=NFT-1DFT
2021-08-25 08:12:29 CEST  DEBUG:      LOGIN=postgres
2021-08-25 08:12:29 CEST  DEBUG:      VISUAL=emacs
2021-08-25 08:12:29 CEST  DEBUG:      CLCMD_PASSTHRU=1
2021-08-25 08:12:29 CEST  DEBUG:
PATH=/usr/bin:/etc:/usr/sbin:/usr/ucb:/usr/bin/X11:/sbin:/usr/java8_64/jre/bin:/usr/java8_64/bin:/opt/IBM/xlc/16.1.0/bin:/opt/IBM/xlC/16.1.0/bin:/opt/freeware/bin:/usr/opt/perl5/bin:/usr/local/bin:/usr/local/pgsql/bin
2021-08-25 08:12:29 CEST  DEBUG: PG_GRANDPARENT_PID=21889390
2021-08-25 08:12:29 CEST  DEBUG:      LC__FASTMSG=true
2021-08-25 08:12:29 CEST  DEBUG:      LOGNAME=postgres
2021-08-25 08:12:29 CEST  DEBUG: MAIL=/usr/spool/mail/postgres
2021-08-25 08:12:29 CEST  DEBUG:      HOSTNAME=host
2021-08-25 08:12:29 CEST  DEBUG:      LOCPATH=/usr/lib/nls/loc
2021-08-25 08:12:29 CEST  DEBUG:      USER=postgres
2021-08-25 08:12:29 CEST  DEBUG:      AUTHSTATE=files
2021-08-25 08:12:29 CEST  DEBUG:      LC_CTYPE=de_DE.ISO8859-1
2021-08-25 08:12:29 CEST  DEBUG:      DISPLAY=rt01:0
2021-08-25 08:12:29 CEST  DEBUG:      SHELL=/usr/bin/ksh
2021-08-25 08:12:29 CEST  DEBUG:      ODMDIR=/etc/objrepos
2021-08-25 08:12:29 CEST  DEBUG: PGDATA=/usr/local/pgsql/data
2021-08-25 08:12:29 CEST  DEBUG:      HOME=/home/postgres
2021-08-25 08:12:29 CEST  DEBUG:      LC_COLLATE=de_DE.ISO8859-1
2021-08-25 08:12:29 CEST  DEBUG: PGSYSCONFDIR=/usr/local/pgsql-9.2.13/etc
2021-08-25 08:12:29 CEST  DEBUG:      TERM=xterm
2021-08-25 08:12:29 CEST  DEBUG:      MAILMSG=[YOU HAVE NEW MAIL]
2021-08-25 08:12:29 CEST  DEBUG:      PWD=/home/postgres
2021-08-25 08:12:29 CEST  DEBUG:      TZ=Europe/Berlin
2021-08-25 08:12:29 CEST  DEBUG:      ENV=/.env
2021-08-25 08:12:29 CEST  DEBUG:      PGLIB=/usr/local/pgsql/lib
2021-08-25 08:12:29 CEST  DEBUG:      A__z=! LOGNAME
2021-08-25 08:12:29 CEST  DEBUG:
NLSPATH=/usr/lib/nls/msg/%L/%N:/usr/lib/nls/msg/%L/%N.cat:/usr/lib/nls/msg/%l.%c/%N:/usr/lib/nls/msg/%l.%c/%N.cat
2021-08-25 08:12:29 CEST  DEBUG: LD_LIBRARY_PATH=:/usr/local/pgsql/lib
2021-08-25 08:12:29 CEST  DEBUG:      LC_MESSAGES=en_US
2021-08-25 08:12:29 CEST  DEBUG:      LC_MONETARY=C
2021-08-25 08:12:29 CEST  DEBUG:      LC_NUMERIC=C
2021-08-25 08:12:29 CEST  DEBUG:      LC_TIME=C
2021-08-25 08:12:29 CEST  DEBUG: -----------------------------------------
2021-08-25 08:12:29 CEST  DEBUG:  invoking IpcMemoryCreate(size=39591936)
2021-08-25 08:12:29 CEST  DEBUG:  SlruScanDirectory invoking callback on
pg_notify/0000
2021-08-25 08:12:29 CEST  DEBUG:  removing file "pg_notify/0000"
2021-08-25 08:12:29 CEST  DEBUG:  max_safe_fds = 984, usable_fds = 1000,
already_open = 6
2021-08-25 08:12:29 CEST  LOG:  database system was shut down at
2021-08-25 08:12:10 CEST
2021-08-25 08:12:29 CEST  DEBUG:  checkpoint record is at 0/250D59C8
2021-08-25 08:12:29 CEST  DEBUG:  redo record is at 0/250D59C8; shutdown
TRUE
2021-08-25 08:12:29 CEST  DEBUG:  next transaction ID: 0/1558; next OID:
17770
2021-08-25 08:12:29 CEST  DEBUG:  next MultiXactId: 1; next
MultiXactOffset: 0
2021-08-25 08:12:29 CEST  DEBUG:  oldest unfrozen transaction ID: 679,
in database 1
2021-08-25 08:12:29 CEST  DEBUG:  transaction ID wrap limit is
2147484326, limited by database with OID 1
2021-08-25 08:12:29 CEST  DEBUG:  shmem_exit(0): 4 callbacks to make
2021-08-25 08:12:29 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 08:12:29 CEST  DEBUG:  exit(0)
2021-08-25 08:12:29 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 08:12:29 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 08:12:29 CEST  DEBUG:  reaping dead processes
2021-08-25 08:12:29 CEST  DEBUG:  checkpointer updated shared memory
configuration values
2021-08-25 08:12:29 CEST  LOG:  database system is ready to accept
connections
2021-08-25 08:12:29 CEST  LOG:  autovacuum launcher started

.... cut ...
2021-08-25 16:22:17 CEST  DEBUG:  name: unnamed; blockState:      
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:17 CEST  DEBUG:  shmem_exit(0): 8 callbacks to make
2021-08-25 16:22:17 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:17 CEST  DEBUG:  exit(0)
2021-08-25 16:22:17 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:17 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:17 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:17 CEST  DEBUG:  server process (PID 19005772) exited
with exit code 0
2021-08-25 16:22:27 CEST  DEBUG:  StartTransaction
2021-08-25 16:22:27 CEST  DEBUG:  name: unnamed; blockState:      
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:27 CEST  DEBUG:  CommitTransaction
2021-08-25 16:22:27 CEST  DEBUG:  name: unnamed; blockState:      
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:27 CEST  DEBUG:  InitPostgres
2021-08-25 16:22:27 CEST  DEBUG:  my backend ID is 2
2021-08-25 16:22:27 CEST  DEBUG:  StartTransaction
2021-08-25 16:22:27 CEST  DEBUG:  name: unnamed; blockState:      
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:27 CEST  DEBUG:  CommitTransaction
2021-08-25 16:22:27 CEST  DEBUG:  name: unnamed; blockState:      
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:27 CEST  DEBUG:  autovacuum: processing database "test"
2021-08-25 16:22:27 CEST  DEBUG:  StartTransaction
2021-08-25 16:22:27 CEST  DEBUG:  name: unnamed; blockState:      
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:27 CEST  DEBUG:  pg_statistic: vac: 0 (threshold 127),
anl: 262 (threshold 88)
2021-08-25 16:22:27 CEST  DEBUG:  pg_type: vac: 0 (threshold 116), anl:
0 (threshold 83)
2021-08-25 16:22:27 CEST  DEBUG:  pg_authid: vac: 1 (threshold 50), anl:
2 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_proc: vac: 1 (threshold 548), anl:
2 (threshold 299)
2021-08-25 16:22:27 CEST  DEBUG:  pg_class: vac: 0 (threshold 108), anl:
0 (threshold 79)
2021-08-25 16:22:27 CEST  DEBUG:  pg_attribute: vac: 0 (threshold 499),
anl: 0 (threshold 275)
2021-08-25 16:22:27 CEST  DEBUG:  pg_constraint: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_inherits: vac: 3 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_operator: vac: 4 (threshold 196),
anl: 4 (threshold 123)
2021-08-25 16:22:27 CEST  DEBUG:  pg_opfamily: vac: 0 (threshold 65),
anl: 0 (threshold 58)
2021-08-25 16:22:27 CEST  DEBUG:  pg_opclass: vac: 0 (threshold 74),
anl: 0 (threshold 62)
2021-08-25 16:22:27 CEST  DEBUG:  pg_am: vac: 0 (threshold 51), anl: 0
(threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_amop: vac: 0 (threshold 129), anl:
0 (threshold 89)
2021-08-25 16:22:27 CEST  DEBUG:  pg_amproc: vac: 0 (threshold 107),
anl: 0 (threshold 79)
2021-08-25 16:22:27 CEST  DEBUG:  pg_language: vac: 0 (threshold 51),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_largeobject_metadata: vac: 20
(threshold 50), anl: 19 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_aggregate: vac: 0 (threshold 74),
anl: 0 (threshold 62)
2021-08-25 16:22:27 CEST  DEBUG:  pg_rewrite: vac: 1 (threshold 71),
anl: 0 (threshold 61)
2021-08-25 16:22:27 CEST  DEBUG:  pg_trigger: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_description: vac: 41 (threshold
740), anl: 81 (threshold 395)
2021-08-25 16:22:27 CEST  DEBUG:  pg_database: vac: 4 (threshold 50),
anl: 8 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_enum: vac: 8 (threshold 50), anl:
16 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_namespace: vac: 4 (threshold 52),
anl: 4 (threshold 51)
2021-08-25 16:22:27 CEST  DEBUG:  pg_conversion: vac: 0 (threshold 76),
anl: 0 (threshold 63)
2021-08-25 16:22:27 CEST  DEBUG:  pg_depend: vac: 1237 (threshold 1291),
anl: 0 (threshold 670)
2021-08-25 16:22:27 CEST  DEBUG:  pg_db_role_setting: vac: 0 (threshold
50), anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_tablespace: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_pltemplate: vac: 0 (threshold 52),
anl: 0 (threshold 51)
2021-08-25 16:22:27 CEST  DEBUG:  pg_auth_members: vac: 0 (threshold
50), anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_shdepend: vac: 38 (threshold 52),
anl: 0 (threshold 51)
2021-08-25 16:22:27 CEST  DEBUG:  pg_shdescription: vac: 1 (threshold
50), anl: 1 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_ts_config: vac: 0 (threshold 53),
anl: 0 (threshold 52)
2021-08-25 16:22:27 CEST  DEBUG:  pg_ts_dict: vac: 0 (threshold 53),
anl: 0 (threshold 52)
2021-08-25 16:22:27 CEST  DEBUG:  pg_ts_parser: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_ts_template: vac: 0 (threshold 51),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_extension: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_foreign_data_wrapper: vac: 1
(threshold 50), anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_foreign_server: vac: 1 (threshold
50), anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_default_acl: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_seclabel: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_shseclabel: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_collation: vac: 0 (threshold 52),
anl: 0 (threshold 51)
2021-08-25 16:22:27 CEST  DEBUG:  pg_largeobject: vac: 27 (threshold
50), anl: 37 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_attrdef: vac: 0 (threshold 50),
anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_index: vac: 0 (threshold 72), anl:
0 (threshold 61)
2021-08-25 16:22:27 CEST  DEBUG:  pg_cast: vac: 0 (threshold 89), anl: 0
(threshold 70)
2021-08-25 16:22:27 CEST  DEBUG:  pg_foreign_table: vac: 1 (threshold
50), anl: 0 (threshold 50)
2021-08-25 16:22:27 CEST  DEBUG:  pg_toast_2619: vac: 2 (threshold 52),
anl: 4 (threshold 51)
2021-08-25 16:22:27 CEST  DEBUG:  CommitTransaction
2021-08-25 16:22:27 CEST  DEBUG:  name: unnamed; blockState:      
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-25 16:22:27 CEST  DEBUG:  shmem_exit(0): 8 callbacks to make
2021-08-25 16:22:27 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:27 CEST  DEBUG:  exit(0)
2021-08-25 16:22:27 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:27 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:27 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:27 CEST  DEBUG:  server process (PID 19005776) exited
with exit code 0
2021-08-25 16:22:33 CEST  DEBUG: postmaster received signal 2
2021-08-25 16:22:33 CEST  LOG:  received fast shutdown request
2021-08-25 16:22:33 CEST  LOG:  aborting any active transactions
2021-08-25 16:22:33 CEST  LOG:  autovacuum launcher shutting down
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(0): 7 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  exit(0)
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(0): 4 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  exit(0)
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(0): 4 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  exit(0)
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:33 CEST  LOG:  shutting down
2021-08-25 16:22:33 CEST  DEBUG:  attempting to remove WAL segments
older than log file 000000010000000000000024
2021-08-25 16:22:33 CEST  DEBUG:  SlruScanDirectory invoking callback on
pg_subtrans/0000
2021-08-25 16:22:33 CEST  LOG:  database system is shut down
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(0): 4 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  exit(0)
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:33 CEST  LOG:  shutting down
2021-08-25 16:22:33 CEST  DEBUG:  attempting to remove WAL segments
older than log file 000000010000000000000024
2021-08-25 16:22:33 CEST  DEBUG:  SlruScanDirectory invoking callback on
pg_subtrans/0000
2021-08-25 16:22:33 CEST  LOG:  database system is shut down
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(0): 4 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  exit(0)
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  reaping dead processes
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(0): 3 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(0): 3 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  exit(0)
2021-08-25 16:22:33 CEST  DEBUG:  shmem_exit(-1): 0 callbacks to make
2021-08-25 16:22:33 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make

Bye
  Rainer

On 24.08.2021 16:11, David G. Johnston wrote:
> On Tue, Aug 24, 2021 at 4:55 AM Rainer Tammer
> <pgsql(at)spg(dot)schulergroup(dot)com <mailto:pgsql(at)spg(dot)schulergroup(dot)com>> wrote:
>
> I have disabled auto vacuum and the instance is now running for ~ 3h.
> [...]
> I have set debug to 5, so that we get some additional information
> is the DB goes down unintended.
>
>
> Run a manual whole-database vacuum and see if it crashes?
>
> David J.
>

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message PG Bug reporting form 2021-08-25 15:11:02 BUG #17160: PostgreSQL13.4:Build failure with GNU Compiler.
Previous Message Tom Lane 2021-08-25 14:55:52 Re: Bug in error reporting for multi-line JSON