MIME-Version: 1.0
References: <19520-73873648d44793cf@postgresql.org>
In-Reply-To: <19520-73873648d44793cf@postgresql.org>
From: Ayush Tiwari <ayushtiwari.slg01@gmail.com>
Date: Mon, 15 Jun 2026 14:44:06 +0530
Message-ID: 
 <CAJTYsWVqtWF+KJUdoKrzUM9QPQA5qD225AoeBeN7cwT4V1qd6A@mail.gmail.com>
Subject: Re: BUG #19520: PANIC when concurrently manipulating stored
 procedures with pg_stat_statements and track_functions =
To: zlh21343@163.com, pgsql-bugs@lists.postgresql.org,
	Andres Freund <andres@anarazel.de>, Michael Paquier <michael@paquier.xyz>
Content-Type: multipart/alternative; boundary="000000000000474998065447409b"
Archived-At: 
 <https://www.postgresql.org/message-id/CAJTYsWVqtWF%2BKJUdoKrzUM9QPQA5qD225AoeBeN7cwT4V1qd6A%40mail.gmail.com>
Precedence: bulk

--000000000000474998065447409b
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

Hi,

On Sun, 14 Jun 2026 at 22:37, PG Bug reporting form <noreply@postgresql.org=
>
wrote:

> The following bug has been logged on the website:
>
> Bug reference:      19520
> Logged by:          zhanglihui
> Email address:      zlh21343@163.com
> PostgreSQL version: 19beta1
> Operating system:   Ubuntu 25.04
> Description:
>
> =3D=3D=3D Configuration =3D=3D=3D
> Enabled extensions: pg_stat_statements
> postgresql.conf:
> shared_preload_libraries =3D 'pg_stat_statements'
> track_functions =3D 'all'
>
> =3D=3D=3D Problem Description =3D=3D=3D
> PostgreSQL server throws PANIC under high concurrent create, CALL and DRO=
P
> of stored procedures.
> This issue **only reproduces when pg_stat_statements is enabled and
> track_functions =3D all**.
> It cannot be triggered if pg_stat_statements is disabled or track_functio=
ns
> is set to none/pl.
>
> =3D=3D=3D Run Steps =3D=3D=3D
> javac -cp postgresql-42.7.5.jar -d out     src/ConcurrentSqlTest.java
> src/ProcCrashReprodure.java
> # Terminal 1 =E2=80=94 Mixed DDL/DML load test (40 threads, 10000 iterati=
ons each)
> java -cp out:postgresql-42.7.5.jar ConcurrentSqlTest
>
> # Terminal 2 =E2=80=94 Pure CALL load test (20 threads, infinite loop)
> java -cp out:postgresql-42.7.5.jar ProcCrashReprodure
> # Note: If no PANIC log or core dump is generated after the execution of
> Terminal 1, please re-run the command repeatedly until the issue occurs.
>
> PANIC log=EF=BC=9A
> postgresql-2026-06-14_235441.log:2026-06-14 23:54:41.949 CST [691761]
> PANIC:
> XX000: cannot abort transaction 4166281, it was already committed
> postgresql-2026-06-14_235931.log:2026-06-14 23:59:31.556 CST [696980]
> PANIC:
> XX000: cannot abort transaction 4641943, it was already committed
>
> (gdb) bt
> #0  __pthread_kill_implementation (threadid=3D<optimized out>, signo=3D6,
> no_tid=3D0) at ./nptl/pthread_kill.c:44
> #1  __pthread_kill_internal (threadid=3D<optimized out>, signo=3D6) at
> ./nptl/pthread_kill.c:89
> #2  __GI___pthread_kill (threadid=3D<optimized out>, signo=3Dsigno@entry=
=3D6) at
> ./nptl/pthread_kill.c:100
> #3  0x000073e62ec4579e in __GI_raise (sig=3Dsig@entry=3D6) at
> ../sysdeps/posix/raise.c:26
> #4  0x000073e62ec288cd in __GI_abort () at ./stdlib/abort.c:73
> #5  0x000056aeb574138c in errfinish (filename=3D0x56aeb57ff545 "xact.c",
> lineno=3D1835, funcname=3D0x56aeb5800d00 <__func__.26>
> "RecordTransactionAbort")
> at elog.c:621
> #6  0x000056aeb4faae67 in RecordTransactionAbort (isSubXact=3Dfalse) at
> xact.c:1835
> #7  0x000056aeb4fac19f in AbortTransaction () at xact.c:2982
> #8  0x000056aeb4facc22 in AbortCurrentTransactionInternal () at xact.c:35=
53
> #9  0x000056aeb4facb93 in AbortCurrentTransaction () at xact.c:3507
> #10 0x000056aeb5525552 in PostgresMain (dbname=3D0x56aedecf30d0 "postgres=
",
> username=3D0x56aedecf30b0 "zlh_user") at postgres.c:4539
> #11 0x000056aeb551b59c in BackendMain (startup_data=3D0x7fffb9501000,
> startup_data_len=3D24) at backend_startup.c:124
> #12 0x000056aeb5405686 in postmaster_child_launch (child_type=3DB_BACKEND=
,
> child_slot=3D24, startup_data=3D0x7fffb9501000, startup_data_len=3D24,
> client_sock=3D0x7fffb9501060) at launch_backend.c:268
> #13 0x000056aeb540c11b in BackendStartup (client_sock=3D0x7fffb9501060) a=
t
> postmaster.c:3627
> #14 0x000056aeb540969f in ServerLoop () at postmaster.c:1728
> #15 0x000056aeb5408f7c in PostmasterMain (argc=3D1, argv=3D0x56aedeca1430=
) at
> postmaster.c:1415
> #16 0x000056aeb528ce51 in main (argc=3D1, argv=3D0x56aedeca1430) at main.=
c:231
>

