Re: BUG #5556: "cannot drop active portal" and "ERRORDATA_STACK_SIZE exceeded" lead to server crash

The following bug has been logged online:

Bug reference: 5556
Logged by: Robert Walker
Email address: robwalker01(at)speedymail(dot)org
PostgreSQL version: 9.0 beta3
Operating system: WinXP 32-bit
Description: "cannot drop active portal" and "ERRORDATA_STACK_SIZE
exceeded" lead to server crash
Details:

Since version 9.0 beta3 I've been having a problem with the backend crashing
that wasn't happening before in version 9.0 beta2.

Looking at the psql-bugs mailing list, I found two entries that might be
related:

http://archives.postgresql.org/pgsql-bugs/2010-06/msg00321.php
http://archives.postgresql.org/pgsql-bugs/2010-07/msg00022.php

The final patch introduced from the July 5th entry introduces changes that
in my situation eventually generates an error at portalmem.c line 419 (I
believe). I'm not sure where the problem is actually starting at though, as
I don't understand PostgreSQL's internals on that level. I assume it has to
do with the FOR LOOP in the plpgsql function I created using implied/unnamed
portals, and having problems with that.

The intent of what I was originally trying to do is to intentionally cause a
unique constraint violation for the sake of testing to ensure that I won't
get duplicate data in the final design. But when the unique violation
occurs, a series of other (possibly related?) errors occur that lead to the
crash.

-----------------------------------------
The following is the contents of the log:
-----------------------------------------

2010-07-12 15:23:11 CDT LOCATION: exec_simple_query,
.\src\backend\tcop\postgres.c:894
2010-07-12 15:23:25 CDT WARNING: 25P01: there is no transaction in
progress
2010-07-12 15:23:25 CDT LOCATION: EndTransactionBlock,
.\src\backend\access\transam\xact.c:3179
2010-07-12 15:23:28 CDT ERROR: 23505: duplicate key value violates unique
constraint "aisle_grid_columns_pkey"
2010-07-12 15:23:28 CDT DETAIL: Key (aisle_grid_column, aisle_id, area_id,
site_id)=(15, 1, 1, e435198e-f6b8-11dd-a076-0ba58160eb99) already exists.
2010-07-12 15:23:28 CDT CONTEXT: SQL statement "INSERT INTO
ebatt.aisle_grid_columns (

site_id,

area_id,

aisle_id,

aisle_grid_column,

aisle_zone_id,

beginning_aisle_grid_column_for_zone,

ending_aisle_grid_column_for_zone

)

VALUES (

_site_id,

_area_id,

_aisle_id,

_c.new_c,

_aisle_zone_id,

_beginning_aisle_grid_column,

_ending_aisle_grid_column

)"
PL/pgSQL function "add_aisle_zone" line 144 at SQL statement
2010-07-12 15:23:28 CDT LOCATION: _bt_check_unique,
.\src\backend\access\nbtree\nbtinsert.c:389
2010-07-12 15:23:28 CDT STATEMENT:
SELECT config.add_aisle_zone(
aisle_zone_id := 3,
aisle_id := 1,
area_id := 1,
site_id := 'e435198e-f6b8-11dd-a076-0ba58160eb99',
default_exchanger_id := 2,
current_exchanger_id := 2,
beginning_aisle_grid_column := 15,
ending_aisle_grid_column := 24,
row_height := 4,
is_safety_guarded := TRUE,
is_enabled := TRUE
);

2010-07-12 15:23:28 CDT ERROR: 24000: cannot drop active portal "<unnamed
portal 24>"
2010-07-12 15:23:28 CDT LOCATION: PortalDrop,
.\src\backend\utils\mmgr\portalmem.c:419
2010-07-12 15:23:28 CDT STATEMENT: ROLLBACK to _EXEC_SVP_00F8A1C8
2010-07-12 15:23:28 CDT ERROR: 24000: cannot drop active portal "<unnamed
portal 24>"
2010-07-12 15:23:28 CDT LOCATION: PortalDrop,
.\src\backend\utils\mmgr\portalmem.c:419
2010-07-12 15:23:28 CDT ERROR: 24000: cannot drop active portal "<unnamed
portal 24>"
2010-07-12 15:23:28 CDT LOCATION: PortalDrop,
.\src\backend\utils\mmgr\portalmem.c:419
2010-07-12 15:23:28 CDT ERROR: 24000: cannot drop active portal "<unnamed
portal 24>"
2010-07-12 15:23:28 CDT LOCATION: PortalDrop,
.\src\backend\utils\mmgr\portalmem.c:419
2010-07-12 15:23:28 CDT ERROR: 24000: cannot drop active portal "<unnamed
portal 24>"
2010-07-12 15:23:28 CDT LOCATION: PortalDrop,
.\src\backend\utils\mmgr\portalmem.c:419
2010-07-12 15:23:28 CDT PANIC: XX000: ERRORDATA_STACK_SIZE exceeded
2010-07-12 15:23:28 CDT LOCATION: errstart,
.\src\backend\utils\error\elog.c:329

