Thread: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Eric Thinnes
Date:
Hello Postgres team, i get a segmentation fault when calling BlessTupleDesc in a C function in parallel. System Configuration --------------------- Architecture : Intel Pentium Operating System : Ubuntu versions: 16.04.7 LTS, 18.04.5 LTS, 20.04.2 LTS PostgreSQL version : PostgreSQL-(12.6, 12.7, 13.2, 13.3) Compiler used : gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0 Please enter a FULL description of your problem: ------------------------------------------------ In the version with the configure option --enable-cassert, the process is aborted before the segmentation fault occurs. It is possible that the error does not occur the first time and that the call has to be repeated several times. That probably indicates a timing problem with concurrency. postgres:5433:et@test=# SET max_parallel_workers_per_gather TO 4; SET Zeit: 0,558 ms postgres:5433:et@test=#* SELECT sum(sign*Betrag) FROM kpos_test, setof_kpos(kpos); INFO: pid: 9132, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 9131, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 9130, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 9134, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 9133, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d WARNING: terminating connection because of crash of another server process DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. TIP: In a moment you should be able to reconnect to the database and repeat your command. SSL-SYSCALL-Fehler: Dateiende entdeckt Die Verbindung zum Server wurde verloren. Versuche Reset: Fehlgeschlagen. Zeit: 421,098 ms ::@!>? \q If I call the c function once with an empty argument before the parallel scan, the error does not occur. SET max_parallel_workers_per_gather TO 4; SET Zeit: 0,390 ms postgres:5433:et@test=#* SELECT setof_kpos(''); INFO: pid: 12396, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d setof_kpos ------------ (0 Zeilen) Zeit: 1,253 ms postgres:5433:et@test=#* SELECT sum(sign*Betrag) FROM kpos_test, setof_kpos(kpos); INFO: pid: 12400, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 12398, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 12399, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d INFO: pid: 12397, outTypeId: 40962 INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d sum ----- 0 (1 Zeile) I don't know how to fix this. In the appendix I have added the complete sources for the test and a core dump including postgres logs and configs. The complete test SQL. DROP TYPE t_kpos CASCADE; CREATE TYPE t_kpos AS ( Pos smallint , Count smallint , Konto integer , Sign smallint , BTyp smallint , Betrag bigint ); DROP FUNCTION IF EXISTS setof_kpos; CREATE OR REPLACE FUNCTION setof_kpos(kontopositionen text) RETURNS SETOF t_kpos AS '/var/lib/postgresql/lib/13/test', 'set_of_kpos' LANGUAGE C IMMUTABLE STRICT PARALLEL SAFE ; COMMIT; SELECT * FROM setof_kpos('11.40,11052,-1,328;9.58,4736,1,226;1.82,3806,1,314'); DROP TABLE kpos_test; CREATE TABLE kpos_test (id int, kpos text); INSERT INTO kpos_test SELECT generate_series(1,10000000) AS id, '11.40,11052,-1,328;9.58,4736,1,226;1.82,3806,1,314' AS kpos; COMMIT; -- psql -h postgres.vmware -p 5433 test SET max_parallel_workers_per_gather TO 4; SELECT sum(sign*Betrag) FROM kpos_test, setof_kpos(kpos); Short Version of C-function (complete version in attechment) .... int create_result_from_kpos( Datum result[], const t_TypInfo &tinfo, const char txt[] ) { t_KPos kpos [MAX_KPOS]; short allBtyp[MAX_KPOS]; bool nulls [N_ATTS]; memcpy( nulls, tinfo.nulls, sizeof(nulls) ); Datum values [N_ATTS]; int count = split_kpos( kpos, allBtyp, MAX_KPOS, txt ); TupleDesc tupleDesc = CreateTemplateTupleDesc( N_ATTS ); for ( int n = 0; n < N_ATTS; n++ ) TupleDescInitEntry( tupleDesc, n+1, tinfo.attNames[n], tinfo.attOids[n], -1, 0 ); tupleDesc = BlessTupleDesc( tupleDesc ); for ( int i = 0; i < count; i++ ) { // elog(INFO, "%2i: %8i %5i %5i %10lli", i+1, kpos[i].Konto, kpos[i].Sign, kpos[i].BTyp, kpos[i].Betrag ); values[0] = Int16GetDatum( (short)i+1 ); values[1] = Int16GetDatum( (short)count ); values[2] = Int32GetDatum( kpos[i].Konto ); values[3] = Int16GetDatum( kpos[i].Sign ); values[4] = Int16GetDatum( kpos[i].BTyp ); values[5] = Int64GetDatum( kpos[i].Betrag ); result[i] = HeapTupleGetDatum( heap_form_tuple( tupleDesc, values, nulls ) ); } return count; } Datum set_of_kpos(PG_FUNCTION_ARGS) { typedef struct { int nextelem, numelems; Datum result[MAX_KPOS]; } t_user_ctx; FuncCallContext *funcctx; t_user_ctx *userctx; // stuff done only on the first call of the function if ( SRF_IS_FIRSTCALL() ) { // create a function context for cross-call persistence funcctx = SRF_FIRSTCALL_INIT(); // switch to memory context appropriate for multiple function calls MemoryContext oldcontext = MemoryContextSwitchTo( funcctx->multi_call_memory_ctx ); const t_TypInfo &tinfo = init_tinfo( fcinfo ); const char *txt = TextDatumGetCString( PG_GETARG_TEXT_PP( 0 ) ); // allocate memory for user context funcctx->user_fctx = userctx = (t_user_ctx*) palloc(sizeof(t_user_ctx)); userctx->nextelem = 0; userctx->numelems = create_result_from_kpos( userctx->result, tinfo, txt ); MemoryContextSwitchTo( oldcontext ); } // stuff done on every call of the function funcctx = SRF_PERCALL_SETUP(); userctx = (t_user_ctx*) funcctx->user_fctx; if ( userctx->nextelem < userctx->numelems ) { SRF_RETURN_NEXT( funcctx, userctx->result[ userctx->nextelem++ ] ); } else { SRF_RETURN_DONE( funcctx ); } } 2021-05-14 10:38:18.462 CEST 9014 00000 LOG: redo done at 0/D1F496C8 2021-05-14 10:38:18.473 CEST 2188 00000 LOG: database system is ready to accept connections TRAP: FailedAssertion("result->tdrefcount == -1", File: "typcache.c", Line: 2711) postgres: 13/main13: parallel worker for PID 9080 (ExceptionalCondition+0x7c)[0x5566dd7ef4ec] postgres: 13/main13: parallel worker for PID 9080 (+0x58d2b4)[0x5566dd7ed2b4] postgres: 13/main13: parallel worker for PID 9080 (assign_record_type_typmod+0xa7)[0x5566dd7eeb77] postgres: 13/main13: parallel worker for PID 9080 (BlessTupleDesc+0x2d)[0x5566dd52ca9d] /var/lib/postgresql/lib/13/test.so(_Z23create_result_from_kposPmRK9s_TypInfoPKc+0xa7)[0x7f034364e7d7] /var/lib/postgresql/lib/13/test.so(set_of_kpos+0x107)[0x7f034364e9a7] postgres: 13/main13: parallel worker for PID 9080 (ExecMakeTableFunctionResult+0x37f)[0x5566dd5281ef] postgres: 13/main13: parallel worker for PID 9080 (+0x2dbbec)[0x5566dd53bbec] postgres: 13/main13: parallel worker for PID 9080 (ExecScan+0x371)[0x5566dd528ea1] postgres: 13/main13: parallel worker for PID 9080 (+0x2f0cb0)[0x5566dd550cb0] postgres: 13/main13: parallel worker for PID 9080 (+0x2d18c1)[0x5566dd5318c1] postgres: 13/main13: parallel worker for PID 9080 (+0x2d4a88)[0x5566dd534a88] postgres: 13/main13: parallel worker for PID 9080 (standard_ExecutorRun+0x113)[0x5566dd51dbb3] /usr/local/pgsql/13/lib/pg_stat_statements.so(+0x4335)[0x7f035053c335] postgres: 13/main13: parallel worker for PID 9080 (ParallelQueryMain+0x214)[0x5566dd522d54] postgres: 13/main13: parallel worker for PID 9080 (ParallelWorkerMain+0x498)[0x5566dd3cfef8] postgres: 13/main13: parallel worker for PID 9080 (StartBackgroundWorker+0x2e5)[0x5566dd619265] postgres: 13/main13: parallel worker for PID 9080 (+0x3c7123)[0x5566dd627123] postgres: 13/main13: parallel worker for PID 9080 (+0x3c7b92)[0x5566dd627b92] /lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0)[0x7f03540733c0] /lib/x86_64-linux-gnu/libc.so.6(__select+0x1a)[0x7f03537e80da] postgres: 13/main13: parallel worker for PID 9080 (+0x3c83ce)[0x5566dd6283ce] postgres: 13/main13: parallel worker for PID 9080 (PostmasterMain+0xe54)[0x5566dd62a124] postgres: 13/main13: parallel worker for PID 9080 (main+0x793)[0x5566dd322b03] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7f03536f70b3] postgres: 13/main13: parallel worker for PID 9080 (_start+0x2e)[0x5566dd322bae] 2021-05-14 10:38:47.819 CEST 2188 00000 LOG: background worker "parallel worker" (PID 9082) was terminated by signal 6: Aborted 2021-05-14 10:38:47.819 CEST 2188 00000 DETAIL: Failed process was running: SELECT sum(sign*Betrag) FROM kpos_test, setof_kpos(kpos); 2021-05-14 10:38:47.819 CEST 2188 00000 LOG: terminating any other active server processes 2021-05-14 10:38:47.819 CEST et test 192.168.150.1(33280) SELECT 9080 57P02 WARNING: terminating connection because of crash of another server process 2021-05-14 10:38:47.819 CEST et test 192.168.150.1(33280) SELECT 9080 57P02 DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2021-05-14 10:38:47.819 CEST et test 192.168.150.1(33280) SELECT 9080 57P02 HINT: In a moment you should be able to reconnect to the database and repeat your command. 2021-05-14 10:38:47.819 CEST 9019 57P02 WARNING: terminating connection because of crash of another server process 2021-05-14 10:38:47.819 CEST 9019 57P02 DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2021-05-14 10:38:47.819 CEST 9019 57P02 HINT: In a moment you should be able to reconnect to the database and repeat your command. 2021-05-14 10:38:47.821 CEST 2188 00000 LOG: archiver process (PID 9020) exited with exit code 2 2021-05-14 10:38:47.828 CEST et test 192.168.150.1(33282) 9086 57P03 FATAL: the database system is in recovery mode 2021-05-14 10:38:47.830 CEST 2188 00000 LOG: all server processes terminated; reinitializing 2021-05-14 10:38:47.900 CEST 9088 00000 LOG: database system was interrupted; last known up at 2021-05-14 10:38:18 CEST 2021-05-14 10:38:47.900 CEST et test 192.168.150.1(33284) 9089 57P03 FATAL: the database system is in recovery mode 2021-05-14 10:38:47.933 CEST 9088 00000 LOG: database system was not properly shut down; automatic recovery in progress 2021-05-14 10:38:47.935 CEST 9088 00000 LOG: redo starts at 0/D1F49778 2021-05-14 10:38:47.935 CEST 9088 00000 LOG: invalid record length at 0/D1F497B0: wanted 24, got 0 2021-05-14 10:38:47.935 CEST 9088 00000 LOG: redo done at 0/D1F49778 2021-05-14 10:38:47.946 CEST 2188 00000 LOG: database system is ready to accept connections TRAP: FailedAssertion("result->tdrefcount == -1", File: "typcache.c", Line: 2711) postgres: 13/main13: parallel worker for PID 9130 (ExceptionalCondition+0x7c)[0x5566dd7ef4ec] postgres: 13/main13: parallel worker for PID 9130 (+0x58d2b4)[0x5566dd7ed2b4] postgres: 13/main13: parallel worker for PID 9130 (assign_record_type_typmod+0xa7)[0x5566dd7eeb77] postgres: 13/main13: parallel worker for PID 9130 (BlessTupleDesc+0x2d)[0x5566dd52ca9d] /var/lib/postgresql/lib/13/test.so(_Z23create_result_from_kposPmRK9s_TypInfoPKc+0xa7)[0x7f034364e7d7] /var/lib/postgresql/lib/13/test.so(set_of_kpos+0x107)[0x7f034364e9a7] postgres: 13/main13: parallel worker for PID 9130 (ExecMakeTableFunctionResult+0x37f)[0x5566dd5281ef] postgres: 13/main13: parallel worker for PID 9130 (+0x2dbbec)[0x5566dd53bbec] postgres: 13/main13: parallel worker for PID 9130 (ExecScan+0x371)[0x5566dd528ea1] postgres: 13/main13: parallel worker for PID 9130 (+0x2f0cb0)[0x5566dd550cb0] postgres: 13/main13: parallel worker for PID 9130 (+0x2d18c1)[0x5566dd5318c1] postgres: 13/main13: parallel worker for PID 9130 (+0x2d4a88)[0x5566dd534a88] postgres: 13/main13: parallel worker for PID 9130 (standard_ExecutorRun+0x113)[0x5566dd51dbb3] /usr/local/pgsql/13/lib/pg_stat_statements.so(+0x4335)[0x7f035053c335] postgres: 13/main13: parallel worker for PID 9130 (ParallelQueryMain+0x214)[0x5566dd522d54] postgres: 13/main13: parallel worker for PID 9130 (ParallelWorkerMain+0x498)[0x5566dd3cfef8] postgres: 13/main13: parallel worker for PID 9130 (StartBackgroundWorker+0x2e5)[0x5566dd619265] postgres: 13/main13: parallel worker for PID 9130 (+0x3c7123)[0x5566dd627123] postgres: 13/main13: parallel worker for PID 9130 (+0x3c7b92)[0x5566dd627b92] /lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0)[0x7f03540733c0] /lib/x86_64-linux-gnu/libc.so.6(__select+0x1a)[0x7f03537e80da] postgres: 13/main13: parallel worker for PID 9130 (+0x3c83ce)[0x5566dd6283ce] postgres: 13/main13: parallel worker for PID 9130 (PostmasterMain+0xe54)[0x5566dd62a124] postgres: 13/main13: parallel worker for PID 9130 (main+0x793)[0x5566dd322b03] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7f03536f70b3] postgres: 13/main13: parallel worker for PID 9130 (_start+0x2e)[0x5566dd322bae] 2021-05-14 10:39:04.103 CEST 2188 00000 LOG: background worker "parallel worker" (PID 9132) was terminated by signal 6: Aborted 2021-05-14 10:39:04.103 CEST 2188 00000 DETAIL: Failed process was running: SELECT sum(sign*Betrag) FROM kpos_test, setof_kpos(kpos); 2021-05-14 10:39:04.103 CEST 2188 00000 LOG: terminating any other active server processes (gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00007f03536f5859 in __GI_abort () at abort.c:79 #2 0x00005566dd7ef50b in ExceptionalCondition (conditionName=conditionName@entry=0x5566dd99826a "result->tdrefcount == -1", errorType=errorType@entry=0x5566dd84b01d "FailedAssertion", fileName=fileName@entry=0x5566dd998237 "typcache.c", lineNumber=lineNumber@entry=2711) at assert.c:67 #3 0x00005566dd7ed2b4 in find_or_make_matching_shared_tupledesc (tupdesc=<optimized out>) at typcache.c:2711 #4 0x00005566dd7eeb77 in assign_record_type_typmod (tupDesc=<optimized out>, tupDesc@entry=0x5566e02087b8) at typcache.c:1873 #5 0x00005566dd52ca9d in BlessTupleDesc (tupdesc=0x5566e02087b8) at execTuples.c:2086 #6 BlessTupleDesc (tupdesc=tupdesc@entry=0x5566e02087b8) at execTuples.c:2082 #7 0x00007f034364e7d7 in create_result_from_kpos (result=result@entry=0x5566e0208728, tinfo=..., txt=txt@entry=0x5566df3ee200 "11.40,11052,-1,328;9.58,4736,1,226;1.82,3806,1,314") at test.c:125 #8 0x00007f034364e9a7 in set_of_kpos (fcinfo=<optimized out>) at test.c:168 #9 0x00005566dd5281ef in ExecMakeTableFunctionResult (setexpr=0x5566df435368, econtext=0x5566df4346f0, argContext=<optimized out>, expectedDesc=0x5566df457600, randomAccess=false) at execSRF.c:234 #10 0x00005566dd53bbec in FunctionNext (node=node@entry=0x5566df4345d8) at nodeFunctionscan.c:94 #11 0x00005566dd528ea1 in ExecScanFetch (recheckMtd=0x5566dd53b8e0 <FunctionRecheck>, accessMtd=0x5566dd53b8f0 <FunctionNext>, node=0x5566df4345d8) at execScan.c:133 #12 ExecScan (node=0x5566df4345d8, accessMtd=0x5566dd53b8f0 <FunctionNext>, recheckMtd=0x5566dd53b8e0 <FunctionRecheck>) at execScan.c:182 #13 0x00005566dd550cb0 in ExecProcNode (node=0x5566df4345d8) at ../../../src/include/executor/executor.h:248 #14 ExecNestLoop (pstate=0x5566df434118) at nodeNestloop.c:160 #15 0x00005566dd5318c1 in ExecProcNode (node=0x5566df434118) at ../../../src/include/executor/executor.h:248 #16 fetch_input_tuple (aggstate=aggstate@entry=0x5566df433bd0) at nodeAgg.c:589 #17 0x00005566dd534a88 in agg_retrieve_direct (aggstate=<optimized out>) at nodeAgg.c:2368 #18 ExecAgg (pstate=<optimized out>) at nodeAgg.c:2183 #19 0x00005566dd51dbb3 in ExecProcNode (node=0x5566df433bd0) at ../../../src/include/executor/executor.h:248 #20 ExecutePlan (execute_once=<optimized out>, dest=0x5566df392598, direction=<optimized out>, numberTuples=0, sendTuples=<optimized out>, operation=CMD_SELECT, use_parallel_mode=<optimized out>, planstate=0x5566df433bd0, estate=0x5566df4336f0) at execMain.c:1632 #21 standard_ExecutorRun (queryDesc=0x5566df394230, direction=<optimized out>, count=0, execute_once=<optimized out>) at execMain.c:350 #22 0x00007f035053c335 in pgss_ExecutorRun (queryDesc=0x5566df394230, direction=ForwardScanDirection, count=0, execute_once=<optimized out>) at pg_stat_statements.c:1045 #23 0x00005566dd522d54 in ParallelQueryMain (seg=seg@entry=0x5566df305938, toc=toc@entry=0x7f03435ca000) at execParallel.c:1448 #24 0x00005566dd3cfef8 in ParallelWorkerMain (main_arg=<optimized out>) at parallel.c:1470 #25 0x00005566dd619265 in StartBackgroundWorker () at bgworker.c:879 #26 0x00005566dd627123 in do_start_bgworker (rw=<optimized out>) at postmaster.c:5870 #27 maybe_start_bgworkers () at postmaster.c:6095 #28 0x00005566dd627b92 in sigusr1_handler (postgres_signal_arg=<optimized out>) at postmaster.c:5255 #29 <signal handler called> #30 0x00007f03537e80da in __GI___select (nfds=nfds@entry=8, readfds=readfds@entry=0x7ffe861f5d30, writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0, timeout=timeout@entry=0x7ffe861f5c90) at ../sysdeps/unix/sysv/linux/select.c:41 #31 0x00005566dd6283ce in ServerLoop () at postmaster.c:1703 #32 0x00005566dd62a124 in PostmasterMain (argc=3, argv=<optimized out>) at postmaster.c:1412 #33 0x00005566dd322b03 in main (argc=3, argv=0x5566df303920) at main.c:210
Attachment
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Bharath Rupireddy
Date:
On Fri, May 14, 2021 at 4:49 PM Eric Thinnes <e.thinnes@gmx.de> wrote: > > > Hello Postgres team, > > i get a segmentation fault when calling BlessTupleDesc in a C function > in parallel. > > System Configuration > --------------------- > Architecture : Intel Pentium > Operating System : Ubuntu versions: 16.04.7 LTS, 18.04.5 LTS, > 20.04.2 LTS > PostgreSQL version : PostgreSQL-(12.6, 12.7, 13.2, 13.3) > Compiler used : gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0 > > Please enter a FULL description of your problem: > ------------------------------------------------ > > In the version with the configure option --enable-cassert, the process > is aborted > before the segmentation fault occurs. > > It is possible that the error does not occur the first time and that > the call has to be repeated several times. > That probably indicates a timing problem with concurrency. > > > postgres:5433:et@test=# SET max_parallel_workers_per_gather TO 4; > SET > Zeit: 0,558 ms > postgres:5433:et@test=#* SELECT sum(sign*Betrag) FROM kpos_test, > setof_kpos(kpos); > INFO: pid: 9132, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 9131, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 9130, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 9134, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 9133, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > WARNING: terminating connection because of crash of another server process > DETAIL: The postmaster has commanded this server process to roll back > the current transaction and exit, because another server process exited > abnormally and possibly corrupted shared memory. > TIP: In a moment you should be able to reconnect to the database and > repeat your command. > SSL-SYSCALL-Fehler: Dateiende entdeckt > Die Verbindung zum Server wurde verloren. Versuche Reset: Fehlgeschlagen. > Zeit: 421,098 ms > ::@!>? \q > > If I call the c function once with an empty argument before the > parallel scan, the error does not occur. > > > SET max_parallel_workers_per_gather TO 4; > SET > Zeit: 0,390 ms > postgres:5433:et@test=#* SELECT setof_kpos(''); > INFO: pid: 12396, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > setof_kpos > ------------ > (0 Zeilen) > > Zeit: 1,253 ms > postgres:5433:et@test=#* SELECT sum(sign*Betrag) FROM kpos_test, > setof_kpos(kpos); > INFO: pid: 12400, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 12398, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 12399, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > INFO: pid: 12397, outTypeId: 40962 > INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d > sum > ----- > 0 > (1 Zeile) > > I don't know how to fix this. I'm not sure if this makes sense - do you want to set the set_of_kpos function's parallel safety to 'unsafe' or 'restricted'? With Regards, Bharath Rupireddy. EnterpriseDB: http://www.enterprisedb.com
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Eric Thinnes
Date:
I do think it should be possible. The function always delivers the same result with the same call parameters except for the determination of the result types and the generation of the TupleDesc, the function has no side effects. If BlessTupleDesc inevitably leads to side effects, I am happy to be instructed to improve something. So far I haven't found any information on this. Am 14.05.21 um 13:45 schrieb Bharath Rupireddy: > On Fri, May 14, 2021 at 4:49 PM Eric Thinnes <e.thinnes@gmx.de> wrote: >> >> >> Hello Postgres team, >> >> i get a segmentation fault when calling BlessTupleDesc in a C function >> in parallel. >> >> System Configuration >> --------------------- >> Architecture : Intel Pentium >> Operating System : Ubuntu versions: 16.04.7 LTS, 18.04.5 LTS, >> 20.04.2 LTS >> PostgreSQL version : PostgreSQL-(12.6, 12.7, 13.2, 13.3) >> Compiler used : gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0 >> >> Please enter a FULL description of your problem: >> ------------------------------------------------ >> >> In the version with the configure option --enable-cassert, the process >> is aborted >> before the segmentation fault occurs. >> >> It is possible that the error does not occur the first time and that >> the call has to be repeated several times. >> That probably indicates a timing problem with concurrency. >> >> >> postgres:5433:et@test=# SET max_parallel_workers_per_gather TO 4; >> SET >> Zeit: 0,558 ms >> postgres:5433:et@test=#* SELECT sum(sign*Betrag) FROM kpos_test, >> setof_kpos(kpos); >> INFO: pid: 9132, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 9131, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 9130, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 9134, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 9133, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> WARNING: terminating connection because of crash of another server process >> DETAIL: The postmaster has commanded this server process to roll back >> the current transaction and exit, because another server process exited >> abnormally and possibly corrupted shared memory. >> TIP: In a moment you should be able to reconnect to the database and >> repeat your command. >> SSL-SYSCALL-Fehler: Dateiende entdeckt >> Die Verbindung zum Server wurde verloren. Versuche Reset: Fehlgeschlagen. >> Zeit: 421,098 ms >> ::@!>? \q >> >> If I call the c function once with an empty argument before the >> parallel scan, the error does not occur. >> >> >> SET max_parallel_workers_per_gather TO 4; >> SET >> Zeit: 0,390 ms >> postgres:5433:et@test=#* SELECT setof_kpos(''); >> INFO: pid: 12396, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> setof_kpos >> ------------ >> (0 Zeilen) >> >> Zeit: 1,253 ms >> postgres:5433:et@test=#* SELECT sum(sign*Betrag) FROM kpos_test, >> setof_kpos(kpos); >> INFO: pid: 12400, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 12398, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 12399, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> INFO: pid: 12397, outTypeId: 40962 >> INFO: outTypRelId: 40960, typlen: -1, typbyval: 0, typalign: d >> sum >> ----- >> 0 >> (1 Zeile) >> >> I don't know how to fix this. > > I'm not sure if this makes sense - do you want to set the set_of_kpos > function's parallel safety to 'unsafe' or 'restricted'? > > With Regards, > Bharath Rupireddy. > EnterpriseDB: http://www.enterprisedb.com >
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Bharath Rupireddy
Date:
On Fri, May 14, 2021 at 5:56 PM Eric Thinnes <e.thinnes@gmx.de> wrote: > > > I do think it should be possible. > > The function always delivers the same result with the same call > parameters except for the determination of the result types and the > generation of the TupleDesc, the function has no side effects. > > If BlessTupleDesc inevitably leads to side effects, I am happy to be > instructed to improve something. > So far I haven't found any information on this. I can't say exactly that the BlessTupleDesc is actually causing the problem, because there are a good number of parallel safe functions (see [1]) in the core which didn't cause any problem. Since setof_kpos is a custom function, maybe it's a good idea to debug your function: with 1 or 2 workers, with parallel_leader_participation off, with force_parallel_mode on, putting some sleep code in that function, with some lesser data and encouraging parallel plans (see [2]). [1] hash_page_items pg_buffercache_pages pg_prepared_xact pg_lock_status pg_get_catalog_foreign_keys pg_partition_tree [2] -- encourage use of parallel plans set parallel_setup_cost=0; set parallel_tuple_cost=0; set min_parallel_table_scan_size=0; set max_parallel_workers_per_gather=2; With Regards, Bharath Rupireddy. EnterpriseDB: http://www.enterprisedb.com
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Tom Lane
Date:
Eric Thinnes <e.thinnes@gmx.de> writes: > The function always delivers the same result with the same call > parameters except for the determination of the result types and the > generation of the TupleDesc, the function has no side effects. BlessTupleDesc certainly has side effects; that's pretty much the whole point of it. If you're marking this thing as parallel safe, I imagine that the problem boils down to "parallel worker locally registers a blessed tupdesc, but the leader has never heard of it, so fails to interpret the returned tuple". Perhaps a workaround is possible by using a named composite type instead of generating a rowtype on the fly? But that won't work if you want this to be polymorphic. Also, I recall that there are provisions in typcache.c in recent versions to support a shared pool of registered (i.e. blessed) tuple descriptors. That would likely solve your problem, but I've never looked into how to use that code. I doubt just calling BlessTupleDesc is enough. In particular, I imagine you need to make sure the leader process creates the tupdesc first, so it's available to all workers. regards, tom lane
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Eric Thinnes
Date:
Because of the parallelism it is difficult to debug the error. I have less experience with that. But I have now rewritten the function setof_kpos a little and no longer use the user-specific result type. The c-function was of course adjusted accordingly and the result type was not more dynamically determined via the corresponding functions. CREATE OR REPLACE FUNCTION setof_kpos( kontopositionen text , OUT Pos smallint , OUT Count smallint , OUT Konto integer , OUT Sign smallint , OUT BTyp smallint , OUT Betrag bigint ) RETURNS SETOF RECORD AS '/var/lib/postgresql/lib/13/test', 'set_of_kpos' LANGUAGE C IMMUTABLE STRICT PARALLEL SAFE ; That seems to solve the problem. > BlessTupleDesc certainly has side effects; that's pretty much the > whole point of it. If you're marking this thing as parallel safe, > I imagine that the problem boils down to "parallel worker locally > registers a blessed tupdesc, but the leader has never heard of it, > so fails to interpret the returned tuple". I noticed that as well. Whenever it was the leader's turn the crash came. That explains a lot and I now understand why the changes brought success. But it doesn't matter, it does and I am richer by one experience. Thank you very much for the good and quick help. Eric Thinnes Am 14.05.21 um 17:20 schrieb Tom Lane: > Eric Thinnes <e.thinnes@gmx.de> writes: >> The function always delivers the same result with the same call >> parameters except for the determination of the result types and the >> generation of the TupleDesc, the function has no side effects. > > BlessTupleDesc certainly has side effects; that's pretty much the > whole point of it. If you're marking this thing as parallel safe, > I imagine that the problem boils down to "parallel worker locally > registers a blessed tupdesc, but the leader has never heard of it, > so fails to interpret the returned tuple". > > Perhaps a workaround is possible by using a named composite type > instead of generating a rowtype on the fly? But that won't work > if you want this to be polymorphic. > > Also, I recall that there are provisions in typcache.c in recent > versions to support a shared pool of registered (i.e. blessed) > tuple descriptors. That would likely solve your problem, but > I've never looked into how to use that code. I doubt just > calling BlessTupleDesc is enough. In particular, I imagine > you need to make sure the leader process creates the tupdesc > first, so it's available to all workers. > > regards, tom lane >
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Thomas Munro
Date:
On Sat, May 15, 2021 at 5:42 AM Eric Thinnes <e.thinnes@gmx.de> wrote: > Because of the parallelism it is difficult to debug the error. > I have less experience with that. I was able to reproduce the problem using your test.c/test.sql. It's a bug in PostgreSQL. BlessTupleDesc() is supposed to work correctly in any process in a parallel query since the typmods are shared (since PG 11, before that there was a different arrangement involving translation), but there is a low probability edge case that your test manages to hit fairly reliably, where two backends try to bless a tuple with matching attributes at exactly the same time, and then the one that loses the race switches to using the TupleDesc blessed by the other, but it dereferences the wrong pointer (or rather, a non-pointer with a similar name...) here: /* Return the one we found. */ Assert(record_table_entry->key.shared); result = (TupleDesc) dsa_get_address(CurrentSession->area, - record_table_entry->key.shared); + record_table_entry->key.u.shared_tupdesc); Assert(result->tdrefcount == -1); With that change I can see it still hits this path often but works correctly. Will fix next week.
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Eric Thinnes
Date:
> PG 11, before that there was a different arrangement involving > translation), but there is a low probability edge case that your test > manages to hit fairly reliably, where two backends try to bless a I see that I have a talent for stepping into the trap. > record_table_entry->key.u.shared_tupdesc); > Assert(result->tdrefcount == -1); > > With that change I can see it still hits this path often but works > correctly. Will fix next week. That is good news. This means that all users can benefit from it.
Re: Segmentation fault when calling BlessTupleDesc in a C function in parallel on PostgreSQL-(12.6, 12.7, 13.2, 13.3)
From
Thomas Munro
Date:
On Mon, May 17, 2021 at 7:01 PM Eric Thinnes <e.thinnes@gmx.de> wrote: > > PG 11, before that there was a different arrangement involving > > translation), but there is a low probability edge case that your test > > manages to hit fairly reliably, where two backends try to bless a > > I see that I have a talent for stepping into the trap. > > > record_table_entry->key.u.shared_tupdesc); > > Assert(result->tdrefcount == -1); > > > > With that change I can see it still hits this path often but works > > correctly. Will fix next week. > > That is good news. > > This means that all users can benefit from it. Pushed. Thanks for the report and the reproducer!