Pg 15 devel crashes when fetching data from table using cursor

Поиск
Список
Период
Сортировка
Искать
От
hubert depesz lubaczewski
Тема
Pg 15 devel crashes when fetching data from table using cursor
Дата
Msg-id
20220307094423.GA24798@depesz.com
Список
Дерево обсуждения
Pg 15 devel crashes when fetching data from table using cursor hubert depesz lubaczewski <depesz@depesz.com>
Re: Pg 15 devel crashes when fetching data from table using cursor Andres Freund <andres@anarazel.de>
Re: Pg 15 devel crashes when fetching data from table using cursor Andres Freund <andres@anarazel.de>
Re: Pg 15 devel crashes when fetching data from table using cursor Tom Lane <tgl@sss.pgh.pa.us>
Re: Pg 15 devel crashes when fetching data from table using cursor Andres Freund <andres@anarazel.de>
Re: Pg 15 devel crashes when fetching data from table using cursor Andres Freund <andres@anarazel.de>
Re: Pg 15 devel crashes when fetching data from table using cursor Peter Geoghegan <pg@bowt.ie>
Re: Pg 15 devel crashes when fetching data from table using cursor Andres Freund <andres@anarazel.de>
Re: Pg 15 devel crashes when fetching data from table using cursor Tom Lane <tgl@sss.pgh.pa.us>
Re: Pg 15 devel crashes when fetching data from table using cursor Andres Freund <andres@anarazel.de>
Re: Pg 15 devel crashes when fetching data from table using cursor Tom Lane <tgl@sss.pgh.pa.us>
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_explain database=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 csr CURSOR 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=0 kB, 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_anonymized group 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-C compiler (LLVM based), clang binary
ii  clang-13                                      1:13.0.0-2                                  amd64        C, C++ and Objective-C compiler
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 Compiler Collection (base package)
ii  gcc-11-base:amd64                             11.2.0-7ubuntu2                             amd64        GCC, the GNU Compiler Collection (base package)
ii  gcc-11-cross-base                             11.2.0-5ubuntu1cross1                       all          GCC, the GNU Compiler Collection (library base package)
ii  gcc-aarch64-linux-gnu                         4:11.2.0-1ubuntu1                           amd64        GNU C compiler for 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++ interface to the Clang library
ii  libclang1-13                                  1:13.0.0-2                                  amd64        C interface to the 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 compiler and toolchain technologies, runtime library
ii  libllvm13:amd64                               1:13.0.0-2                                  amd64        Modular compiler and toolchain technologies, runtime library
ii  liblz4-1:amd64                                1.9.3-2                                     amd64        Fast LZ compression algorithm library - runtime
ii  liblz4-dev:amd64                              1.9.3-2                                     amd64        Fast LZ compression algorithm library - development files
ii  llvm                                          1:13.0-53~exp1                              amd64        Low-Level Virtual Machine (LLVM)
ii  llvm-13                                       1:13.0.0-2                                  amd64        Modular compiler and toolchain technologies
ii  llvm-13-dev                                   1:13.0.0-2                                  amd64        Modular compiler and toolchain technologies, libraries and headers
ii  llvm-13-linker-tools                          1:13.0.0-2                                  amd64        Modular compiler and toolchain technologies - Plugins
ii  llvm-13-runtime                               1:13.0.0-2                                  amd64        Modular compiler and toolchain technologies, IR interpreter
ii  llvm-13-tools                                 1:13.0.0-2                                  amd64        Modular compiler and toolchain technologies, tools
ii  llvm-runtime                                  1:13.0-53~exp1                              amd64        Low-Level Virtual Machine (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 по дате отправления
От: PG Bug reporting form
Дата:
От: David G. Johnston
Дата:
FAQ