DataDog/pg_tracing

Assertion failure with cursor

Closed this issue · 2 comments

postgres=# create table foo (i int);
CREATE TABLE
postgres=# insert into foo select g from generate_series(1, 100000) g;
INSERT 0 100000
postgres=# set pg_tracing.sample_rate = 1.0;
SET
postgres=# begin;
BEGIN
postgres=*# declare foocur CURSOR FOR SELECT * from foo;
DECLARE CURSOR
postgres=*# fetch forward 10 from foocur;
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.
TRAP: failed Assert("nested_level <= max_nested_level"), File: "src/pg_tracing.c", Line: 620, PID: 510625
postgres: heikki postgres [local] FETCH(ExceptionalCondition+0xaf)[0x55fb74f9651f]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x7242)[0x7f96b5563242]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x4940)[0x7f96b5560940]
postgres: heikki postgres [local] FETCH(ExecutorRun+0x45)[0x55fb74a77db5]
postgres: heikki postgres [local] FETCH(+0x720924)[0x55fb74d76924]
postgres: heikki postgres [local] FETCH(+0x7217ec)[0x55fb74d777ec]
postgres: heikki postgres [local] FETCH(PortalRunFetch+0x179)[0x55fb74d77149]
postgres: heikki postgres [local] FETCH(PerformPortalFetch+0x191)[0x55fb749d7f31]
postgres: heikki postgres [local] FETCH(standard_ProcessUtility+0x515)[0x55fb74d78b25]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x5366)[0x7f96b5561366]
postgres: heikki postgres [local] FETCH(ProcessUtility+0x132)[0x55fb74d785d2]
postgres: heikki postgres [local] FETCH(+0x721c7a)[0x55fb74d77c7a]
postgres: heikki postgres [local] FETCH(+0x720734)[0x55fb74d76734]
postgres: heikki postgres [local] FETCH(PortalRun+0x29f)[0x55fb74d7637f]
postgres: heikki postgres [local] FETCH(+0x71b727)[0x55fb74d71727]
postgres: heikki postgres [local] FETCH(PostgresMain+0x922)[0x55fb74d70992]
postgres: heikki postgres [local] FETCH(+0x713063)[0x55fb74d69063]
postgres: heikki postgres [local] FETCH(postmaster_child_launch+0xe7)[0x55fb74c69867]
postgres: heikki postgres [local] FETCH(+0x61a6fa)[0x55fb74c706fa]
postgres: heikki postgres [local] FETCH(+0x617b99)[0x55fb74c6db99]
postgres: heikki postgres [local] FETCH(PostmasterMain+0x18e7)[0x55fb74c6cd87]
postgres: heikki postgres [local] FETCH(+0x4bd7dd)[0x55fb74b137dd]
/lib/x86_64-linux-gnu/libc.so.6(+0x2724a)[0x7f96b484824a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x85)[0x7f96b4848305]
postgres: heikki postgres [local] FETCH(_start+0x21)[0x55fb74730b21]
2024-05-06 20:44:22.611 EEST [510617] LOG:  server process (PID 510625) was terminated by signal 6: Aborted
2024-05-06 20:44:22.611 EEST [510617] DETAIL:  Failed process was running: fetch forward 10 from foocur;
2024-05-06 20:44:22.611 EEST [510617] LOG:  terminating any other active server processes

Thanks for the fix!

This still fails:

postgres=# begin;
BEGIN
postgres=*# declare foocur CURSOR FOR SELECT * from foo;
DECLARE CURSOR
postgres=*# move forward 100 foocur;
MOVE 100
postgres=*# close foocur;
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.
TRAP: failed Assert("nested_level <= max_nested_level"), File: "src/pg_tracing.c", Line: 620, PID: 560011
postgres: heikki postgres ::1(57476) CLOSE CURSOR(ExceptionalCondition+0xaf)[0x55900b67551f]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x7272)[0x7f045eeab272]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x4cc2)[0x7f045eea8cc2]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(ExecutorFinish+0x27)[0x55900b1572d7]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(PortalCleanup+0xdd)[0x55900b0b71dd]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(PortalDrop+0x187)[0x55900b6c4e77]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(PerformPortalClose+0x156)[0x55900b0b70f6]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(standard_ProcessUtility+0x4ff)[0x55900b457b0f]
/home/heikki/pgsql.master/lib/pg_tracing.so(+0x5396)[0x7f045eea9396]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(ProcessUtility+0x132)[0x55900b4575d2]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x721c7a)[0x55900b456c7a]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x720e56)[0x55900b455e56]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(PortalRun+0x330)[0x55900b455410]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x71b727)[0x55900b450727]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(PostgresMain+0x922)[0x55900b44f992]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x713063)[0x55900b448063]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(postmaster_child_launch+0xe7)[0x55900b348867]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x61a6fa)[0x55900b34f6fa]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x617b99)[0x55900b34cb99]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(PostmasterMain+0x18e7)[0x55900b34bd87]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(+0x4bd7dd)[0x55900b1f27dd]
/lib/x86_64-linux-gnu/libc.so.6(+0x2724a)[0x7f045e24824a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x85)[0x7f045e248305]
postgres: heikki postgres ::1(57476) CLOSE CURSOR(_start+0x21)[0x55900ae0fb21]
2024-05-07 15:28:08.445 EEST [556193] LOG:  server process (PID 560011) was terminated by signal 6: Aborted
2024-05-07 15:28:08.445 EEST [556193] DETAIL:  Failed process was running: close foocur;
2024-05-07 15:28:08.445 EEST [556193] LOG:  terminating any other active server processes

Thanks for the report.
I've pushed another fix that handles cursor close.