Обсуждение: Postgres 9.2.13 on AIX 7.1

Поиск

Список

Период

Сортировка

Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

10 августа 2021 г., 19:14:32

Hello,
I know that this is an older version, but maybe someone has a hint.
I can unfortunately currently not upgrade this instance to a higher
version because of some restrictions in other applications.

postgresql-9.2.13

2021-08-10 16:24:50 CEST [local] postgresSTATEMENT: SELECT 'tele_shd_id_max'::pg_catalog.regproc::pg_catalog.oid (no problen, caused by upgrade an missing table)
2021-08-10 17:15:44 CEST LOG: 00000: received fast shutdown request
2021-08-10 17:15:44 CEST LOCATION: pmdie, postmaster.c:2215
2021-08-10 17:15:44 CEST LOG: 00000: aborting any active transactions
2021-08-10 17:15:44 CEST LOCATION: pmdie, postmaster.c:2239
2021-08-10 17:15:44 CEST LOG: 00000: autovacuum launcher shutting down
2021-08-10 17:15:44 CEST LOCATION: AutoVacLauncherMain, autovacuum.c:779
2021-08-10 17:15:44 CEST LOG: 00000: shutting down
2021-08-10 17:15:44 CEST LOCATION: ShutdownXLOG, xlog.c:7957
2021-08-10 17:15:44 CEST LOG: 00000: database system is shut down
2021-08-10 17:15:44 CEST LOCATION: ShutdownXLOG, xlog.c:7979

OS: AIX 7.1 TL5 SP8

It looks line 8.4.22 is running without crashing.

The postmaster simply dies after about 1 hour.

Bye
Rainer Tammer

Re: Postgres 9.2.13 on AIX 7.1

От

"David G. Johnston"

Дата:

10 августа 2021 г., 19:31:19

On Tuesday, August 10, 2021, Rainer Tammer <pgsql@spg.schulergroup.com> wrote:

2021-08-10 17:15:44 CEST LOG: 00000: received fast shutdown request

Your service was told to shutdown and it did

David J.

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

10 августа 2021 г., 19:42:38

Hello,
Unfortunately that happened without a command from the outside.
Currently I am the only one on that LPAR and I did not issue a shutdown.
There are no cron jobs running.

I replaced the 9.2.13 with 8.4.22 (as a test) and this build does not show this problem (so far)....

Bye
Rainer

On 10.08.2021 18:31, David G. Johnston wrote:

On Tuesday, August 10, 2021, Rainer Tammer <pgsql@spg.schulergroup.com> wrote:

2021-08-10 17:15:44 CEST LOG: 00000: received fast shutdown request

Your service was told to shutdown and it did

David J.

Re: Postgres 9.2.13 on AIX 7.1

От

Tom Lane

Дата:

10 августа 2021 г., 20:07:53

Rainer Tammer <pgsql@spg.schulergroup.com> writes:
> 2021-08-10 17:15:44 CEST  LOG:  00000: received fast shutdown request
> 2021-08-10 17:15:44 CEST  LOCATION:  pmdie, postmaster.c:2215

> The postmaster simply dies after about 1 hour.

Something is sending the postmaster a SIGINT signal.

            regards, tom lane

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

11 августа 2021 г., 09:33:10

Hello,
I have some additional information:

