Pg 15 devel crashes when fetching data from table using cursor - Mailing list pgsql-bugs
| From | hubert depesz lubaczewski |
|---|---|
| Subject | Pg 15 devel crashes when fetching data from table using cursor |
| Date | |
| Msg-id | 20220307094423.GA24798@depesz.com Whole thread Raw |
| Responses |
Re: Pg 15 devel crashes when fetching data from table using cursor
|
| List | pgsql-bugs |
Hi,
I ran 15devel, compiled today, on Ryzen processor (amd64), with data for
explain.depesz.com.
In psql I ran:
#v+
=$ psql -U depesz_explain
psql (15devel)
Type "help" for help.
(depesz_explain@[local]:5430) 09:46:37 [depesz_explain]
$ begin;
BEGIN
Time: 0.312 ms
(depesz_explain@[local]:5430) 09:46:40 [depesz_explain]
*$ DECLARE csr CURSOR FOR select id, plan FROM plans_part_25 WHERE is_public and NOT is_deleted and NOT is_anonymized;
DECLARE CURSOR
Time: 1.486 ms
(depesz_explain@[local]:5430) 09:46:53 [depesz_explain]
*$ fetch 100 from csr;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
Time: 92.067 ms
(@:) 09:47:03 []
?$
#v-
Pg logs show:
#v+
2022-03-07 09:46:37.179 CET depesz_explain@depesz_explain 526595 [local] LOG: connection authorized:
user=depesz_explaindatabase=depesz_explain application_name=psql
2022-03-07 09:46:40.082 CET depesz_explain@depesz_explain 526595 [local] LOG: duration: 0.235 ms statement: begin;
2022-03-07 09:46:53.933 CET depesz_explain@depesz_explain 526595 [local] LOG: duration: 1.348 ms statement: DECLARE
csrCURSOR FOR select id, plan FROM plans_part_25 WHERE is_public and NOT is_deleted and NOT is_anonymized;
TRAP: FailedAssertion("HaveRegisteredOrActiveSnapshot()", File: "toast_internals.c", Line: 670, PID: 526595)
postgres: depesz_explain depesz_explain [local] FETCH(ExceptionalCondition+0x99)[0x557da5491dc9]
postgres: depesz_explain depesz_explain [local] FETCH(+0x174f64)[0x557da5010f64]
postgres: depesz_explain depesz_explain [local] FETCH(heap_fetch_toast_slice+0x15f)[0x557da50606cf]
postgres: depesz_explain depesz_explain [local] FETCH(+0x16c374)[0x557da5008374]
postgres: depesz_explain depesz_explain [local] FETCH(detoast_attr+0x18d)[0x557da500884d]
postgres: depesz_explain depesz_explain [local] FETCH(text_to_cstring+0x16)[0x557da5467796]
postgres: depesz_explain depesz_explain [local] FETCH(OutputFunctionCall+0x58)[0x557da549c7c8]
postgres: depesz_explain depesz_explain [local] FETCH(+0x170fc5)[0x557da500cfc5]
postgres: depesz_explain depesz_explain [local] FETCH(+0x4cc4ee)[0x557da53684ee]
postgres: depesz_explain depesz_explain [local] FETCH(+0x4cc626)[0x557da5368626]
postgres: depesz_explain depesz_explain [local] FETCH(PortalRun+0x191)[0x557da5369e71]
postgres: depesz_explain depesz_explain [local] FETCH(+0x4c9ceb)[0x557da5365ceb]
postgres: depesz_explain depesz_explain [local] FETCH(PostgresMain+0x1708)[0x557da5367828]
postgres: depesz_explain depesz_explain [local] FETCH(+0x432073)[0x557da52ce073]
postgres: depesz_explain depesz_explain [local] FETCH(PostmasterMain+0xd5d)[0x557da52cf0ad]
postgres: depesz_explain depesz_explain [local] FETCH(main+0x20f)[0x557da4ff99bf]
/lib/x86_64-linux-gnu/libc.so.6(+0x29fd0)[0x7f7ba79dcfd0]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x7d)[0x7f7ba79dd07d]
postgres: depesz_explain depesz_explain [local] FETCH(_start+0x25)[0x557da4ff9d15]
2022-03-07 09:47:03.298 CET @ 508510 LOG: server process (PID 526595) was terminated by signal 6: Aborted
2022-03-07 09:47:03.298 CET @ 508510 DETAIL: Failed process was running: fetch 100 from csr;
2022-03-07 09:47:03.298 CET @ 508510 LOG: terminating any other active server processes
2022-03-07 09:47:03.299 CET [unknown]@[unknown] 527019 [local] LOG: connection received: host=[local]
2022-03-07 09:47:03.299 CET depesz_explain@depesz_explain 527019 [local] FATAL: the database system is in recovery
mode
2022-03-07 09:47:03.299 CET @ 508510 LOG: all server processes terminated; reinitializing
2022-03-07 09:47:03.316 CET @ 527022 LOG: database system was interrupted; last known up at 2022-03-07 09:45:57 CET
2022-03-07 09:47:03.558 CET @ 527022 LOG: database system was not properly shut down; automatic recovery in progress
2022-03-07 09:47:03.566 CET @ 527022 LOG: redo starts at 0/F61B64E0
2022-03-07 09:47:03.566 CET @ 527022 LOG: invalid record length at 0/F61B6518: wanted 24, got 0
2022-03-07 09:47:03.566 CET @ 527022 LOG: redo done at 0/F61B64E0 system usage: CPU: user: 0.00 s, system: 0.00 s,
elapsed:0.00 s
2022-03-07 09:47:03.578 CET @ 527023 LOG: checkpoint starting: end-of-recovery immediate wait
2022-03-07 09:47:03.585 CET @ 527023 LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0
removed,0 recycled; write=0.002 s, sync=0.001 s, total=0.008 s; sync files=2, longest=0.001 s, average=0.001 s;
distance=0kB, estimate=0 kB
2022-03-07 09:47:03.587 CET @ 508510 LOG: database system is ready to accept connections
#v-
Interestingly, I can select the data if I don't use cursor:
#v+
$ select id, plan FROM plans_part_25 WHERE is_public and NOT is_deleted and NOT is_anonymized \g | wc
1162074 11448274 1337357239722
Time: 213.767 ms
#v-
Details about the table:
#v+
$ \d+ plans_part_25
Table "public.plans_part_25"
Column │ Type │ Collation │ Nullable │ Default │ Storage │ Compression │ Stats target │
Description
──────────────────┼──────────────────────────┼───────────┼──────────┼─────────┼──────────┼─────────────┼──────────────┼─────────────
id │ text │ │ not null │ │ extended │ │ │
plan │ text │ │ not null │ │ extended │ │ │
entered_on │ timestamp with time zone │ │ not null │ now() │ plain │ │ │
is_public │ boolean │ │ not null │ true │ plain │ │ │
is_anonymized │ boolean │ │ not null │ false │ plain │ │ │
title │ text │ │ │ │ extended │ │ │
delete_key │ text │ │ │ │ extended │ │ │
is_deleted │ boolean │ │ not null │ false │ plain │ │ │
added_by │ text │ │ │ │ extended │ │ │
optimization_for │ text │ │ │ │ extended │ │ │
query │ text │ │ │ │ extended │ │ │
Partition of: plans FOR VALUES WITH (modulus 50, remainder 25)
Partition constraint: satisfies_hash_partition('16523'::oid, 50, 25, id)
Indexes:
"part_25_pkey" PRIMARY KEY, btree (id)
"part_25_added_by_entered_on_id_idx" UNIQUE, btree (added_by, entered_on, id) WHERE is_deleted = false
"part_25_added_by_idx" btree (added_by)
"part_25_entered_on_idx" btree (entered_on)
"part_25_entered_on_idx1" btree (entered_on) WHERE is_public AND NOT is_deleted
"part_25_length_idx" btree (length(plan)) WHERE NOT is_anonymized AND is_public
"part_25_optimization_for_idx" btree (optimization_for) WHERE NOT is_deleted
Access method: heap
$ select pg_column_compression(plan), count(*) FROM plans_part_25 WHERE is_public and NOT is_deleted and NOT
is_anonymizedgroup by 1;
pg_column_compression │ count
───────────────────────┼───────
[null] │ 3272
pglz │ 6556
(2 rows)
#v-
Information about compilation:
#v+
=$ pg_config --configure
'--prefix=/home/pgdba/work' '--with-pgport=5430' '--with-tcl' '--with-perl' '--with-python'
'--enable-integer-datetimes''--without-pam' '--without-bonjour' '--with-openssl' '--with-uuid=ossp' '--with-readline'
'--with-libxml''--with-systemd' '--with-zlib' '--with-lz4' '--with-llvm' '--with-gnu-ld' '--enable-debug'
'--enable-depend''--enable-cassert' 'PYTHON=/usr/bin/python3'
=$ dpkg -l | grep -iE '^ii[[:space:]]*(lib)?(gcc|clang|llvm|lz4|zlib)'
ii clang 1:13.0-53~exp1 amd64 C, C++ and
Objective-Ccompiler (LLVM based), clang binary
ii clang-13 1:13.0.0-2 amd64 C, C++ and
Objective-Ccompiler
ii gcc 4:11.2.0-1ubuntu1 amd64 GNU C
compiler
ii gcc-11 11.2.0-7ubuntu2 amd64 GNU C
compiler
ii gcc-11-aarch64-linux-gnu 11.2.0-5ubuntu1cross1 amd64 GNU C
compiler(cross compiler for arm64 architecture)
ii gcc-11-aarch64-linux-gnu-base:amd64 11.2.0-5ubuntu1cross1 amd64 GCC, the GNU
CompilerCollection (base package)
ii gcc-11-base:amd64 11.2.0-7ubuntu2 amd64 GCC, the GNU
CompilerCollection (base package)
ii gcc-11-cross-base 11.2.0-5ubuntu1cross1 all GCC, the GNU
CompilerCollection (library base package)
ii gcc-aarch64-linux-gnu 4:11.2.0-1ubuntu1 amd64 GNU C
compilerfor the arm64 architecture
ii libclang-common-13-dev 1:13.0.0-2 amd64 Clang
library- Common development package
ii libclang-cpp13 1:13.0.0-2 amd64 C++
interfaceto the Clang library
ii libclang1-13 1:13.0.0-2 amd64 C interface
tothe Clang library
ii libgcc-11-dev:amd64 11.2.0-7ubuntu2 amd64 GCC support
library(development files)
ii libgcc-11-dev-arm64-cross 11.2.0-5ubuntu1cross1 all GCC support
library(development files)
ii libgcc-s1:amd64 11.2.0-7ubuntu2 amd64 GCC support
library
ii libgcc-s1-arm64-cross 11.2.0-5ubuntu1cross1 all GCC support
library(arm64)
ii libllvm12:amd64 1:12.0.1-8build1 amd64 Modular
compilerand toolchain technologies, runtime library
ii libllvm13:amd64 1:13.0.0-2 amd64 Modular
compilerand toolchain technologies, runtime library
ii liblz4-1:amd64 1.9.3-2 amd64 Fast LZ
compressionalgorithm library - runtime
ii liblz4-dev:amd64 1.9.3-2 amd64 Fast LZ
compressionalgorithm library - development files
ii llvm 1:13.0-53~exp1 amd64 Low-Level
VirtualMachine (LLVM)
ii llvm-13 1:13.0.0-2 amd64 Modular
compilerand toolchain technologies
ii llvm-13-dev 1:13.0.0-2 amd64 Modular
compilerand toolchain technologies, libraries and headers
ii llvm-13-linker-tools 1:13.0.0-2 amd64 Modular
compilerand toolchain technologies - Plugins
ii llvm-13-runtime 1:13.0.0-2 amd64 Modular
compilerand toolchain technologies, IR interpreter
ii llvm-13-tools 1:13.0.0-2 amd64 Modular
compilerand toolchain technologies, tools
ii llvm-runtime 1:13.0-53~exp1 amd64 Low-Level
VirtualMachine (LLVM), bytecode interpreter
ii zlib1g:amd64 1:1.2.11.dfsg-2ubuntu7 amd64 compression
library- runtime
ii zlib1g-dev:amd64 1:1.2.11.dfsg-2ubuntu7 amd64 compression
library- development
#v-
depesz
pgsql-bugs by date: