Re: Postgres 9.2.13 on AIX 7.1 - Mailing list pgsql-bugs

From Rainer Tammer
Subject Re: Postgres 9.2.13 on AIX 7.1
Date
Msg-id fe2f0005-da96-1508-6139-d6ac3d99af59@spg.schulergroup.com
Whole thread Raw
In response to Re: Postgres 9.2.13 on AIX 7.1  ("David G. Johnston" <david.g.johnston@gmail.com>)
Responses Re: Postgres 9.2.13 on AIX 7.1  (Tom Lane <tgl@sss.pgh.pa.us>)
List pgsql-bugs
Hello,
After re-enabling auto vacuum the postmaster exited after several hours:

processes:

postgres@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@spg.schulergroup.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.


pgsql-bugs by date:

Previous
From: Tom Lane
Date:
Subject: Re: Bug in error reporting for multi-line JSON
Next
From: PG Bug reporting form
Date:
Subject: BUG #17160: PostgreSQL13.4:Build failure with GNU Compiler.