Date: Mon, 9 Aug 2021 08:40:04 -0400 From: Zaphod Beeblebrox <zbeeble@gmail.com> To: freebsd@walstatt-de.de Cc: FreeBSD CURRENT <freebsd-current@freebsd.org>, FreeBSD Ports <freebsd-ports@freebsd.org> Subject: Re: databases/postgresl13-server issue: micsompilation on IvyBridge arch? Message-ID: <CACpH0Mc2vJt1QZwefPZUsmG37gJxndAEsZOLFUTcA0v%2B6gFkpg@mail.gmail.com> In-Reply-To: <20210808112032.56889213@thor.intern.walstatt.dynvpn.de> References: <20210808112032.56889213@thor.intern.walstatt.dynvpn.de>
next in thread | previous in thread | raw e-mail | index | archive | help
--000000000000ed721205c91faf72 Content-Type: text/plain; charset="UTF-8" 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? 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 > > --000000000000ed721205c91faf72--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CACpH0Mc2vJt1QZwefPZUsmG37gJxndAEsZOLFUTcA0v%2B6gFkpg>