BUG #16099: Segmentation fault with - triggers and procedures - Mailing list pgsql-bugs

From PG Bug reporting form
Subject BUG #16099: Segmentation fault with - triggers and procedures
Date
Msg-id 16099-8def99f9048582a4@postgresql.org
Whole thread Raw
Responses Re: BUG #16099: Segmentation fault with - triggers and procedures
Re: BUG #16099: Segmentation fault with - triggers and procedures
List pgsql-bugs
The following bug has been logged on the website:

Bug reference:      16099
Logged by:          Jerzy Dudzic
Email address:      jerzy@dudzic.pl
PostgreSQL version: 12.0
Operating system:   Ubuntu 19.04
Description:

Dear developers,

I recently upgraded PostgreSQL from 11(most likely 11.5) to 12 and I use it
as website database. It started crashing quite randomly, especially during
heavier website usage.

FYI, I think this might be heavily related or even the same as
https://www.postgresql.org/message-id/16095-c3ff2e5283b8dba5%40postgresql.org

Versions:
root@jerzy-home:/etc/postgresql/12/main# dpkg -l | grep postgres
postgresql-12             12.0-2.pgdg19.04+1  amd64
postgresql-12-dbgsym 12.0-2.pgdg19.04+1 amd64
postgresql-client-12      12.0-2.pgdg19.04+1  amd64
postgresql-client-common  208.pgdg19.04+2     all  
postgresql-common         208.pgdg19.04+2     all  
postgresql-contrib        12+208.pgdg19.04+2  all  
postgresql-server-dev-12  12.0-2.pgdg19.04+1  amd64

System: Linux jerzy-home 5.0.0-32-generic #34-Ubuntu SMP Wed Oct 2 02:06:48
UTC 2019 x86_64 x86_64 x86_64 GNU/Linux




Here's example log from postgres:
2019-11-07 16:29:57.436 CET [18927] LOG:  00000: server process (PID 19492)
was terminated by signal 11: Segmentation fault
2019-11-07 16:29:57.436 CET [18927] DETAIL:  Failed process was running:
select is_account_active(1)
2019-11-07 16:29:57.436 CET [18927] LOCATION:  LogChildExit,
postmaster.c:3680
2019-11-07 16:29:57.436 CET [18927] LOG:  00000: terminating any other
active server processes
2019-11-07 16:29:57.436 CET [18927] LOCATION:  HandleChildCrash,
postmaster.c:3400
2019-11-07 16:29:57.436 CET [18932] WARNING:  57P02: terminating connection
because of crash of another server process
2019-11-07 16:29:57.436 CET [18932] 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.                                                      
2019-11-07 16:29:57.436 CET [18932] HINT:  In a moment you should be able to
reconnect to the database and repeat your command.
2019-11-07 16:29:57.436 CET [18932] LOCATION:  quickdie, postgres.c:2717
2019-11-07 16:29:57.438 CET [18927] LOG:  00000: all server processes
terminated; reinitializing
2019-11-07 16:29:57.438 CET [18927] LOCATION:  PostmasterStateMachine,
postmaster.c:3912
2019-11-07 16:29:57.477 CET [19495] LOG:  00000: database system was
interrupted; last known up at 2019-11-07 16:29:32 CET
2019-11-07 16:29:57.477 CET [19495] LOCATION:  StartupXLOG, xlog.c:6277
2019-11-07 16:30:06.601 CET [19495] LOG:  00000: database system was not
properly shut down; automatic recovery in progress
2019-11-07 16:30:06.601 CET [19495] LOCATION:  StartupXLOG, xlog.c:6774
2019-11-07 16:30:06.613 CET [19495] LOG:  00000: redo starts at 3/5CB31F60
2019-11-07 16:30:06.613 CET [19495] LOCATION:  StartupXLOG, xlog.c:7045
2019-11-07 16:30:06.613 CET [19495] LOG:  00000: invalid record length at
3/5CB32300: wanted 24, got 0
2019-11-07 16:30:06.613 CET [19495] LOCATION:  ReadRecord, xlog.c:4284
2019-11-07 16:30:06.613 CET [19495] LOG:  00000: redo done at 3/5CB322D8
2019-11-07 16:30:06.613 CET [19495] LOCATION:  StartupXLOG, xlog.c:7307
2019-11-07 16:30:06.711 CET [18927] LOG:  00000: database system is ready to
accept connections
2019-11-07 16:30:06.711 CET [18927] LOCATION:  reaper, postmaster.c:2989

gdb:

NOTE: "Nie ma takiego pliku ani katalogu." is "No such file or directory" -
I don't know off-hand how to make gdb speak English

