Segmentation fault on postgresql 13.4, 12.8 with function call in a cursor

Started by Tomas Bartonover 4 years ago3 messagesbugs
Jump to latest
#1Tomas Barton
barton.tomas@gmail.com

Hi,

a recent change in postgresql is causing a segfault when a function is
called in filter section, e.g. with a plan like this:

Merge Left Join (cost=0.30..207.75 rows=400 width=7) (actual
time=0.006..0.009 rows=0 loops=1)
Merge Cond: (di.itemid = foo.itemid)
Filter: (COALESCE((min(foo.last_update)), '1970-01-01
00:00:00'::timestamp without time zone) < di.download_time)
-> Index Scan using downloaded_images_pkey on downloaded_images di
(cost=0.15..29.25 rows=500 width=15) (actual time=0.005..0.005 rows=0
loops=1)
-> Materialize (cost=0.15..135.25 rows=1200 width=40) (never executed)
-> GroupAggregate (cost=0.15..96.25 rows=1200 width=40) (never
executed)
Group Key: foo.itemid
-> Index Scan using foo_pkey on foo (cost=0.15..54.25
rows=1200 width=40) (never executed)

At least 13.4-1.pgdg100+1 and 12.8-1.pgdg100+1 are affected.
13.3-1.pgdg100+1 works fine. Here are steps to reproduce the issue.

cat <<EOF> postgresql-segfault.sql
CREATE SCHEMA debug;

CREATE TABLE debug.downloaded_images (
itemid text NOT NULL,
download_time timestamp,
PRIMARY KEY(itemId)
);

INSERT INTO debug.downloaded_images (itemid, download_time) VALUES
('1190300','2021-09-07 11:00:10.255831');

BEGIN;

CREATE TABLE IF NOT EXISTS "debug"."foo"
(itemId TEXT,
last_update TIMESTAMP,
PRIMARY KEY(itemId)
);

DECLARE "test-cursor-crash" CURSOR WITH HOLD FOR
SELECT di.itemId FROM "debug".downloaded_images di
LEFT JOIN (SELECT itemId, MIN(last_update) as last_update FROM
"debug"."foo" GROUP BY itemId) computed ON di.itemId=computed.itemId
WHERE COALESCE(last_update, '1970-01-01') < download_time;

FETCH 10000 IN "test-cursor-crash";

COMMIT;
EOF
createdb testdb
psql -d testdb -f postgresql-segfault.sql

here's output from server logs:

[3325]: LOG: all server processes terminated; reinitializing
x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
[3325]: LOG: all server processes terminated; reinitializing
[3325]: LOG: all server processes terminated; reinitializing
[3326]: LOG: database system was shut down at 2021-09-09 10:26:19 UTC
[3325]: LOG: all server processes terminated; reinitializing
[3325]: LOG: all server processes terminated; reinitializing
Segmentation fault
[3325]: LOG: all server processes terminated; reinitializing
[3325]: LOG: all server processes terminated; reinitializing
[3330]: HINT: In a moment you should be able to reconnect to the database and repeat your command.
process
[3330]: HINT: In a moment you should be able to reconnect to the database and repeat your command.
back the current transaction and exit, because another server process
exited abnormally and possibly corrupted shared memory.
[3330]: HINT: In a moment you should be able to reconnect to the database and repeat your command.
and repeat your command.
[3325]: LOG: all server processes terminated; reinitializing
[3411]: LOG: database system was not properly shut down; automatic recovery in progress
10:27:05 UTC
[3411]: LOG: database system was not properly shut down; automatic recovery in progress
in progress

I've already filled a debian bug:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=993848

Best Regards,
Tomas Barton

In reply to: Tomas Barton (#1)
Re: Segmentation fault on postgresql 13.4, 12.8 with function call in a cursor

Hello

I am able to reproduce on REL_13_STABLE. With assertions I got SIGABRT on COMMIT with following backtrace:

#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007fae23a82535 in __GI_abort () at abort.c:79
#2 0x00005598318b869a in ExceptionalCondition (conditionName=conditionName@entry=0x5598319d44ae "!TTS_EMPTY(slot)",
errorType=errorType@entry=0x55983190f028 "FailedAssertion", fileName=fileName@entry=0x5598319f2007 "execTuples.c", lineNumber=lineNumber@entry=693) at assert.c:67
#3 0x000055983160788e in tts_buffer_heap_getsomeattrs (slot=0x559832aeb638, natts=<optimized out>) at execTuples.c:693
#4 0x000055983160a104 in slot_getsomeattrs_int (slot=slot@entry=0x559832aeb638, attnum=2) at execTuples.c:1912
#5 0x00005598315f66e7 in slot_getsomeattrs (attnum=<optimized out>, slot=0x559832aeb638) at ../../../src/include/executor/tuptable.h:344
#6 ExecInterpExpr (state=0x559832aec0d8, econtext=0x559832abba98, isnull=0x7ffc0d62e67f) at execExprInterp.c:482
#7 0x0000559831628da7 in ExecEvalExprSwitchContext (isNull=0x7ffc0d62e67f, econtext=0x559832abba98, state=0x559832aec0d8) at ../../../src/include/executor/executor.h:322
#8 ExecQual (econtext=0x559832abba98, state=0x559832aec0d8) at ../../../src/include/executor/executor.h:391
#9 MJFillInner (node=node@entry=0x559832abb880) at nodeMergejoin.c:494
#10 0x000055983162980e in ExecMergeJoin (pstate=0x559832abb880) at nodeMergejoin.c:1353
#11 0x00005598315fb971 in ExecProcNode (node=0x559832abb880) at ../../../src/include/executor/executor.h:248
#12 ExecutePlan (estate=estate@entry=0x559832abb630, planstate=0x559832abb880, use_parallel_mode=<optimized out>, operation=operation@entry=CMD_SELECT,
sendTuples=sendTuples@entry=true, numberTuples=numberTuples@entry=0, direction=ForwardScanDirection, dest=0x559832ae29e0, execute_once=false) at execMain.c:1632
#13 0x00005598315fc653 in standard_ExecutorRun (queryDesc=0x559832ac50e8, direction=ForwardScanDirection, count=0, execute_once=execute_once@entry=false) at execMain.c:350
#14 0x00005598315fc71c in ExecutorRun (queryDesc=queryDesc@entry=0x559832ac50e8, direction=direction@entry=ForwardScanDirection, count=count@entry=0,
execute_once=execute_once@entry=false) at execMain.c:294
#15 0x00005598315a5f23 in PersistHoldablePortal (portal=portal@entry=0x559832a1f3c8) at portalcmds.c:407
#16 0x00005598318e66f4 in HoldPortal (portal=portal@entry=0x559832a1f3c8) at portalmem.c:642
#17 0x00005598318e6fd6 in PreCommit_Portals (isPrepare=isPrepare@entry=false) at portalmem.c:738
#18 0x00005598314c0a2a in CommitTransaction () at xact.c:2087
#19 0x00005598314c18b8 in CommitTransactionCommand () at xact.c:2974
#20 0x000055983179342f in finish_xact_command () at postgres.c:2662
#21 0x000055983179590e in exec_simple_query (query_string=query_string@entry=0x5598329bdae0 "COMMIT;") at postgres.c:1264
#22 0x0000559831797b01 in PostgresMain (argc=<optimized out>, argv=argv@entry=0x5598329e9380, dbname=<optimized out>, username=<optimized out>) at postgres.c:4339
#23 0x0000559831706ff8 in BackendRun (port=port@entry=0x5598329e02e0) at postmaster.c:4526
#24 0x000055983170a0cd in BackendStartup (port=port@entry=0x5598329e02e0) at postmaster.c:4210
#25 0x000055983170a2e8 in ServerLoop () at postmaster.c:1739
#26 0x000055983170b7cf in PostmasterMain (argc=<optimized out>, argv=<optimized out>) at postmaster.c:1412
#27 0x0000559831654b68 in main (argc=3, argv=0x5598329b8200) at main.c:210

Git bisect points me to a c1fd756fd23f60fcac120c9cd36de2921144e3bd commit ( https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=c1fd756fd23f60fcac120c9cd36de2921144e3bd )

regards, Sergei

#3Tom Lane
tgl@sss.pgh.pa.us
In reply to: Tomas Barton (#1)
Re: Segmentation fault on postgresql 13.4, 12.8 with function call in a cursor

Tomas Barton <barton.tomas@gmail.com> writes:

a recent change in postgresql is causing a segfault when a function is
called in filter section, e.g. with a plan like this:

Ugh, thanks. PersistHoldablePortal isn't being cautious about
re-executing a plan that already reached completion. Will fix.

regards, tom lane