Thanks for the report!  I'm unsure if this has already been reported or
not.

I looked into this the last day, I could reproduce it locally.  Rather
than the Java harness I used ~60 concurrent psql clients looping DROP /
CREATE OR REPLACE / CALL of the same empty plpgsql procedure
(track_functions=3Dall, pg_stat_statements loaded); here it PANICs within
a few seconds.

Just before the PANIC the failing backend logs:

  ERROR:  trying to drop stats entry already dropped: kind=3Dfunction ...
  WARNING:  AbortTransaction while in COMMIT state
  PANIC:  cannot abort transaction xxx, it was already committed

So it looks like a function's shared stats entry gets dropped twice:
once out-of-band from pgstat_init_function_usage() when a concurrent
CALL notices the function is gone, and once from the transactional drop
at DROP time.  When the latter loses the race it runs from
AtEOXact_PgStat(), past the commit record, so the "already dropped"
elog() in pgstat_drop_entry_internal() becomes the PANIC.

The two droppers and the guard all seem to date back to PG 15
(5891c7a8ed8f).  I guess the "drop exactly once" assumption behind that
guard doesn't really hold for function stats, where two independent
droppers are legitimate.

I've added Andres and Michael on the thread, since they have worked on
this in the past, for their input.

Regards,
Ayush