I have now used 9.6.22 on AIX 7.1 TL5 SP8 (that's the lates 7.1 level).
Comiler IBM XLC/C++ V16.1.

export CFLAGS=-qsuppress=1500-010
export CC=cc_r <--- _r is thread safe
export CXX=xlC_r
export CONFIG_SHELL=/bin/bash

bash ./configure \
--with-includes=/opt/freeware/include/readline \
--with-libraries=/opt/freeware/lib \
--prefix=/usr/local/pgsql-9.6.22 \
--with-CC=cc_r \
--with-libxml \
--without-tcl \
--without-python

All "make check" test do run without an issue.
It's not like the hanging test we had worked on a couple years ago (were a SIGINT was blocked
https://www.postgresql.org/message-id/flat/32656.1393346132%40sss.pgh.pa.us#1328f6db2318885b185753f81307865c ).

It looks like the wrong process is getting a SIGINT right after an auto vacuum.

This is a debug log:

2021-08-10 23:28:49 CEST LOG: database system was shut down at 2021-08-10 23:28:40 CEST
2021-08-10 23:28:49 CEST LOG: MultiXact member wraparound protections are now enabled
2021-08-10 23:28:49 CEST LOG: autovacuum launcher started
2021-08-10 23:28:49 CEST LOG: database system is ready to accept connections
2021-08-10 23:33:36 CEST LOG: received fast shutdown request
2021-08-10 23:33:36 CEST LOG: aborting any active transactions
2021-08-10 23:33:36 CEST LOG: autovacuum launcher shutting down
2021-08-10 23:33:36 CEST LOG: shutting down
2021-08-10 23:33:36 CEST LOG: database system is shut down
2021-08-10 23:33:43 CEST DEBUG: postgres: PostmasterMain: initial environment dump:
2021-08-10 23:33:43 CEST DEBUG: -----------------------------------------
2021-08-10 23:33:43 CEST DEBUG:        _=/usr/local/pgsql-9.6.22/bin/postgres
2021-08-10 23:33:43 CEST DEBUG:        MANPATH=/usr/share/man:/opt/freeware/man:/usr/local/man:/usr/local/share/man:/usr/local/ssl/man:/usr/local/pgsql/man
2021-08-10 23:33:43 CEST DEBUG:        myid=postgres
2021-08-10 23:33:43 CEST DEBUG:        LANG=en_US
2021-08-10 23:33:43 CEST DEBUG:        PGTZ=NFT-1DFT
2021-08-10 23:33:43 CEST DEBUG:        LOGIN=postgres
2021-08-10 23:33:43 CEST DEBUG:        VISUAL=emacs
2021-08-10 23:33:43 CEST DEBUG:        CLCMD_PASSTHRU=1
2021-08-10 23:33:43 CEST DEBUG:        PATH=/usr/bin:/etc:/usr/sbin:/usr/ucb:/home/postgres/bin:/usr/bin/X11:/sbin:/usr/local/bin:/usr/dt/bin:/usr/local/pgsql/bin
2021-08-10 23:33:43 CEST DEBUG:        PG_GRANDPARENT_PID=10158176
2021-08-10 23:33:43 CEST DEBUG:        LC__FASTMSG=true
2021-08-10 23:33:43 CEST DEBUG:        LOGNAME=postgres
2021-08-10 23:33:43 CEST DEBUG:        MAIL=/usr/spool/mail/postgres
2021-08-10 23:33:43 CEST DEBUG:        HOSTNAME=wwwlegacy
2021-08-10 23:33:43 CEST DEBUG:        LOCPATH=/usr/lib/nls/loc
2021-08-10 23:33:43 CEST DEBUG:        USER=postgres
2021-08-10 23:33:43 CEST DEBUG:        AUTHSTATE=files
2021-08-10 23:33:43 CEST DEBUG:        DSM_LOG=/usr/tivoli/tsm/client/ba/bin64/log
2021-08-10 23:33:43 CEST DEBUG:        LC_CTYPE=de_DE.ISO8859-1
2021-08-10 23:33:43 CEST DEBUG:        DISPLAY=rtdhcp19:0
2021-08-10 23:33:43 CEST DEBUG:        SHELL=/usr/bin/ksh
2021-08-10 23:33:43 CEST DEBUG:        ODMDIR=/etc/objrepos
2021-08-10 23:33:43 CEST DEBUG:        PGDATA=/usr/local/pgsql/data
2021-08-10 23:33:43 CEST DEBUG:        HOME=/home/postgres
2021-08-10 23:33:43 CEST DEBUG:        LC_COLLATE=de_DE.ISO8859-1
2021-08-10 23:33:43 CEST DEBUG:        PGSYSCONFDIR=/usr/local/pgsql-9.6.22/etc
2021-08-10 23:33:43 CEST DEBUG:        TERM=xterm
2021-08-10 23:33:43 CEST DEBUG:        DSM_DIR=/usr/tivoli/tsm/client/ba/bin64
2021-08-10 23:33:43 CEST DEBUG:        MAILMSG=[YOU HAVE NEW MAIL]
2021-08-10 23:33:43 CEST DEBUG:        PWD=/home/postgres
2021-08-10 23:33:43 CEST DEBUG:        TZ=Europe/Berlin
2021-08-10 23:33:43 CEST DEBUG:        ENV=/.env
2021-08-10 23:33:43 CEST DEBUG:        DSM_CONFIG=/usr/tivoli/tsm/client/ba/bin64/dsm.opt
2021-08-10 23:33:43 CEST DEBUG:        PGLIB=/usr/local/pgsql/lib
2021-08-10 23:33:43 CEST DEBUG:        A__z=! LOGNAME
2021-08-10 23:33:43 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-10 23:33:43 CEST DEBUG:        LD_LIBRARY_PATH=:/usr/local/pgsql/lib
2021-08-10 23:33:43 CEST DEBUG:        LC_MESSAGES=en_US
2021-08-10 23:33:43 CEST DEBUG:        LC_MONETARY=C
2021-08-10 23:33:43 CEST DEBUG:        LC_NUMERIC=C
2021-08-10 23:33:43 CEST DEBUG:        LC_TIME=C
2021-08-10 23:33:43 CEST DEBUG: -----------------------------------------
2021-08-10 23:33:43 CEST DEBUG: invoking IpcMemoryCreate(size=146317312)
2021-08-10 23:33:43 CEST DEBUG: SlruScanDirectory invoking callback on pg_notify/0000
2021-08-10 23:33:43 CEST DEBUG: removing file "pg_notify/0000"
2021-08-10 23:33:43 CEST DEBUG: dynamic shared memory system will support 288 segments
2021-08-10 23:33:43 CEST DEBUG: created dynamic shared memory control segment 563757097 (2316 bytes)
2021-08-10 23:33:43 CEST DEBUG: max_safe_fds = 984, usable_fds = 1000, already_open = 6
2021-08-10 23:33:43 CEST LOG: database system was shut down at 2021-08-10 23:33:36 CEST
2021-08-10 23:33:43 CEST DEBUG: checkpoint record is at 0/216C380
2021-08-10 23:33:43 CEST DEBUG: redo record is at 0/216C380; shutdown TRUE
2021-08-10 23:33:43 CEST DEBUG: next transaction ID: 0:2138; next OID: 18958
2021-08-10 23:33:43 CEST DEBUG: next MultiXactId: 1; next MultiXactOffset: 0
2021-08-10 23:33:43 CEST DEBUG: oldest unfrozen transaction ID: 553, in database 1
2021-08-10 23:33:43 CEST DEBUG: oldest MultiXactId: 1, in database 1
2021-08-10 23:33:43 CEST DEBUG: commit timestamp Xid oldest/newest: 0/0
2021-08-10 23:33:43 CEST DEBUG: transaction ID wrap limit is 2147484200, limited by database with OID 1
2021-08-10 23:33:43 CEST DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1
2021-08-10 23:33:43 CEST DEBUG: starting up replication slots
2021-08-10 23:33:43 CEST DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1
2021-08-10 23:33:43 CEST LOG: MultiXact member wraparound protections are now enabled
2021-08-10 23:33:43 CEST DEBUG: MultiXact member stop limit is now 4294914944 based on MultiXact 1
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(0): 4 on_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:33:43 CEST DEBUG: exit(0)
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:33:43 CEST DEBUG: checkpointer updated shared memory configuration values
2021-08-10 23:33:43 CEST LOG: autovacuum launcher started
2021-08-10 23:33:43 CEST DEBUG: InitPostgres
2021-08-10 23:33:43 CEST DEBUG: StartTransaction
2021-08-10 23:33:43 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:43 CEST DEBUG: CommitTransaction
2021-08-10 23:33:43 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_12416.stat"
2021-08-10 23:33:43 CEST LOG: database system is ready to accept connections
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_16387.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_16386.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_1.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_0.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/global.stat"
2021-08-10 23:33:43 CEST DEBUG: received inquiry for database 0
2021-08-10 23:33:43 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:33:43 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:33:59 CEST DEBUG: StartTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: CommitTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: received inquiry for database 0
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:33:59 CEST DEBUG: InitPostgres
2021-08-10 23:33:59 CEST DEBUG: StartTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: CommitTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: autovacuum: processing database "test"
2021-08-10 23:33:59 CEST DEBUG: received inquiry for database 16387
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/db_16387.stat"
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:33:59 CEST DEBUG: StartTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: pg_statistic: vac: 121 (threshold 128), anl: 284 (threshold 89)
2021-08-10 23:33:59 CEST DEBUG: pg_type: vac: 0 (threshold 122), anl: 0 (threshold 86)
2021-08-10 23:33:59 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_attribute: vac: 0 (threshold 533), anl: 0 (threshold 292)
2021-08-10 23:33:59 CEST DEBUG: pg_proc: vac: 3 (threshold 615), anl: 6 (threshold 332)
2021-08-10 23:33:59 CEST DEBUG: pg_class: vac: 0 (threshold 113), anl: 0 (threshold 82)
2021-08-10 23:33:59 CEST DEBUG: pg_attrdef: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_constraint: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_inherits: vac: 9 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:33:59 CEST DEBUG: pg_operator: vac: 9 (threshold 205), anl: 12 (threshold 128)
2021-08-10 23:33:59 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:33:59 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:33:59 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:33:59 CEST DEBUG: pg_language: vac: 0 (threshold 51), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_largeobject_metadata: vac: 24 (threshold 50), anl: 36 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_aggregate: vac: 0 (threshold 78), anl: 0 (threshold 64)
2021-08-10 23:33:59 CEST DEBUG: pg_rewrite: vac: 6 (threshold 73), anl: 0 (threshold 62)
2021-08-10 23:33:59 CEST DEBUG: pg_largeobject: vac: 24 (threshold 62), anl: 18 (threshold 56)
2021-08-10 23:33:59 CEST DEBUG: pg_trigger: vac: 32 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_description: vac: 64 (threshold 818), anl: 127 (threshold 434)
2021-08-10 23:33:59 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:33:59 CEST DEBUG: pg_enum: vac: 15 (threshold 50), anl: 30 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_namespace: vac: 33 (threshold 52), anl: 0 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: pg_conversion: vac: 0 (threshold 76), anl: 0 (threshold 63)
2021-08-10 23:33:59 CEST DEBUG: pg_depend: vac: 0 (threshold 1516), anl: 0 (threshold 783)
2021-08-10 23:33:59 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_shdepend: vac: 25 (threshold 52), anl: 48 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_foreign_data_wrapper: vac: 3 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_foreign_server: vac: 3 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_foreign_table: vac: 3 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_toast_2619: vac: 2 (threshold 52), anl: 4 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: CommitTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:33:59 CEST DEBUG: exit(0)
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:33:59 CEST DEBUG: server process (PID 13238500) exited with exit code 0
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: postgres child[9044204]: starting with (
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG:       postgres
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: )
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: InitPostgres
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: StartTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST DEBUG: forked new backend, pid=9044204 socket=9
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: CommitTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: StartTransactionCommand
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: StartTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: CommitTransactionCommand
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: CommitTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(0): 6 on_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: proc_exit(0): 3 callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: exit(0)
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:01 CEST DEBUG: server process (PID 9044204) exited with exit code 0
2021-08-10 23:34:14 CEST DEBUG: StartTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: CommitTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: received inquiry for database 0
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:14 CEST DEBUG: InitPostgres
2021-08-10 23:34:14 CEST DEBUG: StartTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: CommitTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: autovacuum: processing database "template1"
2021-08-10 23:34:14 CEST DEBUG: received inquiry for database 1
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/db_1.stat"
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:14 CEST DEBUG: StartTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: pg_statistic: vac: 14 (threshold 127), anl: 14 (threshold 88)
2021-08-10 23:34:14 CEST DEBUG: pg_type: vac: 0 (threshold 122), anl: 0 (threshold 86)
2021-08-10 23:34:14 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: pg_attribute: vac: 0 (threshold 533), anl: 0 (threshold 292)
2021-08-10 23:34:14 CEST DEBUG: pg_class: vac: 0 (threshold 113), anl: 0 (threshold 82)
2021-08-10 23:34:14 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:14 CEST DEBUG: pg_operator: vac: 0 (threshold 205), anl: 0 (threshold 128)
2021-08-10 23:34:14 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:34:14 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:34:14 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:34:14 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:34:14 CEST DEBUG: pg_description: vac: 1 (threshold 818), anl: 1 (threshold 434)
2021-08-10 23:34:14 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:34:14 CEST DEBUG: pg_namespace: vac: 4 (threshold 51), anl: 4 (threshold 51)
2021-08-10 23:34:14 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: pg_shdepend: vac: 25 (threshold 52), anl: 48 (threshold 51)
2021-08-10 23:34:14 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: CommitTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:14 CEST DEBUG: exit(0)
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:14 CEST DEBUG: server process (PID 9044206) exited with exit code 0
2021-08-10 23:34:29 CEST DEBUG: StartTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: CommitTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: received inquiry for database 0
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:29 CEST DEBUG: InitPostgres
2021-08-10 23:34:29 CEST DEBUG: StartTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: CommitTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: autovacuum: processing database "spg"
2021-08-10 23:34:29 CEST DEBUG: received inquiry for database 16386
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/db_16386.stat"
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:29 CEST DEBUG: StartTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: din: vac: 0 (threshold 1201), anl: 0 (threshold 625)
2021-08-10 23:34:29 CEST DEBUG: fb01_fragen: vac: 0 (threshold 123), anl: 0 (threshold 87)
2021-08-10 23:34:29 CEST DEBUG: fb01_kennung: vac: 0 (threshold 250), anl: 0 (threshold 150)
2021-08-10 23:34:29 CEST DEBUG: fb03_fragen: vac: 0 (threshold 132), anl: 0 (threshold 91)
2021-08-10 23:34:29 CEST DEBUG: fb03_kennung: vac: 0 (threshold 650), anl: 0 (threshold 350)
2021-08-10 23:34:29 CEST DEBUG: fb04_fragen: vac: 0 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: fb04_kennung: vac: 0 (threshold 678), anl: 0 (threshold 364)
2021-08-10 23:34:29 CEST DEBUG: st_kataloge: vac: 0 (threshold 152), anl: 0 (threshold 101)
2021-08-10 23:34:29 CEST DEBUG: te_handbuch: vac: 0 (threshold 50), anl: 2 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: te_kataloge: vac: 0 (threshold 258), anl: 0 (threshold 154)
2021-08-10 23:34:29 CEST DEBUG: tele_bcn: vac: 0 (threshold 64), anl: 0 (threshold 57)
2021-08-10 23:34:29 CEST DEBUG: tele_bn: vac: 0 (threshold 50), anl: 27 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_extern: vac: 0 (threshold 148), anl: 0 (threshold 99)
2021-08-10 23:34:29 CEST DEBUG: tele_gps: vac: 0 (threshold 65), anl: 0 (threshold 57)
2021-08-10 23:34:29 CEST DEBUG: tele_konzern: vac: 0 (threshold 347), anl: 0 (threshold 199)
2021-08-10 23:34:29 CEST DEBUG: tele_kurzwahl: vac: 0 (threshold 206), anl: 0 (threshold 128)
2021-08-10 23:34:29 CEST DEBUG: tele_mwmx: vac: 0 (threshold 50), anl: 8 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_statistic: vac: 84 (threshold 127), anl: 436 (threshold 88)
2021-08-10 23:34:29 CEST DEBUG: pg_type: vac: 0 (threshold 145), anl: 0 (threshold 97)
2021-08-10 23:34:29 CEST DEBUG: tele_pers: vac: 0 (threshold 674), anl: 0 (threshold 362)
2021-08-10 23:34:29 CEST DEBUG: tele_psb: vac: 0 (threshold 91), anl: 0 (threshold 71)
2021-08-10 23:34:29 CEST DEBUG: tele_sachvz: vac: 0 (threshold 121), anl: 0 (threshold 86)
2021-08-10 23:34:29 CEST DEBUG: tele_satg: vac: 0 (threshold 100), anl: 0 (threshold 75)
2021-08-10 23:34:29 CEST DEBUG: tele_sath: vac: 0 (threshold 117), anl: 0 (threshold 83)
2021-08-10 23:34:29 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sda: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: tele_shc: vac: 0 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_shp: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: tele_sib: vac: 0 (threshold 50), anl: 3 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sicc: vac: 0 (threshold 50), anl: 4 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sicd: vac: 0 (threshold 72), anl: 0 (threshold 61)
2021-08-10 23:34:29 CEST DEBUG: tele_sim: vac: 0 (threshold 50), anl: 21 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_smg: vac: 0 (threshold 110), anl: 0 (threshold 80)
2021-08-10 23:34:29 CEST DEBUG: tele_smg_save: vac: 0 (threshold 109), anl: 0 (threshold 80)
2021-08-10 23:34:29 CEST DEBUG: tele_spe: vac: 0 (threshold 50), anl: 20 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sru: vac: 0 (threshold 50), anl: 9 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_ssf: vac: 0 (threshold 50), anl: 26 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sspc: vac: 0 (threshold 75), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: tele_tsp: vac: 0 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_vse: vac: 0 (threshold 50), anl: 13 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_attribute: vac: 122 (threshold 807), anl: 0 (threshold 429)
2021-08-10 23:34:29 CEST DEBUG: pg_proc: vac: 0 (threshold 615), anl: 28 (threshold 332)
2021-08-10 23:34:29 CEST DEBUG: pg_class: vac: 2 (threshold 135), anl: 0 (threshold 93)
2021-08-10 23:34:29 CEST DEBUG: pg_attrdef: vac: 0 (threshold 119), anl: 0 (threshold 84)
2021-08-10 23:34:29 CEST DEBUG: pg_constraint: vac: 0 (threshold 50), anl: 2 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 34 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: pg_operator: vac: 0 (threshold 205), anl: 0 (threshold 128)
2021-08-10 23:34:29 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:34:29 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:34:29 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:34:29 CEST DEBUG: pg_language: vac: 0 (threshold 51), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_aggregate: vac: 0 (threshold 78), anl: 0 (threshold 64)
2021-08-10 23:34:29 CEST DEBUG: pg_rewrite: vac: 0 (threshold 73), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: pg_description: vac: 1 (threshold 818), anl: 1 (threshold 434)
2021-08-10 23:34:29 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:34:29 CEST DEBUG: pg_namespace: vac: 4 (threshold 51), anl: 4 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_depend: vac: 0 (threshold 1516), anl: 614 (threshold 783)
2021-08-10 23:34:29 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_shdepend: vac: 25 (threshold 53), anl: 48 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_collation: vac: 0 (threshold 53), anl: 0 (threshold 52)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16416: vac: 0 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16446: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16456: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16484: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16579: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16599: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16649: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_2618: vac: 0 (threshold 91), anl: 0 (threshold 70)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_2619: vac: 1 (threshold 52), anl: 66 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16697: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16873: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: CommitTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:29 CEST DEBUG: exit(0)
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:29 CEST DEBUG: server process (PID 9044208) exited with exit code 0
2021-08-10 23:34:44 CEST DEBUG: StartTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: CommitTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: received inquiry for database 0
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:44 CEST DEBUG: InitPostgres
2021-08-10 23:34:44 CEST DEBUG: StartTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: CommitTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: autovacuum: processing database "postgres"
2021-08-10 23:34:44 CEST DEBUG: received inquiry for database 12416
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/db_12416.stat"
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:44 CEST DEBUG: StartTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: pg_statistic: vac: 0 (threshold 127), anl: 0 (threshold 88)
2021-08-10 23:34:44 CEST DEBUG: pg_type: vac: 0 (threshold 122), anl: 0 (threshold 86)
2021-08-10 23:34:44 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_attribute: vac: 0 (threshold 533), anl: 0 (threshold 292)
2021-08-10 23:34:44 CEST DEBUG: pg_proc: vac: 0 (threshold 615), anl: 0 (threshold 332)
2021-08-10 23:34:44 CEST DEBUG: pg_class: vac: 0 (threshold 113), anl: 0 (threshold 82)
2021-08-10 23:34:44 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:44 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:34:44 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:34:44 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:34:44 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:34:44 CEST DEBUG: pg_description: vac: 1 (threshold 818), anl: 1 (threshold 434)
2021-08-10 23:34:44 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:34:44 CEST DEBUG: pg_namespace: vac: 4 (threshold 51), anl: 4 (threshold 51)
2021-08-10 23:34:44 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_shdepend: vac: 25 (threshold 50), anl: 48 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: CommitTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:44 CEST DEBUG: exit(0)
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:44 CEST DEBUG: server process (PID 9044210) exited with exit code 0
2021-08-10 23:34:49 CEST DEBUG: postmaster received signal 2
2021-08-10 23:34:49 CEST LOG: received fast shutdown request
2021-08-10 23:34:49 CEST LOG: aborting any active transactions
2021-08-10 23:34:49 CEST LOG: autovacuum launcher shutting down
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 6 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST LOG: shutting down
2021-08-10 23:34:49 CEST DEBUG: performing replication slot checkpoint
2021-08-10 23:34:49 CEST DEBUG: attempting to remove WAL segments older than log file 000000000000000000000001
2021-08-10 23:34:49 CEST DEBUG: SlruScanDirectory invoking callback on pg_subtrans/0000
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/global.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_12416.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_12416.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_16387.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_16387.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_16386.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_16386.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_1.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_1.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_0.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 5 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: cleaning up dynamic shared memory control segment with ID 563757097
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST LOG: database system is shut down
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make

Bye
Rainer

On 10.08.2021 19:07, Tom Lane wrote:

Rainer Tammer <pgsql@spg.schulergroup.com> writes:

2021-08-10 17:15:44 CEST  LOG:  00000: received fast shutdown request
2021-08-10 17:15:44 CEST  LOCATION:  pmdie, postmaster.c:2215

The postmaster simply dies after about 1 hour.

Something is sending the postmaster a SIGINT signal.
			regards, tom lane

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

16 августа 2021 г., 16:07:33

Hello,
Could this really be related to the auto vacuum?

Bye
Rainer
-----------
Hello,
I have some additional information:

I have now used 9.6.22 on AIX 7.1 TL5 SP8 (that's the lates 7.1 level).
Comiler IBM XLC/C++ V16.1.

export CFLAGS=-qsuppress=1500-010
export CC=cc_r <--- _r is thread safe
export CXX=xlC_r
export CONFIG_SHELL=/bin/bash

bash ./configure \
--with-includes=/opt/freeware/include/readline \
--with-libraries=/opt/freeware/lib \
--prefix=/usr/local/pgsql-9.6.22 \
--with-CC=cc_r \
--with-libxml \
--without-tcl \
--without-python

All "make check" test do run without an issue.
It's not like the hanging test we had worked on a couple years ago (were a SIGINT was blocked
https://www.postgresql.org/message-id/flat/32656.1393346132%40sss.pgh.pa.us#1328f6db2318885b185753f81307865c ).

It looks like the wrong process is getting a SIGINT right after an auto vacuum.

This is a debug log:

2021-08-10 23:28:49 CEST LOG: database system was shut down at 2021-08-10 23:28:40 CEST
2021-08-10 23:28:49 CEST LOG: MultiXact member wraparound protections are now enabled
2021-08-10 23:28:49 CEST LOG: autovacuum launcher started
2021-08-10 23:28:49 CEST LOG: database system is ready to accept connections
2021-08-10 23:33:36 CEST LOG: received fast shutdown request
2021-08-10 23:33:36 CEST LOG: aborting any active transactions
2021-08-10 23:33:36 CEST LOG: autovacuum launcher shutting down
2021-08-10 23:33:36 CEST LOG: shutting down
2021-08-10 23:33:36 CEST LOG: database system is shut down
2021-08-10 23:33:43 CEST DEBUG: postgres: PostmasterMain: initial environment dump:
2021-08-10 23:33:43 CEST DEBUG: -----------------------------------------
2021-08-10 23:33:43 CEST DEBUG:        _=/usr/local/pgsql-9.6.22/bin/postgres
2021-08-10 23:33:43 CEST DEBUG:        MANPATH=/usr/share/man:/opt/freeware/man:/usr/local/man:/usr/local/share/man:/usr/local/ssl/man:/usr/local/pgsql/man
2021-08-10 23:33:43 CEST DEBUG:        myid=postgres
2021-08-10 23:33:43 CEST DEBUG:        LANG=en_US
2021-08-10 23:33:43 CEST DEBUG:        PGTZ=NFT-1DFT
2021-08-10 23:33:43 CEST DEBUG:        LOGIN=postgres
2021-08-10 23:33:43 CEST DEBUG:        VISUAL=emacs
2021-08-10 23:33:43 CEST DEBUG:        CLCMD_PASSTHRU=1
2021-08-10 23:33:43 CEST DEBUG:        PATH=/usr/bin:/etc:/usr/sbin:/usr/ucb:/home/postgres/bin:/usr/bin/X11:/sbin:/usr/local/bin:/usr/dt/bin:/usr/local/pgsql/bin
2021-08-10 23:33:43 CEST DEBUG:        PG_GRANDPARENT_PID=10158176
2021-08-10 23:33:43 CEST DEBUG:        LC__FASTMSG=true
2021-08-10 23:33:43 CEST DEBUG:        LOGNAME=postgres
2021-08-10 23:33:43 CEST DEBUG:        MAIL=/usr/spool/mail/postgres
2021-08-10 23:33:43 CEST DEBUG:        HOSTNAME=wwwlegacy
2021-08-10 23:33:43 CEST DEBUG:        LOCPATH=/usr/lib/nls/loc
2021-08-10 23:33:43 CEST DEBUG:        USER=postgres
2021-08-10 23:33:43 CEST DEBUG:        AUTHSTATE=files
2021-08-10 23:33:43 CEST DEBUG:        DSM_LOG=/usr/tivoli/tsm/client/ba/bin64/log
2021-08-10 23:33:43 CEST DEBUG:        LC_CTYPE=de_DE.ISO8859-1
2021-08-10 23:33:43 CEST DEBUG:        DISPLAY=rtdhcp19:0
2021-08-10 23:33:43 CEST DEBUG:        SHELL=/usr/bin/ksh
2021-08-10 23:33:43 CEST DEBUG:        ODMDIR=/etc/objrepos
2021-08-10 23:33:43 CEST DEBUG:        PGDATA=/usr/local/pgsql/data
2021-08-10 23:33:43 CEST DEBUG:        HOME=/home/postgres
2021-08-10 23:33:43 CEST DEBUG:        LC_COLLATE=de_DE.ISO8859-1
2021-08-10 23:33:43 CEST DEBUG:        PGSYSCONFDIR=/usr/local/pgsql-9.6.22/etc
2021-08-10 23:33:43 CEST DEBUG:        TERM=xterm
2021-08-10 23:33:43 CEST DEBUG:        DSM_DIR=/usr/tivoli/tsm/client/ba/bin64
2021-08-10 23:33:43 CEST DEBUG:        MAILMSG=[YOU HAVE NEW MAIL]
2021-08-10 23:33:43 CEST DEBUG:        PWD=/home/postgres
2021-08-10 23:33:43 CEST DEBUG:        TZ=Europe/Berlin
2021-08-10 23:33:43 CEST DEBUG:        ENV=/.env
2021-08-10 23:33:43 CEST DEBUG:        DSM_CONFIG=/usr/tivoli/tsm/client/ba/bin64/dsm.opt
2021-08-10 23:33:43 CEST DEBUG:        PGLIB=/usr/local/pgsql/lib
2021-08-10 23:33:43 CEST DEBUG:        A__z=! LOGNAME
2021-08-10 23:33:43 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-10 23:33:43 CEST DEBUG:        LD_LIBRARY_PATH=:/usr/local/pgsql/lib
2021-08-10 23:33:43 CEST DEBUG:        LC_MESSAGES=en_US
2021-08-10 23:33:43 CEST DEBUG:        LC_MONETARY=C
2021-08-10 23:33:43 CEST DEBUG:        LC_NUMERIC=C
2021-08-10 23:33:43 CEST DEBUG:        LC_TIME=C
2021-08-10 23:33:43 CEST DEBUG: -----------------------------------------
2021-08-10 23:33:43 CEST DEBUG: invoking IpcMemoryCreate(size=146317312)
2021-08-10 23:33:43 CEST DEBUG: SlruScanDirectory invoking callback on pg_notify/0000
2021-08-10 23:33:43 CEST DEBUG: removing file "pg_notify/0000"
2021-08-10 23:33:43 CEST DEBUG: dynamic shared memory system will support 288 segments
2021-08-10 23:33:43 CEST DEBUG: created dynamic shared memory control segment 563757097 (2316 bytes)
2021-08-10 23:33:43 CEST DEBUG: max_safe_fds = 984, usable_fds = 1000, already_open = 6
2021-08-10 23:33:43 CEST LOG: database system was shut down at 2021-08-10 23:33:36 CEST
2021-08-10 23:33:43 CEST DEBUG: checkpoint record is at 0/216C380
2021-08-10 23:33:43 CEST DEBUG: redo record is at 0/216C380; shutdown TRUE
2021-08-10 23:33:43 CEST DEBUG: next transaction ID: 0:2138; next OID: 18958
2021-08-10 23:33:43 CEST DEBUG: next MultiXactId: 1; next MultiXactOffset: 0
2021-08-10 23:33:43 CEST DEBUG: oldest unfrozen transaction ID: 553, in database 1
2021-08-10 23:33:43 CEST DEBUG: oldest MultiXactId: 1, in database 1
2021-08-10 23:33:43 CEST DEBUG: commit timestamp Xid oldest/newest: 0/0
2021-08-10 23:33:43 CEST DEBUG: transaction ID wrap limit is 2147484200, limited by database with OID 1
2021-08-10 23:33:43 CEST DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1
2021-08-10 23:33:43 CEST DEBUG: starting up replication slots
2021-08-10 23:33:43 CEST DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1
2021-08-10 23:33:43 CEST LOG: MultiXact member wraparound protections are now enabled
2021-08-10 23:33:43 CEST DEBUG: MultiXact member stop limit is now 4294914944 based on MultiXact 1
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(0): 4 on_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:33:43 CEST DEBUG: exit(0)
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:33:43 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:33:43 CEST DEBUG: checkpointer updated shared memory configuration values
2021-08-10 23:33:43 CEST LOG: autovacuum launcher started
2021-08-10 23:33:43 CEST DEBUG: InitPostgres
2021-08-10 23:33:43 CEST DEBUG: StartTransaction
2021-08-10 23:33:43 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:43 CEST DEBUG: CommitTransaction
2021-08-10 23:33:43 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_12416.stat"
2021-08-10 23:33:43 CEST LOG: database system is ready to accept connections
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_16387.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_16386.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_1.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/db_0.stat"
2021-08-10 23:33:43 CEST DEBUG: removing permanent stats file "pg_stat/global.stat"
2021-08-10 23:33:43 CEST DEBUG: received inquiry for database 0
2021-08-10 23:33:43 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:33:43 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:33:59 CEST DEBUG: StartTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: CommitTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: received inquiry for database 0
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:33:59 CEST DEBUG: InitPostgres
2021-08-10 23:33:59 CEST DEBUG: StartTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: CommitTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: autovacuum: processing database "test"
2021-08-10 23:33:59 CEST DEBUG: received inquiry for database 16387
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/db_16387.stat"
2021-08-10 23:33:59 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:33:59 CEST DEBUG: StartTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: pg_statistic: vac: 121 (threshold 128), anl: 284 (threshold 89)
2021-08-10 23:33:59 CEST DEBUG: pg_type: vac: 0 (threshold 122), anl: 0 (threshold 86)
2021-08-10 23:33:59 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_attribute: vac: 0 (threshold 533), anl: 0 (threshold 292)
2021-08-10 23:33:59 CEST DEBUG: pg_proc: vac: 3 (threshold 615), anl: 6 (threshold 332)
2021-08-10 23:33:59 CEST DEBUG: pg_class: vac: 0 (threshold 113), anl: 0 (threshold 82)
2021-08-10 23:33:59 CEST DEBUG: pg_attrdef: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_constraint: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_inherits: vac: 9 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:33:59 CEST DEBUG: pg_operator: vac: 9 (threshold 205), anl: 12 (threshold 128)
2021-08-10 23:33:59 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:33:59 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:33:59 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:33:59 CEST DEBUG: pg_language: vac: 0 (threshold 51), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_largeobject_metadata: vac: 24 (threshold 50), anl: 36 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_aggregate: vac: 0 (threshold 78), anl: 0 (threshold 64)
2021-08-10 23:33:59 CEST DEBUG: pg_rewrite: vac: 6 (threshold 73), anl: 0 (threshold 62)
2021-08-10 23:33:59 CEST DEBUG: pg_largeobject: vac: 24 (threshold 62), anl: 18 (threshold 56)
2021-08-10 23:33:59 CEST DEBUG: pg_trigger: vac: 32 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_description: vac: 64 (threshold 818), anl: 127 (threshold 434)
2021-08-10 23:33:59 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:33:59 CEST DEBUG: pg_enum: vac: 15 (threshold 50), anl: 30 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_namespace: vac: 33 (threshold 52), anl: 0 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: pg_conversion: vac: 0 (threshold 76), anl: 0 (threshold 63)
2021-08-10 23:33:59 CEST DEBUG: pg_depend: vac: 0 (threshold 1516), anl: 0 (threshold 783)
2021-08-10 23:33:59 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_shdepend: vac: 25 (threshold 52), anl: 48 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_foreign_data_wrapper: vac: 3 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_foreign_server: vac: 3 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_foreign_table: vac: 3 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:33:59 CEST DEBUG: pg_toast_2619: vac: 2 (threshold 52), anl: 4 (threshold 51)
2021-08-10 23:33:59 CEST DEBUG: CommitTransaction
2021-08-10 23:33:59 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:33:59 CEST DEBUG: exit(0)
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:33:59 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:33:59 CEST DEBUG: server process (PID 13238500) exited with exit code 0
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: postgres child[9044204]: starting with (
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG:       postgres
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: )
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: InitPostgres
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: StartTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST DEBUG: forked new backend, pid=9044204 socket=9
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: CommitTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: StartTransactionCommand
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: StartTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: CommitTransactionCommand
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: CommitTransaction
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(0): 6 on_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: proc_exit(0): 3 callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: exit(0)
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:01 CEST 127.0.0.1 postgresDEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:01 CEST DEBUG: server process (PID 9044204) exited with exit code 0
2021-08-10 23:34:14 CEST DEBUG: StartTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: CommitTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: received inquiry for database 0
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:14 CEST DEBUG: InitPostgres
2021-08-10 23:34:14 CEST DEBUG: StartTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: CommitTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: autovacuum: processing database "template1"
2021-08-10 23:34:14 CEST DEBUG: received inquiry for database 1
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/db_1.stat"
2021-08-10 23:34:14 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:14 CEST DEBUG: StartTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: pg_statistic: vac: 14 (threshold 127), anl: 14 (threshold 88)
2021-08-10 23:34:14 CEST DEBUG: pg_type: vac: 0 (threshold 122), anl: 0 (threshold 86)
2021-08-10 23:34:14 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: pg_attribute: vac: 0 (threshold 533), anl: 0 (threshold 292)
2021-08-10 23:34:14 CEST DEBUG: pg_class: vac: 0 (threshold 113), anl: 0 (threshold 82)
2021-08-10 23:34:14 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:14 CEST DEBUG: pg_operator: vac: 0 (threshold 205), anl: 0 (threshold 128)
2021-08-10 23:34:14 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:34:14 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:34:14 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:34:14 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:34:14 CEST DEBUG: pg_description: vac: 1 (threshold 818), anl: 1 (threshold 434)
2021-08-10 23:34:14 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:34:14 CEST DEBUG: pg_namespace: vac: 4 (threshold 51), anl: 4 (threshold 51)
2021-08-10 23:34:14 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: pg_shdepend: vac: 25 (threshold 52), anl: 48 (threshold 51)
2021-08-10 23:34:14 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:14 CEST DEBUG: CommitTransaction
2021-08-10 23:34:14 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:14 CEST DEBUG: exit(0)
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:14 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:14 CEST DEBUG: server process (PID 9044206) exited with exit code 0
2021-08-10 23:34:29 CEST DEBUG: StartTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: CommitTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: received inquiry for database 0
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:29 CEST DEBUG: InitPostgres
2021-08-10 23:34:29 CEST DEBUG: StartTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: CommitTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: autovacuum: processing database "spg"
2021-08-10 23:34:29 CEST DEBUG: received inquiry for database 16386
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/db_16386.stat"
2021-08-10 23:34:29 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:29 CEST DEBUG: StartTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: din: vac: 0 (threshold 1201), anl: 0 (threshold 625)
2021-08-10 23:34:29 CEST DEBUG: fb01_fragen: vac: 0 (threshold 123), anl: 0 (threshold 87)
2021-08-10 23:34:29 CEST DEBUG: fb01_kennung: vac: 0 (threshold 250), anl: 0 (threshold 150)
2021-08-10 23:34:29 CEST DEBUG: fb03_fragen: vac: 0 (threshold 132), anl: 0 (threshold 91)
2021-08-10 23:34:29 CEST DEBUG: fb03_kennung: vac: 0 (threshold 650), anl: 0 (threshold 350)
2021-08-10 23:34:29 CEST DEBUG: fb04_fragen: vac: 0 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: fb04_kennung: vac: 0 (threshold 678), anl: 0 (threshold 364)
2021-08-10 23:34:29 CEST DEBUG: st_kataloge: vac: 0 (threshold 152), anl: 0 (threshold 101)
2021-08-10 23:34:29 CEST DEBUG: te_handbuch: vac: 0 (threshold 50), anl: 2 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: te_kataloge: vac: 0 (threshold 258), anl: 0 (threshold 154)
2021-08-10 23:34:29 CEST DEBUG: tele_bcn: vac: 0 (threshold 64), anl: 0 (threshold 57)
2021-08-10 23:34:29 CEST DEBUG: tele_bn: vac: 0 (threshold 50), anl: 27 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_extern: vac: 0 (threshold 148), anl: 0 (threshold 99)
2021-08-10 23:34:29 CEST DEBUG: tele_gps: vac: 0 (threshold 65), anl: 0 (threshold 57)
2021-08-10 23:34:29 CEST DEBUG: tele_konzern: vac: 0 (threshold 347), anl: 0 (threshold 199)
2021-08-10 23:34:29 CEST DEBUG: tele_kurzwahl: vac: 0 (threshold 206), anl: 0 (threshold 128)
2021-08-10 23:34:29 CEST DEBUG: tele_mwmx: vac: 0 (threshold 50), anl: 8 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_statistic: vac: 84 (threshold 127), anl: 436 (threshold 88)
2021-08-10 23:34:29 CEST DEBUG: pg_type: vac: 0 (threshold 145), anl: 0 (threshold 97)
2021-08-10 23:34:29 CEST DEBUG: tele_pers: vac: 0 (threshold 674), anl: 0 (threshold 362)
2021-08-10 23:34:29 CEST DEBUG: tele_psb: vac: 0 (threshold 91), anl: 0 (threshold 71)
2021-08-10 23:34:29 CEST DEBUG: tele_sachvz: vac: 0 (threshold 121), anl: 0 (threshold 86)
2021-08-10 23:34:29 CEST DEBUG: tele_satg: vac: 0 (threshold 100), anl: 0 (threshold 75)
2021-08-10 23:34:29 CEST DEBUG: tele_sath: vac: 0 (threshold 117), anl: 0 (threshold 83)
2021-08-10 23:34:29 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sda: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: tele_shc: vac: 0 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_shp: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: tele_sib: vac: 0 (threshold 50), anl: 3 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sicc: vac: 0 (threshold 50), anl: 4 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sicd: vac: 0 (threshold 72), anl: 0 (threshold 61)
2021-08-10 23:34:29 CEST DEBUG: tele_sim: vac: 0 (threshold 50), anl: 21 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_smg: vac: 0 (threshold 110), anl: 0 (threshold 80)
2021-08-10 23:34:29 CEST DEBUG: tele_smg_save: vac: 0 (threshold 109), anl: 0 (threshold 80)
2021-08-10 23:34:29 CEST DEBUG: tele_spe: vac: 0 (threshold 50), anl: 20 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sru: vac: 0 (threshold 50), anl: 9 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_ssf: vac: 0 (threshold 50), anl: 26 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_sspc: vac: 0 (threshold 75), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: tele_tsp: vac: 0 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: tele_vse: vac: 0 (threshold 50), anl: 13 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_attribute: vac: 122 (threshold 807), anl: 0 (threshold 429)
2021-08-10 23:34:29 CEST DEBUG: pg_proc: vac: 0 (threshold 615), anl: 28 (threshold 332)
2021-08-10 23:34:29 CEST DEBUG: pg_class: vac: 2 (threshold 135), anl: 0 (threshold 93)
2021-08-10 23:34:29 CEST DEBUG: pg_attrdef: vac: 0 (threshold 119), anl: 0 (threshold 84)
2021-08-10 23:34:29 CEST DEBUG: pg_constraint: vac: 0 (threshold 50), anl: 2 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 34 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: pg_operator: vac: 0 (threshold 205), anl: 0 (threshold 128)
2021-08-10 23:34:29 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:34:29 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:34:29 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:34:29 CEST DEBUG: pg_language: vac: 0 (threshold 51), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_aggregate: vac: 0 (threshold 78), anl: 0 (threshold 64)
2021-08-10 23:34:29 CEST DEBUG: pg_rewrite: vac: 0 (threshold 73), anl: 0 (threshold 62)
2021-08-10 23:34:29 CEST DEBUG: pg_description: vac: 1 (threshold 818), anl: 1 (threshold 434)
2021-08-10 23:34:29 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:34:29 CEST DEBUG: pg_namespace: vac: 4 (threshold 51), anl: 4 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_depend: vac: 0 (threshold 1516), anl: 614 (threshold 783)
2021-08-10 23:34:29 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_shdepend: vac: 25 (threshold 53), anl: 48 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_collation: vac: 0 (threshold 53), anl: 0 (threshold 52)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16416: vac: 0 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16446: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16456: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16484: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16579: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16599: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16649: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_2618: vac: 0 (threshold 91), anl: 0 (threshold 70)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_2619: vac: 1 (threshold 52), anl: 66 (threshold 51)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16697: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: pg_toast_16873: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:29 CEST DEBUG: CommitTransaction
2021-08-10 23:34:29 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:29 CEST DEBUG: exit(0)
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:29 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:29 CEST DEBUG: server process (PID 9044208) exited with exit code 0
2021-08-10 23:34:44 CEST DEBUG: StartTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: CommitTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: received inquiry for database 0
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:44 CEST DEBUG: InitPostgres
2021-08-10 23:34:44 CEST DEBUG: StartTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: CommitTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: autovacuum: processing database "postgres"
2021-08-10 23:34:44 CEST DEBUG: received inquiry for database 12416
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/global.stat"
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/db_12416.stat"
2021-08-10 23:34:44 CEST DEBUG: writing stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:44 CEST DEBUG: StartTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: pg_statistic: vac: 0 (threshold 127), anl: 0 (threshold 88)
2021-08-10 23:34:44 CEST DEBUG: pg_type: vac: 0 (threshold 122), anl: 0 (threshold 86)
2021-08-10 23:34:44 CEST DEBUG: pg_authid: vac: 3 (threshold 50), anl: 5 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_attribute: vac: 0 (threshold 533), anl: 0 (threshold 292)
2021-08-10 23:34:44 CEST DEBUG: pg_proc: vac: 0 (threshold 615), anl: 0 (threshold 332)
2021-08-10 23:34:44 CEST DEBUG: pg_class: vac: 0 (threshold 113), anl: 0 (threshold 82)
2021-08-10 23:34:44 CEST DEBUG: pg_index: vac: 0 (threshold 74), anl: 0 (threshold 62)
2021-08-10 23:34:44 CEST DEBUG: pg_opclass: vac: 0 (threshold 82), anl: 0 (threshold 66)
2021-08-10 23:34:44 CEST DEBUG: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 51)
2021-08-10 23:34:44 CEST DEBUG: pg_amop: vac: 0 (threshold 188), anl: 0 (threshold 119)
2021-08-10 23:34:44 CEST DEBUG: pg_amproc: vac: 0 (threshold 159), anl: 0 (threshold 105)
2021-08-10 23:34:44 CEST DEBUG: pg_description: vac: 1 (threshold 818), anl: 1 (threshold 434)
2021-08-10 23:34:44 CEST DEBUG: pg_cast: vac: 0 (threshold 93), anl: 0 (threshold 71)
2021-08-10 23:34:44 CEST DEBUG: pg_namespace: vac: 4 (threshold 51), anl: 4 (threshold 51)
2021-08-10 23:34:44 CEST DEBUG: pg_database: vac: 4 (threshold 50), anl: 6 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_tablespace: vac: 0 (threshold 50), anl: 0 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_shdepend: vac: 25 (threshold 50), anl: 48 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: pg_shdescription: vac: 1 (threshold 50), anl: 1 (threshold 50)
2021-08-10 23:34:44 CEST DEBUG: CommitTransaction
2021-08-10 23:34:44 CEST DEBUG: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(0): 7 on_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:44 CEST DEBUG: exit(0)
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:44 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:44 CEST DEBUG: server process (PID 9044210) exited with exit code 0
2021-08-10 23:34:49 CEST DEBUG: postmaster received signal 2
2021-08-10 23:34:49 CEST LOG: received fast shutdown request
2021-08-10 23:34:49 CEST LOG: aborting any active transactions
2021-08-10 23:34:49 CEST LOG: autovacuum launcher shutting down
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 6 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST LOG: shutting down
2021-08-10 23:34:49 CEST DEBUG: performing replication slot checkpoint
2021-08-10 23:34:49 CEST DEBUG: attempting to remove WAL segments older than log file 000000000000000000000001
2021-08-10 23:34:49 CEST DEBUG: SlruScanDirectory invoking callback on pg_subtrans/0000
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/global.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_12416.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_12416.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_16387.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_16387.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_16386.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_16386.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_1.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_1.stat"
2021-08-10 23:34:49 CEST DEBUG: writing stats file "pg_stat/db_0.stat"
2021-08-10 23:34:49 CEST DEBUG: removing temporary stats file "pg_stat_tmp/db_0.stat"
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(0): 5 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: cleaning up dynamic shared memory control segment with ID 563757097
2021-08-10 23:34:49 CEST DEBUG: proc_exit(0): 2 callbacks to make
2021-08-10 23:34:49 CEST LOG: database system is shut down
2021-08-10 23:34:49 CEST DEBUG: exit(0)
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2021-08-10 23:34:49 CEST DEBUG: proc_exit(-1): 0 callbacks to make

Bye
Rainer

On 10.08.2021 19:07, Tom Lane wrote:

Rainer Tammer <pgsql@spg.schulergroup.com> writes:

2021-08-10 17:15:44 CEST  LOG:  00000: received fast shutdown request
2021-08-10 17:15:44 CEST  LOCATION:  pmdie, postmaster.c:2215

The postmaster simply dies after about 1 hour.

Something is sending the postmaster a SIGINT signal.
			regards, tom lane

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

24 августа 2021 г., 14:55:11

Hello,
Could this really be related to the auto vacuum?
I have disabled auto vacuum and the instance is now running for ~ 3h.
I have imported ~ 500MB data and executed some queries via psql.

Any idea is appreciated!

This is the current config for 9.2.13:

max_connections = 100
shared_buffers = 32MB
log_min_messages = debug5
log_line_prefix = '%t %h %u'
log_timezone = 'Europe/Berlin'
autovacuum = off
datestyle = 'iso, mdy'
timezone = 'Europe/Berlin'
lc_messages = 'en_US'
lc_monetary = 'en_US'
lc_numeric = 'en_US'
lc_time = 'en_US'
default_text_search_config = 'pg_catalog.english'

I have set debug to 5, so that we get some additional information is the DB goes down unintended.

Bye
Rainer

Re: Postgres 9.2.13 on AIX 7.1

От

"David G. Johnston"

Дата:

24 августа 2021 г., 17:11:41

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.

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

25 августа 2021 г., 10:04:41

Hello,
A full vacuum does run without any issues.
The postmaster did run for ~ one day without auto vacuum turned on.

I have now re-enabled auto vacuum and wait for the tings to happen.
It may well be a coincidence that the server ended right after an auto vacuum run...

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.

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

25 августа 2021 г., 18:06:56

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.

Re: Postgres 9.2.13 on AIX 7.1

От

Tom Lane

Дата:

25 августа 2021 г., 18:13:22

Rainer Tammer <pgsql@spg.schulergroup.com> writes:
> 2021-08-25 16:22:33 CEST  DEBUG: postmaster received signal 2
> 2021-08-25 16:22:33 CEST  LOG:  received fast shutdown request

Well, something sent the postmaster SIGINT.  There isn't any
mechanism within Postgres itself that would do that; you need
to look for outside causes.

            regards, tom lane

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

25 августа 2021 г., 19:04:17

Hello,
It did run the server with auto vacuum disabled for ~ 24h - no server shutdown.
After re-enabling auto vacuum the server dies in less then 9 hours:

Started: 2021-08-25 08:12:29
Dies: 2021-08-25 16:22:33

During the time of the shutdown there was no access to the server.
No running applications and no psql cli sessions.

I will let it run over night and see it the server is going down again.
There is no software installed on this AIX LPAR which uses this instance or sends signals to the server.
I did only do some interaction during the day to see if the server is working correctly.
Unfortunately I can not really see in the main process which other process did sent the signal SIGINT.

This is the only correlation I see:

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

The time gap is 6s.... so it might be a bit far away from the last process exit.

I could migrate the test DB to 9.6.23 and see if the problem persists.
Would it be worth adding additional code before every signal to trace the source ID and the target PID as well as the source/target process name?

The OS is at the latest patch level.
The compiler is at the latest patch level.
The 9.2.x is at the latest patch level.

I can also run a trace tomorrow, this would give me some information:

Sample output (shortened):

Wed Aug 25 17:58:51 2021
System: AIX 7.2 Node: host
Machine: 000000000000
Internet Address: 00000000 1.1.1.1
At trace startup, the system contained 16 cpus, of which 16 were traced.
Buffering: Kernel Heap
This is from a 64-bit kernel.
Tracing only these hooks, 14e0

ID   PROCESS NAME   PID      TID      I SYSTEM CALL    ELAPSED_SEC     DELTA_MSEC   APPL    SYSCALL KERNEL INTERRUPT

001 trace          23789978 87687537                  0.000000000       0.000000                   TRACE ON channel 0
                                                                                                    Wed Aug 25 17:58:51 2021
14E postgres:      18743746 85000571                  7.903995939    2994.175459                   kill: signal SIGUSR1 to process 25166296 postgres
14E --1-           -1       85393753                  7.904962367       0.966428                   kill: signal SIGUSR2 to process 18743746 postgres:
14E --1-           -1       85393753                  7.946566507      41.604140                   kill: signal SIGUSR2 to process 18743746 postgres:
14E postgres:      18743746 85000571                 17.902007437    2992.131623                   kill: signal SIGUSR1 to process 25166296 postgres
14E --1-           -1       94437835                 17.903004949       0.997512                   kill: signal SIGUSR2 to process 18743746 postgres:
14E --1-           -1       94437835                 17.935897005      32.892056                   kill: signal SIGUSR2 to process 18743746 postgres:
14E postgres:      18743746 85000571                 28.001327251    3091.401199                   kill: signal SIGUSR1 to process 25166296 postgres
14E --1-           -1       40042983                 28.002307781       0.980530                   kill: signal SIGUSR2 to process 18743746 postgres:
14E --1-           -1       40042983                 28.032432646      30.124865                   kill: signal SIGUSR2 to process 18743746 postgres:
14E postgres:      18743746 85000571                 37.901060572    2991.083160                   kill: signal SIGUSR1 to process 25166296 postgres
14E --1-           -1       88539511                 37.902072470       1.011898                   kill: signal SIGUSR2 to process 18743746 postgres:
14E --1-           -1       88539511                 37.936426058      34.353588                   kill: signal SIGUSR2 to process 18743746 postgres:

I do not observe this with V8.x servers.

That stupid problem is taking my nerves!!

Bye
Rainer

On 25.08.2021 17:13, Tom Lane wrote:

Rainer Tammer <pgsql@spg.schulergroup.com> writes:

2021-08-25 16:22:33 CEST  DEBUG: postmaster received signal 2
2021-08-25 16:22:33 CEST  LOG:  received fast shutdown request

Well, something sent the postmaster SIGINT.  There isn't any
mechanism within Postgres itself that would do that; you need
to look for outside causes.
			regards, tom lane

Re: Postgres 9.2.13 on AIX 7.1

От

Tom Lane

Дата:

25 августа 2021 г., 19:19:30

Rainer Tammer <pgsql@spg.schulergroup.com> writes:
> It did run the server with auto vacuum disabled for ~ 24h - no server 
> shutdown.
> After re-enabling auto vacuum the server dies in less then 9 hours:

This is just speculation, but it fits the reported facts: somewhere
you've got something that tries to limit the resources consumed by
a background process, and when it decides the limit is exhausted
then it sends SIGINT.  Without autovacuum waking up every so often,
the time for PG-as-a-whole to hit the hypothetical limit would be
much longer.

> Would it be worth adding additional code before every signal to trace 
> the source ID and the target PID as well as the source/target process name?

I will be *mightily* astonished if the signal is coming from
within PG.  The more so since it appears to be happening while
the instance is entirely idle.

            regards, tom lane

Re: Postgres 9.2.13 on AIX 7.1

От

Rainer Tammer

Дата:

26 августа 2021 г., 09:45:36

Hello,
OK, I'll try to find out which process is sending the SIGINT.

Bye
Rainer

On 25.08.2021 18:19, Tom Lane wrote:

Rainer Tammer <pgsql@spg.schulergroup.com> writes:

It did run the server with auto vacuum disabled for ~ 24h - no server 
shutdown.
After re-enabling auto vacuum the server dies in less then 9 hours:

This is just speculation, but it fits the reported facts: somewhere
you've got something that tries to limit the resources consumed by
a background process, and when it decides the limit is exhausted
then it sends SIGINT.  Without autovacuum waking up every so often,
the time for PG-as-a-whole to hit the hypothetical limit would be
much longer.

Would it be worth adding additional code before every signal to trace 
the source ID and the target PID as well as the source/target process name?

I will be *mightily* astonished if the signal is coming from
within PG.  The more so since it appears to be happening while
the instance is entirely idle.
			regards, tom lane

Вход в личный кабинет

Восстановление пароля

Подтверждение аккаунта

Изменение пароля

Обсуждение: Postgres 9.2.13 on AIX 7.1