root@jerzy-home:/tmp/crashlog# sudo -u postgres gdb -q -c CoreDump
/usr/lib/postgresql/12/bin/postgres
Reading symbols from /usr/lib/postgresql/12/bin/postgres...
Reading symbols from
/usr/lib/debug/.build-id/7d/6b94ccd31a1f965e7dc510cd80b05e813c1555.debug...
[New LWP 27302]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `postgres: 12/main: jerzy segfault_test [local] SELECT
                        '.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x0000564f3537c013 in GetMemoryChunkContext (pointer=0x0) at
./build/../src/include/utils/memutils.h:127
127     ./build/../src/include/utils/memutils.h: Nie ma takiego pliku ani
katalogu.
(gdb) bt
#0  0x0000564f3537c013 in GetMemoryChunkContext (pointer=0x0) at
./build/../src/include/utils/memutils.h:127
#1  pfree (pointer=0x0) at ./build/../src/backend/utils/mmgr/mcxt.c:1033
#2  0x0000564f34f1da35 in heap_freetuple (htup=<optimized out>) at
./build/../src/backend/access/common/heaptuple.c:1340
#3  0x0000564f350cbe69 in tts_buffer_heap_clear (slot=0x564f36286778) at
./build/../src/backend/executor/execTuples.c:652
#4  0x0000564f350cc825 in ExecClearTuple (slot=0x564f36286778) at
./build/../src/include/executor/tuptable.h:428
#5  ExecForceStoreHeapTuple (tuple=0x564f3628c820, slot=0x564f36286778,
shouldFree=<optimized out>) at
./build/../src/backend/executor/execTuples.c:1446
#6  0x0000564f350a20f6 in ExecBRUpdateTriggers
(estate=estate@entry=0x564f36282700, epqstate=epqstate@entry=0x564f36282cf0,
relinfo=relinfo@entry=0x564f362829c0, tupleid=tupleid@entry=0x7ffd28e1e34a,
fdw_trigtuple=fdw_trigtuple@entry=0x0,
newslot=newslot@entry=0x564f36286778)
    at ./build/../src/backend/commands/trigger.c:3109
#7  0x0000564f350e657d in ExecUpdate (mtstate=mtstate@entry=0x564f36282bf8,
tupleid=0x7ffd28e1e34a, oldtuple=0x0, slot=0x564f36286778,
planSlot=0x564f36286648, epqstate=epqstate@entry=0x564f36282cf0,
estate=0x564f36282700, canSetTag=true)
    at ./build/../src/backend/executor/nodeModifyTable.c:1072
#8  0x0000564f350e7a52 in ExecModifyTable (pstate=0x564f36282bf8) at
./build/../src/backend/executor/nodeModifyTable.c:2223
#9  0x0000564f350c0983 in ExecProcNode (node=0x564f36282bf8) at
./build/../src/include/executor/executor.h:239
#10 ExecutePlan (execute_once=<optimized out>, dest=0x564f355d35c0
<spi_printtupDR>, direction=<optimized out>, numberTuples=0,
sendTuples=<optimized out>, operation=CMD_UPDATE,
use_parallel_mode=<optimized out>, planstate=0x564f36282bf8,
estate=0x564f36282700)
    at ./build/../src/backend/executor/execMain.c:1646
#11 standard_ExecutorRun (queryDesc=0x564f3626fa98, direction=<optimized
out>, count=0, execute_once=<optimized out>) at
./build/../src/backend/executor/execMain.c:364
#12 0x0000564f350f73a1 in _SPI_pquery (tcount=0, fire_triggers=true,
queryDesc=0x564f3626fa98) at ./build/../src/backend/executor/spi.c:2521
#13 _SPI_execute_plan (plan=plan@entry=0x564f36273ce0,
paramLI=paramLI@entry=0x564f3625b860, snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=false, fire_triggers=fire_triggers@entry=true,
tcount=<optimized out>)
    at ./build/../src/backend/executor/spi.c:2296
#14 0x0000564f350f7b14 in SPI_execute_plan_with_paramlist
(plan=0x564f36273ce0, params=0x564f3625b860, read_only=<optimized out>,
tcount=0) at ./build/../src/backend/executor/spi.c:577
#15 0x00007f04562830b4 in exec_stmt_execsql
(estate=estate@entry=0x7ffd28e1e9a0, stmt=stmt@entry=0x564f3625ffe8) at
./build/../src/pl/plpgsql/src/pl_exec.c:4162
#16 0x00007f0456283deb in exec_stmt (estate=estate@entry=0x7ffd28e1e9a0,
stmt=0x564f3625ffe8) at ./build/../src/pl/plpgsql/src/pl_exec.c:2033
#17 0x00007f0456286f94 in exec_stmts (estate=0x7ffd28e1e9a0,
stmts=<optimized out>) at ./build/../src/pl/plpgsql/src/pl_exec.c:1924
#18 0x00007f045628735a in exec_stmt_block
(estate=estate@entry=0x7ffd28e1e9a0, block=block@entry=0x564f36260188) at
./build/../src/pl/plpgsql/src/pl_exec.c:1865
#19 0x00007f0456284b8b in exec_stmt (estate=estate@entry=0x7ffd28e1e9a0,
stmt=0x564f36260188) at ./build/../src/pl/plpgsql/src/pl_exec.c:1957
#20 0x00007f0456286b1d in plpgsql_exec_function
(func=func@entry=0x564f361c22e0, fcinfo=fcinfo@entry=0x564f3624f2d0,
simple_eval_estate=simple_eval_estate@entry=0x0, atomic=<optimized out>) at
./build/../src/pl/plpgsql/src/pl_exec.c:589
#21 0x00007f04562797fd in plpgsql_call_handler (fcinfo=0x564f3624f2d0) at
./build/../src/pl/plpgsql/src/pl_handler.c:267
#22 0x0000564f350bd493 in ExecInterpExpr (state=0x564f3624f1f8,
econtext=0x564f3624ef20, isnull=<optimized out>) at
./build/../src/backend/executor/execExprInterp.c:1160
#23 0x0000564f350e9a36 in ExecEvalExprSwitchContext (isNull=0x7ffd28e1ec77,
econtext=0x564f3624ef20, state=0x564f3624f1f8) at
./build/../src/include/executor/executor.h:307
#24 ExecProject (projInfo=0x564f3624f1f0) at
./build/../src/include/executor/executor.h:341
#25 ExecResult (pstate=<optimized out>) at
./build/../src/backend/executor/nodeResult.c:136
#26 0x0000564f350c0983 in ExecProcNode (node=0x564f3624ee10) at
./build/../src/include/executor/executor.h:239
#27 ExecutePlan (execute_once=<optimized out>, dest=0x564f361bbb30,
direction=<optimized out>, numberTuples=0, sendTuples=<optimized out>,
operation=CMD_SELECT, use_parallel_mode=<optimized out>,
planstate=0x564f3624ee10, estate=0x564f3624ebd0)
    at ./build/../src/backend/executor/execMain.c:1646
#28 standard_ExecutorRun (queryDesc=0x564f361b8b00, direction=<optimized
out>, count=0, execute_once=<optimized out>) at
./build/../src/backend/executor/execMain.c:364
#29 0x0000564f35226e2c in PortalRunSelect
(portal=portal@entry=0x564f361fcbc0, forward=forward@entry=true, count=0,
count@entry=9223372036854775807, dest=dest@entry=0x564f361bbb30) at
./build/../src/backend/tcop/pquery.c:929
#30 0x0000564f352283c8 in PortalRun (portal=portal@entry=0x564f361fcbc0,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true,
run_once=run_once@entry=true, dest=dest@entry=0x564f361bbb30,
altdest=altdest@entry=0x564f361bbb30, completionTag=0x7ffd28e1ef20 "")
    at ./build/../src/backend/tcop/pquery.c:770
#31 0x0000564f3522418c in exec_simple_query (query_string=0x564f36170d20
"select is_account_active(1)") at
./build/../src/backend/tcop/postgres.c:1215
#32 0x0000564f352259ce in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x564f361c0c80, dbname=<optimized out>, username=<optimized
out>) at ./build/../src/backend/tcop/postgres.c:4236
#33 0x0000564f351ab579 in BackendRun (port=0x564f361ba0b0,
port=0x564f361ba0b0) at
./build/../src/backend/postmaster/postmaster.c:4431
#34 BackendStartup (port=0x564f361ba0b0) at
./build/../src/backend/postmaster/postmaster.c:4122
#35 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1704
#36 0x0000564f351ac49f in PostmasterMain (argc=5, argv=0x564f3616ac30) at
./build/../src/backend/postmaster/postmaster.c:1377
#37 0x0000564f34f13ebd in main (argc=5, argv=0x564f3616ac30) at
./build/../src/backend/main/main.c:228



Here is a small repository I created with a setup to reproduce:
https://github.com/jerzy-dudzic/pgtest_segfault


If I can do anything to help, please let me know!

Best regards,
Jerzy Dudzic


pgsql-bugs by date:

Previous
From: Jeff Janes
Date:
Subject: Re: BUG #16098: unexplained autovacuum to prevent wraparound
Next
From: Andres Freund
Date:
Subject: Re: BUG #16099: Segmentation fault with - triggers and procedures