--000000000000474998065447409b
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div dir=3D"ltr">Hi,</div><br><div class=3D"gmail_quote gm=
ail_quote_container"><div dir=3D"ltr" class=3D"gmail_attr">On Sun, 14 Jun 2=
026 at 22:37, PG Bug reporting form &lt;<a href=3D"mailto:noreply@postgresq=
l.org">noreply@postgresql.org</a>&gt; wrote:<br></div><blockquote class=3D"=
gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(20=
4,204,204);padding-left:1ex">The following bug has been logged on the websi=
te:<br>
<br>
Bug reference:=C2=A0 =C2=A0 =C2=A0 19520<br>
Logged by:=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 zhanglihui<br>
Email address:=C2=A0 =C2=A0 =C2=A0 <a href=3D"mailto:zlh21343@163.com" targ=
et=3D"_blank">zlh21343@163.com</a><br>
PostgreSQL version: 19beta1<br>
Operating system:=C2=A0 =C2=A0Ubuntu 25.04<br>
Description:=C2=A0 =C2=A0 =C2=A0 =C2=A0 <br>
<br>
=3D=3D=3D Configuration =3D=3D=3D<br>
Enabled extensions: pg_stat_statements<br>
postgresql.conf:<br>
shared_preload_libraries =3D &#39;pg_stat_statements&#39;<br>
track_functions =3D &#39;all&#39;<br>
<br>
=3D=3D=3D Problem Description =3D=3D=3D<br>
PostgreSQL server throws PANIC under high concurrent create, CALL and DROP<=
br>
of stored procedures.<br>
This issue **only reproduces when pg_stat_statements is enabled and<br>
track_functions =3D all**.<br>
It cannot be triggered if pg_stat_statements is disabled or track_functions=
<br>
is set to none/pl.<br>
<br>
=3D=3D=3D Run Steps =3D=3D=3D<br>
javac -cp postgresql-42.7.5.jar -d out=C2=A0 =C2=A0 =C2=A0src/ConcurrentSql=
Test.java<br>
src/ProcCrashReprodure.java<br>
# Terminal 1 =E2=80=94 Mixed DDL/DML load test (40 threads, 10000 iteration=
s each)<br>
java -cp out:postgresql-42.7.5.jar ConcurrentSqlTest<br>
<br>
# Terminal 2 =E2=80=94 Pure CALL load test (20 threads, infinite loop)<br>
java -cp out:postgresql-42.7.5.jar ProcCrashReprodure<br>
# Note: If no PANIC log or core dump is generated after the execution of<br=
>
Terminal 1, please re-run the command repeatedly until the issue occurs.<br=
>
<br>
PANIC log=EF=BC=9A<br>
postgresql-2026-06-14_235441.log:2026-06-14 23:54:41.949 CST [691761] PANIC=
:<br>
XX000: cannot abort transaction 4166281, it was already committed<br>
postgresql-2026-06-14_235931.log:2026-06-14 23:59:31.556 CST [696980] PANIC=
:<br>
XX000: cannot abort transaction 4641943, it was already committed<br>
<br>
(gdb) bt<br>
#0=C2=A0 __pthread_kill_implementation (threadid=3D&lt;optimized out&gt;, s=
igno=3D6,<br>
no_tid=3D0) at ./nptl/pthread_kill.c:44<br>
#1=C2=A0 __pthread_kill_internal (threadid=3D&lt;optimized out&gt;, signo=
=3D6) at<br>
./nptl/pthread_kill.c:89<br>
#2=C2=A0 __GI___pthread_kill (threadid=3D&lt;optimized out&gt;, signo=3Dsig=
no@entry=3D6) at<br>
./nptl/pthread_kill.c:100<br>
#3=C2=A0 0x000073e62ec4579e in __GI_raise (sig=3Dsig@entry=3D6) at<br>
../sysdeps/posix/raise.c:26<br>
#4=C2=A0 0x000073e62ec288cd in __GI_abort () at ./stdlib/abort.c:73<br>
#5=C2=A0 0x000056aeb574138c in errfinish (filename=3D0x56aeb57ff545 &quot;x=
act.c&quot;,<br>
lineno=3D1835, funcname=3D0x56aeb5800d00 &lt;__func__.26&gt; &quot;RecordTr=
ansactionAbort&quot;)<br>
at elog.c:621<br>
#6=C2=A0 0x000056aeb4faae67 in RecordTransactionAbort (isSubXact=3Dfalse) a=
t<br>
xact.c:1835<br>
#7=C2=A0 0x000056aeb4fac19f in AbortTransaction () at xact.c:2982<br>
#8=C2=A0 0x000056aeb4facc22 in AbortCurrentTransactionInternal () at xact.c=
:3553<br>
#9=C2=A0 0x000056aeb4facb93 in AbortCurrentTransaction () at xact.c:3507<br=
>
#10 0x000056aeb5525552 in PostgresMain (dbname=3D0x56aedecf30d0 &quot;postg=
res&quot;,<br>
username=3D0x56aedecf30b0 &quot;zlh_user&quot;) at postgres.c:4539<br>
#11 0x000056aeb551b59c in BackendMain (startup_data=3D0x7fffb9501000,<br>
startup_data_len=3D24) at backend_startup.c:124<br>
#12 0x000056aeb5405686 in postmaster_child_launch (child_type=3DB_BACKEND,<=
br>
child_slot=3D24, startup_data=3D0x7fffb9501000, startup_data_len=3D24,<br>
client_sock=3D0x7fffb9501060) at launch_backend.c:268<br>
#13 0x000056aeb540c11b in BackendStartup (client_sock=3D0x7fffb9501060) at<=
br>
postmaster.c:3627<br>
#14 0x000056aeb540969f in ServerLoop () at postmaster.c:1728<br>
#15 0x000056aeb5408f7c in PostmasterMain (argc=3D1, argv=3D0x56aedeca1430) =
at<br>
postmaster.c:1415<br>
#16 0x000056aeb528ce51 in main (argc=3D1, argv=3D0x56aedeca1430) at main.c:=
231<br></blockquote><div><br>Thanks for the report!=C2=A0 I&#39;m unsure if=
 this has already been reported or<br>not.<br><br>I looked into this the la=
st day, I could reproduce it locally.=C2=A0 Rather<br>than the Java harness=
 I used ~60 concurrent psql clients looping DROP /<br>CREATE OR REPLACE / C=
ALL of the same empty plpgsql procedure<br>(track_functions=3Dall, pg_stat_=
statements loaded); here it PANICs within<br>a few seconds.<br><br>Just bef=
ore the PANIC the failing backend logs:<br><br>=C2=A0 ERROR: =C2=A0trying t=
o drop stats entry already dropped: kind=3Dfunction ...<br>=C2=A0 WARNING: =
=C2=A0AbortTransaction while in COMMIT state<br>=C2=A0 PANIC: =C2=A0cannot =
abort transaction xxx, it was already committed<br><br>So it looks like a f=
unction&#39;s shared stats entry gets dropped twice:<br>once out-of-band fr=
om pgstat_init_function_usage() when a concurrent<br>CALL notices the funct=
ion is gone, and once from the transactional drop<br>at DROP time.=C2=A0 Wh=
en the latter loses the race it runs from<br>AtEOXact_PgStat(), past the co=
mmit record, so the &quot;already dropped&quot;<br>elog() in pgstat_drop_en=
try_internal() becomes the PANIC.<br><br>The two droppers and the guard all=
 seem to date back to PG 15<br>(5891c7a8ed8f).=C2=A0 I guess the &quot;drop=
 exactly once&quot; assumption behind that<br>guard doesn&#39;t really hold=
 for function stats, where two independent<br>droppers are legitimate.<br><=
br>I&#39;ve added Andres and Michael on the thread, since they have worked =
on<br>this in the past, for their input.<br><br>Regards,<br>Ayush</div></di=
v></div>

--000000000000474998065447409b--