This application has requested the Runtime to terminate it in an unusual
way.
Please contact the application's support team for more information.

2010-07-12 15:23:28 CDT LOG: 00000: server process (PID 4368) exited with
exit code 3
2010-07-12 15:23:28 CDT LOCATION: LogChildExit,
.\src\backend\postmaster\postmaster.c:2812
2010-07-12 15:23:28 CDT LOG: 00000: terminating any other active server
processes
2010-07-12 15:23:28 CDT LOCATION: HandleChildCrash,
.\src\backend\postmaster\postmaster.c:2646
2010-07-12 15:23:28 CDT WARNING: 57P02: terminating connection because of
crash of another server process
2010-07-12 15:23:28 CDT 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.
2010-07-12 15:23:28 CDT HINT: In a moment you should be able to reconnect
to the database and repeat your command.
2010-07-12 15:23:28 CDT LOCATION: quickdie,
.\src\backend\tcop\postgres.c:2626
2010-07-12 15:23:28 CDT LOG: 00000: all server processes terminated;
reinitializing
2010-07-12 15:23:28 CDT LOCATION: PostmasterStateMachine,
.\src\backend\postmaster\postmaster.c:3066
2010-07-12 15:23:38 CDT FATAL: XX000: pre-existing shared memory block is
still in use
2010-07-12 15:23:38 CDT HINT: Check if there are any old server processes
still running, and terminate them.
2010-07-12 15:23:38 CDT LOCATION: PGSharedMemoryCreate,
.\src\backend\port\win32_shmem.c:194

"Robert Walker" <robwalker01(at)speedymail(dot)org> writes:
> Description: "cannot drop active portal" and "ERRORDATA_STACK_SIZE
> exceeded" lead to server crash

We're really going to need to see a self-contained example to do much
with this.

regards, tom lane

On 13/07/10 05:00, Robert Walker wrote:

> The intent of what I was originally trying to do is to intentionally cause a
> unique constraint violation for the sake of testing to ensure that I won't
> get duplicate data in the final design. But when the unique violation
> occurs, a series of other (possibly related?) errors occur that lead to the
> crash.

> This application has requested the Runtime to terminate it in an unusual
> way.
> Please contact the application's support team for more information.

It'd be really nice to have a backtrace of that. PostgreSQL binaries for
Windows are released with debug information, and if you can reproduce
the crash it's not hard to get a stack trace showing a fair bit of
information about the state the backend was in when it crashed.

See:

http://wiki.postgresql.org/wiki/Getting_a_stack_trace_of_a_running_PostgreSQL_backend_on_Windows

You'll need Debugging Tools for Windows or even better, the Visual C++
Express Edition. Both are free downloads. If you have a paid version of
Visual Studio, that's even better.

It is very important to set your symbol path up properly, and make sure
that the information you collect is useful. See the instructions above.

--
Craig Ringer

Tech-related writing: http://soapyfrogs.blogspot.com/

On 13/07/10 02:22, Tom Lane wrote:
> "Robert Walker"<robwalker01(at)speedymail(dot)org> writes:
>> Description: "cannot drop active portal" and "ERRORDATA_STACK_SIZE
>> exceeded" lead to server crash
>
> We're really going to need to see a self-contained example to do much
> with this.

I see what's going on, I neglected to change subtransaction abort
cleanup the same way I did main transaction cleanup. This is
reproducible with:

CREATE OR REPLACE FUNCTION func() RETURNS VOID AS '
declare
erec record;
--cur CURSOR IS SELECT generate_series(1,10) AS a;
BEGIN
FOR erec IN EXECUTE ''SELECT generate_series(1,10) AS a'' LOOP
raise notice ''row %'', erec.a ;
IF (erec.a = 5) THEN PERFORM closefunc(); END IF;
END LOOP;
RETURN;
END;
' LANGUAGE plpgsql;

CREATE OR REPLACE FUNCTION closefunc() RETURNS void AS ' CLOSE "<unnamed
portal 1>"; ' LANGUAGE sql;

begin;
savepoint sp1;
select func();
rollback to savepoint sp1;

Thanks for the report! I'll fix that.

--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com