[Bug 1187392] New: postgresql13 segfaults
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 Bug ID: 1187392 Summary: postgresql13 segfaults Classification: openSUSE Product: openSUSE Distribution Version: Leap 15.3 Hardware: Other OS: Other Status: NEW Severity: Critical Priority: P5 - None Component: Other Assignee: max@suse.com Reporter: bwiedemann@suse.com QA Contact: qa-bugs@suse.de Found By: --- Blocker: --- Over the last days, we had our "mirrordb" postgresql13 instance break on at least 3 occasions, affecting users of services using it: download.o.o, MLs, weblate, chat.o.o etc https://progress.opensuse.org/issues/93686 The version is postgresql13-13.3-lp153.27.1 Install Date: Thu 20 May 2021 09:13:16 PM UTC from server:database:postgresql / openSUSE_Leap_15.3 We also found duplicate entries in rows that were supposed to have UNIQUE keys. For now we downgraded to postgresql12 to keep the operations going smoothly, but crashes and data corruptions in DB software are really something that must be fixed. I got 150 GB of DB data backup to aid in the investigation, but so far we do not have a reproducer to trigger corruption outside the live system. During normal operation, all writes went to mirrordb1 and mirrordb2 did replication (using repmgr and wal) to serve read requests from download.o.o / mirrorbrain. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c1 --- Comment #1 from Reinhard Max <max@suse.com> --- I need more details to narrow this down: - How was the database showing the crashes and duplicates created and populated (pg_upgrade, replication, restore of a dump, etc.)? - When was PostgreSQL being upgraded? - When was the OS upgraded from 15.2 to 15.3? - When did the first crash happen? I suppose the duplicate entries are due to the system upgrade that contains a glibc upgrade that comes with heavy changes to collations which in turn requires reindexing of all indexes on text columns in PostgreSQL that use one of the affected collations. This would be the case if the database was migrated using pg_upgrade along with the system upgrade, or if PostgreSQL was upgraded to 13 on 15.2 (regardless of the migration method) and the system upgrade happened afterwards. See also https://bugzilla.suse.com/show_bug.cgi?id=1187217 https://www.cybertec-postgresql.com/en/icu-collations-against-glibc-2-28-dat... Not sure about the segfaults. They might be a consequence of the corrupted indexes, although I haven't yet heared of them causing crashes. I'd say let's address the corrupted indexes first and then see if the crashes still happen. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c2 Bernhard Wiedemann <bwiedemann@suse.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |andrii.nikitin@suse.com --- Comment #2 from Bernhard Wiedemann <bwiedemann@suse.com> --- /var/log/zypp/history had this: 2021-03-11 08:00:17|install|postgresql11|11.11-lp152.44.1|server_database_postgresql 2021-03-22 09:46:31|install|postgresql13|13.2-lp152.22.2|root@mirrordb1|server_database_postgresql 2021-03-25 19:07:02|install|postgresql11|11.11-lp152.47.2|server_database_postgresql| 2021-04-01 12:41:37|remove |postgresql11|11.11-lp152.47.2|root@mirrordb1| 2021-04-22 07:15:12|install|postgresql13|13.2-lp152.23.1|server_database_postgresql 2021-04-29 19:41:42|install|postgresql13|13.2-lp152.25.1|server_database_postgresql 2021-05-20 21:13:16|install|postgresql13|13.3-lp153.27.1|server_database_postgresql The /var/lib/pgsql/data11 dir has last updates from 2021-04-01 so that must have been when postgresql13 went into use. The ticket was from 2021-06-09, but the timestamp on a segfault was 2021-06-05T10:56:53 update to 15.3 was 2021-05-20 21:11:23|install|openSUSE-release|15.3-lp153.129.1 and that was also when postgres 13.3 replaced 13.2 -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c3 --- Comment #3 from Bernhard Wiedemann <bwiedemann@suse.com> --- I checked the journal and found that the very first segfault happened not even 3h after the dist-upgrade: May 21 00:00:27 mirrordb1 systemd[1]: Removed slice User Slice of UID 65534. May 21 00:00:45 mirrordb1 sshd[1407]: Connection closed by 192.168.47.7 port 516 32 [preauth] May 21 00:01:17 mirrordb1 kernel: show_signal_msg: 18 callbacks suppressed May 21 00:01:17 mirrordb1 kernel: postgres[32567]: segfault at 5626bf85dffa ip 00007ff966d7612e sp 00007ffd90595538 error 4 in libc-2.31.so[7ff966c30000+1cb000] May 21 00:01:18 mirrordb1 kernel: Code: 0f ae f8 4c 8d 1d c2 df 05 00 49 63 14 93 49 8d 14 13 ff e2 0f 0b 66 0f 1f 44 00 00 0f 18 8e 40 fe ff ff 0f 18 8e 00 fe ff ff <f3> 0f 6f 46 f0 f3 0f 6f 4e e0 f3 0f 6f 56 d0 f3 0f 6f 5e c0 f3 0f May 21 00:01:18 mirrordb1 prometheus-postgres_exporter[1232]: time="2021-05-21T00:01:18Z" level=warning msg="Proceeding with outdated query maps, as the Postgres version could not be determined: Error scanning version string: pq: the database system is in recovery mode" source="postgres_exporter.go:1081" That is a pretty strong indication that something is bad in that 15.3 + server_database_postgresql combination. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c4 --- Comment #4 from Andrii Nikitin <andrii.nikitin@suse.com> --- It worth to mention that dozens unique key violations happened on 3 independent postgres instances at mirrorcache.o.o, mirrorcache-us.o.o and mirrorcache-eu.o.o three weeks ago, which had fully default config and also upgraded from leap-15.2 (default packages) to leap-15.3 (default packages). Then at least one occurrence happened afterward. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c5 --- Comment #5 from Reinhard Max <max@suse.com> --- Yes, that's to be expected due to the collation changes that come with the glibc upgrade. I only learned yesteday because of similar problems in SUMA that this change has such a huge impact. Running REINDEX against the affected databases should fix it, and we'll have to see if it also stops the segfaults. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c6 --- Comment #6 from Reinhard Max <max@suse.com> --- Of course, this REINDEX should happen immediately after the glibc upgrade and before productive write access is allowed to the database again, because if the corrupted index gets actually used it might cause further damage to the data. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c7 --- Comment #7 from Bernhard Wiedemann <bwiedemann@suse.com> --- May 20 21:29:00 mirrordb1 systemd-fsck[348]: ROOT: recovering journal May 20 21:29:00 mirrordb1 kernel: random: fast init done May 20 21:29:00 mirrordb1 systemd-fsck[348]: ROOT: Clearing orphaned inode 125827 (uid=0, gid=0, mode=0100644, size=10406312) May 20 21:29:00 mirrordb1 systemd-fsck[348]: ROOT: Clearing orphaned inode 128894 (uid=0, gid=498, mode=0100640, size=8388608) May 20 21:29:13 mirrordb1 kernel: XFS (vdb): Ending recovery (logdev: internal) May 21 00:00:08 mirrordb1 systemd[1]: Starting Rotate log files... May 21 00:00:14 mirrordb1 systemd[1]: Finished Rotate log files. The "orphaned inode" messages for vda1 (root partition) indicate that there might have been an earlier unclean shutdown (e.g. there was the power outage 20201118), so maybe postgresql data on vdb (xfs) was not as consistent as they should be. The logrotate could have triggered a service reload, but OTOH, I dont see any postgres-related files in /etc/logrotate.d/ -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c8 --- Comment #8 from Reinhard Max <max@suse.com> --- I am not sure I can follow you here. If the machine crashed due to a power outage in November 2020 the FS corruption should have been detected at the first boot after that rather than half a year later. Those fsck messages appear to come from booting into 15.3 for the first time after the upgrade. Could it be that shutdown got stuck after the upgrade (assuming it was done from the running system) and the machine had to be reset, potentially leading to the FS corruption? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c9 --- Comment #9 from Bernhard Wiedemann <bwiedemann@suse.com> ---
Could it be that shutdown got stuck after the upgrade (assuming it was done from the running system) and the machine had to be reset, potentially leading to the FS corruption?
logs show this: May 20 21:27:09 mirrordb1 salt-minion[21459]: The Salt Minion is shutdown. Minion received a SIGTERM. Exited. May 20 21:27:10 mirrordb1 systemd[1]: salt-minion.service: Succeeded. May 20 21:27:10 mirrordb1 systemd[1]: Stopped The Salt Minion. May 20 21:27:18 mirrordb1 systemd[1]: postgresql.service: Succeeded. May 20 21:27:18 mirrordb1 systemd[1]: Stopped PostgreSQL database server. -- Reboot -- May 20 21:28:59 mirrordb1 kernel: Linux version 5.3.18-57-default (geeko@buildhost) (gcc version 7.5.0 (SUSE Linux)) #1 SMP Wed Apr 28 10:54:41 UTC 2021 (ba3c2e9) May 20 21:28:59 mirrordb1 kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-5.3.18-57-default root=UUID=5cb86df2-370f-42b8-bb1a-188d7feb4d8c root=/dev/vda1 disk=/dev/vda resume=/dev/vda2 console=tty0 console=ttyS0,115200 quiet It probably was a live update, because messages appeared in the journal. Since this is a VM, BIOS+bootloader should take below 20s, so that leaves 70s after postgresql stop was finished - that should have been enough to flush dirty buffers. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c10 --- Comment #10 from Reinhard Max <max@suse.com> --- OK, but if the corruption was coming from the power outage, why wasn't it detected by fsck right after the unclean shutdown? Anyway, for now I assume we are looking at two entirely different things here: 1. Corrupted indexes due to the collation changes in glibc. This is a (now) known problem, but I haven't seen any other reports of this causing segfaults. 2. Segfaults due to database file corruptions that were caused by something outside of PostgreSQL. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 Christian Boltz <suse-beta@cboltz.de> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |suse-beta@cboltz.de -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c11 --- Comment #11 from Andrii Nikitin <andrii.nikitin@suse.com> --- Just some considerations - when I was trying to restore logical dump of database - only one table had missing rows (matrix.destinations if I remember properly). That table had varchar Primary Key , which was referenced as Foreign Key in another table. Since it was the only table with missing rows - a chance exists that corruption is related to varchar primary key. I will try to compile a test case, but it is tricky. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c12 Reinhard Max <max@suse.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Flags| |needinfo? --- Comment #12 from Reinhard Max <max@suse.com> --- How shall we proceed with this? Has it ever happened again? Is there any way to reproduce it? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c13 --- Comment #13 from Bernhard Wiedemann <bwiedemann@suse.com> --- It seems to run stable now with postgresql13 so maybe some of the DB files had unexpected contents. We probably do not have a copy of the old DB files, so reproducing will be hard if we don't accidentally encounter it again. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1187392 http://bugzilla.opensuse.org/show_bug.cgi?id=1187392#c14 Reinhard Max <max@suse.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |RESOLVED Resolution|--- |WORKSFORME Flags|needinfo? | --- Comment #14 from Reinhard Max <max@suse.com> --- I still think that the collation changes in glibc were the most likely reason for the data corruption. In that case it shouldn't happen again unless glibc changes collations again, which is something we will have to watch out for in the future. Given that it is not reproducible I'll close this as WORKSFORME for now, but feel free to reopen in case it happens again. -- You are receiving this mail because: You are on the CC list for the bug.
participants (1)
-
bugzilla_noreply@suse.com