Re: databases/postgresl13-server issue: micsompilation on IvyBridge arch?

From: FreeBSD User <freebsd_at_walstatt-de.de>
Date: Tue, 10 Aug 2021 05:48:11 UTC
On Mon, 9 Aug 2021 08:40:04 -0400
Zaphod Beeblebrox <zbeeble@gmail.com> wrote:

> IIRC, isn't the postgresql-server's default install on FreeBSD, from ports,
> have TCP turned off?  IE: try editing the config (in the database
> directory) to uncomment the listen directive?

Hello and thank you very much for responding. I do not understand what you mean
by "editing the config (in the database directory). Do you mean by that the
postgresql.conf file? Well, this file is proper set and has been, the
installation has worked well once until May the 26th. I try out to figure out
what happened to CURRENT that time.

In the meanwhile, I tried to rebuild CURRENT from scratch with
WITHOUT_OPENSSL_KTLS set, avoiding any CPU optimization during compilation of
world and postgresql - but without any effect. The pain is, that two boxes
ofthe same CPU arch affected the same way, no matter what I do. 



> 
> On Sun, Aug 8, 2021 at 5:21 AM FreeBSD User <freebsd@walstatt-de.de> wrote:
> 
> > Hello,
> >
> > on all(!) of my home systems based on Intel's IvyBridge CPU architecture
> >
> > a) CPU microcode: updated from 0x1f to 0x21
> >    CPU: Intel(R) Core(TM) i5-3470 CPU @ 3.20GHz (3200.09-MHz K8-class CPU)
> >
> > b) CPU microcode: updated from 0x1f to 0x21
> >    CPU: Intel(R) Xeon(R) CPU E3-1245 V2 @ 3.40GHz (3400.09-MHz K8-class
> > CPU)
> >
> > I face a severe and nasty problem:
> >
> > database/postgresql12-server, database/postgresql13-server,
> > database/postgresql14-server, when
> > installed, do not allow any kind of tcp/ip connections, even on ::1 or
> > 127.0.0.1 (localhost).
> > All systems in question are dual stack and fully configured using IPv6.
> > Firewall is FreeBSD
> > standard IPFW running from /etc/rc.conf (port 5432/tcp is open and
> > listening as one can check
> > via sockstat -4 or sockstat -6).
> >
> > The hosts in question do run 14-CURRENT (with customized kernels).
> >
> > Phenomenon:
> >
> > Login locally via "psql -U postgres -d postgres" via socket works for ALL
> > DB users on all
> > configured to access databases as expected. Login via "psql -U postgres -d
> > postgres -h
> > localhost" (or any form of an IP if access tried from another remote host,
> > even locally via
> > 127.0.0.1 or ::1) does result in:
> >
> > : psql -U postgres -d postgres -h localhost
> > psql: error: server closed the connection unexpectedly
> >         This probably means the server terminated abnormally
> >         before or while processing the request.
> >
> > On the server's postgresql log I always see connection attempts like:
> >
> > [...]
> > 2021-08-08 08:56:57.601 GMT [42987] LOG:  connection received:
> > host=localhost port=12340
> >
> > but nothing more, no error message or any kind of timeout message.
> >
> > I tried to raise the log level to debug, but it is always nothing shown
> > execept the initial
> > connection attempt.
> >
> > What I tried so far:
> > I used either self compiled ports or packages taken via pkg fetch from the
> > official FreeBSD
> > pkg repos. I had LLVM suspected to miscompile something on IvyBridge. No
> > different result so
> > far. Postgres 12, 13 14 fail the same way.
> >
> > I installed with the above strategy vanilla databases. That includes a
> > pg_hba.conf with the
> > follwoing lines (as anybody can proof):
> >
> > [...]
> > # TYPE  DATABASE        USER            ADDRESS                 METHOD
> >
> > # "local" is for Unix domain socket connections only
> > local   all             all                                     trust
> > # IPv4 local connections:
> > host    all             all             127.0.0.1/32            trust
> > # IPv6 local connections:
> > host    all             all             ::1/128                 trust
> > host    all             all             0.0.0.0/32              trust
> > host    all             all             ::/128                  trust
> >
> >
> > That should grant access via "localhost" and, for test purposes, access
> > from any other machine
> > in our LAN for any user to any database.
> >
> > Also, I configured postgresql13-server's postgresql.conf with following
> > additions:
> >
> > log_destination = 'syslog,stderr'
> > log_min_messages = debug5
> > log_min_error_statement = debug5
> >
> > debug_print_parse = on
> > debug_print_rewritten = on
> > debug_print_plan = on
> > debug_pretty_print = on
> > log_checkpoints = on
> > log_connections = on
> > log_disconnections = on
> > log_duration = on
> > log_error_verbosity = verbose       # terse, default, or verbose messages
> > log_hostname = on
> >
> > Trying again a login from localhost via the psql command show above, gives
> > this :
> >
> >
> > [...]
> > 2021-08-08 09:12:12.999 GMT [55664] DEBUG:  00000: forked new backend,
> > pid=55673 socket=12
> >
> > 2021-08-08 09:12:12.999 GMT [55664] LOCATION:  BackendStartup,
> > postmaster.c:4232
> >
> > 2021-08-08 09:12:13.000 GMT [55673] LOG:  00000: connection received:
> > host=localhost
> > port=42708
> >
> > 2021-08-08 09:12:13.000 GMT [55673] LOCATION:  BackendInitialize,
> > postmaster.c:4385
> >
> > 2021-08-08 09:12:19.994 GMT [55667] DEBUG:  00000: snapshot of 0+0 running
> > transaction ids
> > (lsn 0/15FF178 oldest xid 487 latest complete 486 next xid 487)
> > 2021-08-08 09:12:19.994 GMT [55667] LOCATION:  LogCurrentRunningXacts,
> > standby.c:1124
> > 2021-08-08 09:13:04.988 GMT [55669] DEBUG:  00000: StartTransaction(1)
> > name: unnamed;
> > blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
> > 2021-08-08 09:13:04.988 GMT [55669] LOCATION:  ShowTransactionStateRec,
> > xact.c:5358
> > 2021-08-08 09:13:04.988 GMT [55669] DEBUG:  00000: CommitTransaction(1)
> > name: unnamed;
> > blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
> > 2021-08-08 09:13:04.988 GMT [55669] LOCATION:  ShowTransactionStateRec,
> > xact.c:5358
> > 2021-08-08 09:13:04.988 GMT [55670] DEBUG:  00000: received inquiry for
> > database 0
> > 2021-08-08 09:13:04.988 GMT [55670] LOCATION:  pgstat_recv_inquiry,
> > pgstat.c:5872
> > 2021-08-08 09:13:04.988 GMT [55670] DEBUG:  00000: writing stats file
> > "pg_stat_tmp/global.stat"
> > 2021-08-08 09:13:04.988 GMT [55670] LOCATION:  pgstat_write_statsfiles,
> > pgstat.c:4879
> > 2021-08-08 09:13:04.988 GMT [55670] DEBUG:  00000: writing stats file
> > "pg_stat_tmp/db_0.stat"
> > 2021-08-08 09:13:04.988 GMT [55670] LOCATION:  pgstat_write_db_statsfile,
> > pgstat.c:5042
> > 2021-08-08 09:13:05.000 GMT [55674] DEBUG:  00000: InitPostgres
> > 2021-08-08 09:13:05.000 GMT [55674] LOCATION:  InitPostgres, postinit.c:587
> > 2021-08-08 09:13:05.000 GMT [55674] DEBUG:  00000: my backend ID is 3
> > 2021-08-08 09:13:05.000 GMT [55674] LOCATION:  SharedInvalBackendInit,
> > sinvaladt.c:323
> > 2021-08-08 09:13:05.000 GMT [55674] DEBUG:  00000: StartTransaction(1)
> > name: unnamed;
> > blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
> > 2021-08-08 09:13:05.000 GMT [55674] LOCATION:  ShowTransactionStateRec,
> > xact.c:5358
> > 2021-08-08 09:13:05.005 GMT [55674] DEBUG:  00000: CommitTransaction(1)
> > name: unnamed;
> > blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
> > 2021-08-08 09:13:05.005 GMT [55674] LOCATION:  ShowTransactionStateRec,
> > xact.c:5358
> > 2021-08-08 09:13:05.005 GMT [55674] DEBUG:  00000: autovacuum: processing
> > database "postgres"
> > 2021-08-08 09:13:05.005 GMT [55674] LOCATION:  AutoVacWorkerMain,
> > autovacuum.c:1686
> > 2021-08-08 09:13:05.005 GMT [55670] DEBUG:  00000: received inquiry for
> > database 13805
> > 2021-08-08 09:13:05.005 GMT [55670] LOCATION:  pgstat_recv_inquiry,
> > pgstat.c:5872
> > 2021-08-08 09:13:05.005 GMT [55670] DEBUG:  00000: writing stats file
> > "pg_stat_tmp/global.stat"
> > 2021-08-08 09:13:05.005 GMT [55670] LOCATION:  pgstat_write_statsfiles,
> > pgstat.c:4879
> > 2021-08-08 09:13:05.005 GMT [55670] DEBUG:  00000: writing stats file
> > "pg_stat_tmp/db_13805.stat"
> > 2021-08-08 09:13:05.005 GMT [55670] LOCATION:  pgstat_write_db_statsfile,
> > pgstat.c:5042
> > 2021-08-08 09:13:05.005 GMT [55670] DEBUG:  00000: writing stats file
> > "pg_stat_tmp/db_0.stat"
> > 2021-08-08 09:13:05.005 GMT [55670] LOCATION:  pgstat_write_db_statsfile,
> > pgstat.c:5042
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: StartTransaction(1)
> > name: unnamed;
> > blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  ShowTransactionStateRec,
> > xact.c:5358
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_type: vac: 0
> > (threshold 132), ins: 0
> > (threshold 1082), anl: 0 (threshold 91)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_authid: vac: 1
> > (threshold 52), ins: 0
> > (threshold 1002), anl: 1 (threshold 51)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_attribute: vac: 0
> > (threshold 622), ins:
> > 0 (threshold 1572), anl: 0 (threshold 336)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_class: vac: 0
> > (threshold 127), ins: 0
> > (threshold 1077), anl: 0 (threshold 89)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_index: vac: 0
> > (threshold 81), ins: 0
> > (threshold 1031), anl: 0 (threshold 65)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_opclass: vac: 0
> > (threshold 76), ins: 0
> > (threshold 1026), anl: 0 (threshold 63)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_am: vac: 0
> > (threshold 51), ins: 0
> > (threshold 1001), anl: 0 (threshold 51)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_amproc: vac: 0
> > (threshold 147), ins: 0
> > (threshold 1097), anl: 0 (threshold 98)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: pg_database: vac: 0
> > (threshold 50), ins: 0
> > (threshold 1000), anl: 0 (threshold 50)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  relation_needs_vacanalyze,
> > autovacuum.c:3091
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: CommitTransaction(1)
> > name: unnamed;
> > blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  ShowTransactionStateRec,
> > xact.c:5358
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: shmem_exit(0): 1
> > before_shmem_exit
> > callbacks to make
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  shmem_exit, ipc.c:237
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: shmem_exit(0): 7
> > on_shmem_exit callbacks to
> > make
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  shmem_exit, ipc.c:270
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: proc_exit(0): 2
> > callbacks to make
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  proc_exit_prepare, ipc.c:197
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: exit(0)
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  proc_exit, ipc.c:150
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: shmem_exit(-1): 0
> > before_shmem_exit
> > callbacks to make
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  shmem_exit, ipc.c:237
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: shmem_exit(-1): 0
> > on_shmem_exit callbacks
> > to make
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  shmem_exit, ipc.c:270
> > 2021-08-08 09:13:05.016 GMT [55674] DEBUG:  00000: proc_exit(-1): 0
> > callbacks to make
> > 2021-08-08 09:13:05.016 GMT [55674] LOCATION:  proc_exit_prepare, ipc.c:197
> > 2021-08-08 09:13:05.018 GMT [55664] DEBUG:  00000: reaping dead processes
> > 2021-08-08 09:13:05.018 GMT [55664] LOCATION:  reaper, postmaster.c:2921
> > 2021-08-08 09:13:05.018 GMT [55664] DEBUG:  00000: server process (PID
> > 55674) exited with exit
> > code 0
> > 2021-08-08 09:13:05.018 GMT [55664] LOCATION:  LogChildExit,
> > postmaster.c:3714
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: shmem_exit(1): 0
> > before_shmem_exit
> > callbacks to make
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  shmem_exit, ipc.c:237
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: shmem_exit(1): 0
> > on_shmem_exit callbacks to
> > make
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  shmem_exit, ipc.c:270
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: proc_exit(1): 1
> > callbacks to make
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  proc_exit_prepare, ipc.c:197
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: exit(1)
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  proc_exit, ipc.c:150
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: shmem_exit(-1): 0
> > before_shmem_exit
> > callbacks to make
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  shmem_exit, ipc.c:237
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: shmem_exit(-1): 0
> > on_shmem_exit callbacks
> > to make
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  shmem_exit, ipc.c:270
> > 2021-08-08 09:13:13.000 GMT [55673] DEBUG:  00000: proc_exit(-1): 0
> > callbacks to make
> > 2021-08-08 09:13:13.000 GMT [55673] LOCATION:  proc_exit_prepare, ipc.c:197
> > 2021-08-08 09:13:13.001 GMT [55664] DEBUG:  00000: reaping dead processes
> > 2021-08-08 09:13:13.001 GMT [55664] LOCATION:  reaper, postmaster.c:2921
> > 2021-08-08 09:13:13.002 GMT [55664] DEBUG:  00000: server process (PID
> > 55673) exited with exit
> > code 1
> > 2021-08-08 09:13:13.002 GMT [55664] LOCATION:  LogChildExit,
> > postmaster.c:3714
> > [...]
> >
> >
> > I moved the complete DB configuration onto another Host running a more
> > modern XEON CPU (I do
> > not have the arch specs at hand, but it is one of Intel's later models of
> > the Core -i
> > generation 8000 I guess, purchased two years ago). We use a very similar
> > customized kernel
> > there, except for the SCSI/SAS controller and some mellanox NICs (the box
> > in question is a
> > Fujitsu, dual socket system).
> > The mysterious thing here is: nothing unusual on that box! I can run the
> > DB in a regular
> > manner, login from external sites/services, use the DB for the cloud
> > service and login via
> > localhost.
> >
> > And now I'm out of ideas and it slowly drives my crazy. Is there something
> > I miss?
> >
> > Appreciate help, thanks in advance and
> > kind regards
> > Oliver
> >
> >
> >
> > --
> > O. Hartmann
> >
> >