From nobody Mon Aug 9 12:40:04 2021 X-Original-To: freebsd-current@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4204411F8F01; Mon, 9 Aug 2021 12:40:18 +0000 (UTC) (envelope-from zbeeble@gmail.com) Received: from mail-ej1-x62a.google.com (mail-ej1-x62a.google.com [IPv6:2a00:1450:4864:20::62a]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1O1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4Gjwf91kwgz4SfM; Mon, 9 Aug 2021 12:40:17 +0000 (UTC) (envelope-from zbeeble@gmail.com) Received: by mail-ej1-x62a.google.com with SMTP id gs8so28590872ejc.13; Mon, 09 Aug 2021 05:40:17 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=Nr26vdDBei3JakzTsyJNzEX4Ns1OfvTf3lbpyVkcIkQ=; b=PQ7MW5a68sKGD0vFDG2VVlTyNYweSNyGzM9zj6mFt3i2YEI9XNQYCTFAAujE0pf/pv ygrqiU+HtkUH7Hs30X8sQOFDpw2HCNJyyPj9T2Yu0EBytlGjXQ769xmD4oly7ni/rYSU nf8rzq4fr0UraW8hdBge1PSXkKIFxIi4OPn7AfFe7xxHe+0lelPC7SoCOHaJ9ikU9wcc YqR9Oyaizer/yeffnBodp409EOZrvixYEzOgJAoax/UVSdhVlqNPRe+Vq9kXW7AXs+lT wZEdLOeKSr970FQodAoPKIxHXnrESwGeXlVw+Of/tdl2bhEG+RxN9Zeh36e2wwaaOIdM WlhA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=Nr26vdDBei3JakzTsyJNzEX4Ns1OfvTf3lbpyVkcIkQ=; b=Sg+2sEVPveXZuzE/fENvnlSRkyT3SmLbSZlPnkG3HIbATnAWY2rmiqZI4lwizdcsQV 7RG4XABbLxx3TcHGCjb9TLihN7FxkoqgmL6cyOgMdZvSm544rYIhzKIrsdsqFKJXPXMG OGuf6mrrWZbVAYBH/wY7kBVgGx0QRpvvRvl1RnUCUCxBM+fy4FkgPjunIoSsTfHb7OF0 m4EeIhuyKQ7Vm/rZC1T7RTunhd/hVbMhAMtksfM9zyUgNV6NMSURxLNeP+p0zvdCF1y7 tKLxbhdXHpbpY9+qlThxpMdL8BJ1qk5HzAdpCnokz89cXXjfn6NJGGsraT890XEh4FP0 DupQ== X-Gm-Message-State: AOAM5306UMShBZmajP7h2KRSIgc56CpQsi3qCXQCuAG38KlbnU1nhjVp mZ5kGnX2jAw4xJxc4comprvmJtISgV8nFgXFGA== X-Google-Smtp-Source: ABdhPJzF5DupaMl3xWQhjZ2+sCFalDXCjrqk+5fQvZTbqySrlh22tPKGLdVExbh86vg+5rUSQ104wxHNjz1BOJ63Luo= X-Received: by 2002:a17:906:af86:: with SMTP id mj6mr22553967ejb.144.1628512816295; Mon, 09 Aug 2021 05:40:16 -0700 (PDT) List-Id: Discussions about the use of FreeBSD-current List-Archive: https://lists.freebsd.org/archives/freebsd-current List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-current@freebsd.org MIME-Version: 1.0 References: <20210808112032.56889213@thor.intern.walstatt.dynvpn.de> In-Reply-To: <20210808112032.56889213@thor.intern.walstatt.dynvpn.de> From: Zaphod Beeblebrox Date: Mon, 9 Aug 2021 08:40:04 -0400 Message-ID: Subject: Re: databases/postgresl13-server issue: micsompilation on IvyBridge arch? To: freebsd@walstatt-de.de Cc: FreeBSD CURRENT , FreeBSD Ports Content-Type: multipart/alternative; boundary="000000000000ed721205c91faf72" X-Rspamd-Queue-Id: 4Gjwf91kwgz4SfM X-Spamd-Bar: - Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20161025 header.b=PQ7MW5a6; dmarc=pass (policy=none) header.from=gmail.com; spf=pass (mx1.freebsd.org: domain of zbeeble@gmail.com designates 2a00:1450:4864:20::62a as permitted sender) smtp.mailfrom=zbeeble@gmail.com X-Spamd-Result: default: False [-1.98 / 15.00]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20161025]; FROM_HAS_DN(0.00)[]; RCPT_COUNT_THREE(0.00)[3]; R_SPF_ALLOW(-0.20)[+ip6:2a00:1450:4000::/36:c]; FREEMAIL_FROM(0.00)[gmail.com]; MIME_GOOD(-0.10)[multipart/alternative,text/plain]; DWL_DNSWL_NONE(0.00)[gmail.com:dkim]; NEURAL_HAM_LONG(-1.00)[-1.000]; TO_DN_SOME(0.00)[]; TO_MATCH_ENVRCPT_SOME(0.00)[]; MID_RHS_MATCH_FROMTLD(0.00)[]; DKIM_TRACE(0.00)[gmail.com:+]; DMARC_POLICY_ALLOW(-0.50)[gmail.com,none]; RCVD_IN_DNSWL_NONE(0.00)[2a00:1450:4864:20::62a:from]; HTTP_TO_IP(1.00)[]; NEURAL_HAM_SHORT(-0.98)[-0.980]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+,1:+,2:~]; FREEMAIL_ENVFROM(0.00)[gmail.com]; ASN(0.00)[asn:15169, ipnet:2a00:1450::/32, country:US]; SUBJECT_ENDS_QUESTION(1.00)[]; RCVD_TLS_ALL(0.00)[]; RCVD_COUNT_TWO(0.00)[2] X-Spam: Yes X-ThisMailContainsUnwantedMimeParts: Y --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 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--