Re: Termination When Switching between PL/Perl and PL/PerlU

Found in 8.4.2, replicated in HEAD. Steps:

1. Create PL/Perl function.
2. Run it.
3. Create same function with PL/PerlU
4. Run it.
5. Create same function again with PL/Perl
6. Boom.

Example on HEAD built today (ignore the error from the plperl version, that's the issue I'm trying to fix locally):

postgres=# create or replace function wtf(text) returns text language plperl as 'shift';
CREATE FUNCTION
Time: 151.054 ms
postgres=# select wtf('hey');
ERROR: invalid byte sequence for encoding "UTF8": 0x00
CONTEXT: PL/Perl function "wtf"
postgres=# create or replace function wtf(text) returns text language plperlu as 'shift';
CREATE FUNCTION
Time: 41.255 ms
postgres=# select wtf('hey');
wtf
-----
hey
(1 row)

Time: 0.523 ms
postgres=# create or replace function wtf(text) returns text language plperl as 'shift';
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.

David E. Wheeler wrote:
> Found in 8.4.2, replicated in HEAD. Steps:
>
> 1. Create PL/Perl function.
> 2. Run it.
> 3. Create same function with PL/PerlU
> 4. Run it.
> 5. Create same function again with PL/Perl
> 6. Boom.

This was just discussed in -HACKERS. Have a look at the archives.

--
Craig Ringer

Craig Ringer <craig(at)postnewspapers(dot)com(dot)au> writes:
> David E. Wheeler wrote:
>> Found in 8.4.2, replicated in HEAD. Steps:
>>
>> 1. Create PL/Perl function.
>> 2. Run it.
>> 3. Create same function with PL/PerlU
>> 4. Run it.
>> 5. Create same function again with PL/Perl
>> 6. Boom.

> This was just discussed in -HACKERS. Have a look at the archives.

No, this is something different, because it still crashes even with the
fix for that other issue. I see this in the postmaster log:

panic: free from wrong pool.
LOG: server process (PID 15697) exited with exit code 255

There's no core dump (thank you, perl). The lower-case panic message
must be from libperl because PG has no such message. I guess that we
probably need to fix this by changing the timing of interpreter
switching relative to throwing away the old compiled function ...

regards, tom lane

> > David E. Wheeler wrote:
> >> Found in 8.4.2, replicated in HEAD. Steps:
> >>
> >> 1. Create PL/Perl function.
> >> 2. Run it.
> >> 3. Create same function with PL/PerlU
> >> 4. Run it.
> >> 5. Create same function again with PL/Perl
> >> 6. Boom.
>
> > This was just discussed in -HACKERS. Have a look at the archives.
>
> No, this is something different, because it still crashes even with the
> fix for that other issue. I see this in the postmaster log:
>
> panic: free from wrong pool.
> LOG: server process (PID 15697) exited with exit code 255
>
> There's no core dump (thank you, perl).

> The lower-case panic message
> must be from libperl because PG has no such message. I guess that we
> probably need to fix this by changing the timing of interpreter
> switching relative to throwing away the old compiled function ...

I added this to src/pl/plperl/sql/plperl_plperlu.sql:

-- recompile same function with different languages
create or replace function wtf(text) returns text language plperl as 'shift';
select wtf('hey');
create or replace function wtf(text) returns text language plperlu as 'shift';
select wtf('hey');
create or replace function wtf(text) returns text language plperl as 'shift';
select wtf('hey');

The first two work ok, the third causes:
LOG: server process (PID 41692) was terminated by signal 10: Bus error

I've appended the stack trace.

That was using a cvs head (via git) from ~ the 9th of Jan.
I got the same failure after applying my feature1a-utils patch,
but then applying my feature1b-misc patch fixed it.

Tim.

#0 0x00ce26d3 in Perl_pad_undef (my_perl=0x10b0800, cv=0x1183bb0) at pad.c:262
262 if (namesv && namesv != &PL_sv_undef
(gdb) bt
#0 0x00ce26d3 in Perl_pad_undef (my_perl=0x10b0800, cv=0x1183bb0) at pad.c:262
#1 0x00cd8057 in Perl_cv_undef (my_perl=0x10b0800, cv=0x1183bb0) at op.c:4301
#2 0x00d3e86c in Perl_sv_clear (my_perl=0x10b0800, sv=0x1183bb0) at sv.c:4702
#3 0x00d3ed9c in Perl_sv_free (my_perl=0x10b0800, sv=0x1183bb0) at sv.c:4862
#4 0x00d3ea26 in Perl_sv_clear (my_perl=0x10b0800, sv=0x11751e4) at sv.c:4754
#5 0x00d3ed9c in Perl_sv_free (my_perl=0x10b0800, sv=0x11751e4) at sv.c:4862
#6 0x008a821f in compile_plperl_function (fn_oid=<value temporarily unavailable, due to optimizations>, is_trigger=0 '\0') at plperl.c:1579
#7 0x008a98f3 in plperl_validator (fcinfo=0xbfffd408) at plperl.c:994
#8 0x00316770 in OidFunctionCall1 (functionId=101107, arg1=101158) at fmgr.c:1562
#9 0x000a8cc8 in ProcedureCreate (procedureName=0x101a5ac "wtf", procNamespace=2200, replace=1 '\001', returnsSet=0 '\0', returnType=25, languageObjectId=101108, languageValidator=101107, prosrc=0x101a7ec "shift", probin=0x0, isAgg=0 '\0', isWindowFunc=0 '\0', security_definer=0 '\0', isStrict=0 '\0', volatility=118 'v', parameterTypes=0x10ed50c, allParameterTypes=0, parameterModes=0, parameterNames=0, parameterDefaults=0x0, proconfig=0, procost=100, prorows=0) at pg_proc.c:621
#10 0x001119be in CreateFunction (stmt=0x101a884, queryString=0x1019c1c "create or replace function wtf(text) returns text language plperl as 'shift';") at functioncmds.c:941
#11 0x0023f317 in MemoryContextSwitchTo [inlined] () at /Users/timbo/pg/postgresql/src/include/utils/palloc.h:1192
#12 0x0023f317 in PortalRunUtility (portal=0x10a561c, utilityStmt=0x101a884, isTopLevel=<value temporarily unavailable, due to optimizations>, dest=0x101aa58, completionTag=0xbfffdbbc "") at pquery.c:1200
#13 0x00240a0b in PortalRunMulti (portal=0x10a561c, isTopLevel=1 '\001', dest=0x101aa58, altdest=0x101aa58, completionTag=0xbfffdbbc "") at pquery.c:1297
#14 0x0024120c in PortalRun (portal=0x10a561c, count=2147483647, isTopLevel=<value temporarily unavailable, due to optimizations>, dest=0x101aa58, altdest=0x101aa58, completionTag=0xbfffdbbc "") at pquery.c:823
#15 0x0023cfe8 in exec_simple_query (query_string=0x1019c1c "create or replace function wtf(text) returns text language plperl as 'shift';") at postgres.c:1045
#16 0x0023de40 in PostgresMain (argc=2, argv=0x1016ba4, username=0x1016a54 "timbo") at postgres.c:3694
#17 0x001fd6ae in ServerLoop () at postmaster.c:3373
#18 0x001fe83f in PostmasterMain (argc=1, argv=0x9009f0) at postmaster.c:1069
#19 0x00191d3d in main (argc=1, argv=0x9009f0) at main.c:188

On Thu, Jan 14, 2010 at 06:41:52PM +0000, Tim Bunce wrote:
> > > David E. Wheeler wrote:
> > >> Found in 8.4.2, replicated in HEAD. Steps:
> > >>
> > >> 1. Create PL/Perl function.
> > >> 2. Run it.
> > >> 3. Create same function with PL/PerlU
> > >> 4. Run it.
> > >> 5. Create same function again with PL/Perl
> > >> 6. Boom.
> >
> > panic: free from wrong pool.
> > LOG: server process (PID 15697) exited with exit code 255
> >
> > There's no core dump (thank you, perl). The lower-case panic message
> > must be from libperl because PG has no such message. I guess that we
> > probably need to fix this by changing the timing of interpreter
> > switching relative to throwing away the old compiled function ...
>
> I added this to src/pl/plperl/sql/plperl_plperlu.sql:
> -- recompile same function with different languages
> create or replace function wtf(text) returns text language plperl as 'shift';
> select wtf('hey');
> create or replace function wtf(text) returns text language plperlu as 'shift';
> select wtf('hey');
> create or replace function wtf(text) returns text language plperl as 'shift';
> select wtf('hey');
>
> The first two work ok, the third causes:
> LOG: server process (PID 41692) was terminated by signal 10: Bus error

> That was using a cvs head (via git) from ~ the 9th of Jan.
> I got the same failure after applying my feature1a-utils patch,
> but then applying my feature1b-misc patch fixed it.

Not quite out of the woods. My next patch adds in destruction of the
perl interpreters. That's showing the 'wrong pool' in a different way:

Scalars leaked: -1
Scalars leaked: 1

I want to get some more patches into the commitfest before it closes.
After that I'll look into this some more, if someone else hasn't got to
it first.

Tim.

On Thu, Jan 14, 2010 at 08:45:06PM +0000, Tim Bunce wrote:
> On Thu, Jan 14, 2010 at 06:41:52PM +0000, Tim Bunce wrote:
> > > > David E. Wheeler wrote:
> > > >> Found in 8.4.2, replicated in HEAD. Steps:
> > > >>
> > > >> 1. Create PL/Perl function.
> > > >> 2. Run it.
> > > >> 3. Create same function with PL/PerlU
> > > >> 4. Run it.
> > > >> 5. Create same function again with PL/Perl
> > > >> 6. Boom.
> > >
> > > panic: free from wrong pool.
> > > LOG: server process (PID 15697) exited with exit code 255
> > >
> > > There's no core dump (thank you, perl). The lower-case panic message
> > > must be from libperl because PG has no such message. I guess that we
> > > probably need to fix this by changing the timing of interpreter
> > > switching relative to throwing away the old compiled function ...
> >
> > [...]
>
> > That was using a cvs head (via git) from ~ the 9th of Jan.
> > I got the same failure after applying my feature1a-utils patch,
> > but then applying my feature1b-misc patch fixed it.
>
> Not quite out of the woods. My next patch adds in destruction of the
> perl interpreters. That's showing the 'wrong pool' in a different way:
>
> Scalars leaked: -1
> Scalars leaked: 1
>
> I want to get some more patches into the commitfest before it closes.
> After that I'll look into this some more, if someone else hasn't got to
> it first.

The attached patch fixes the (longstanding) problem.

It should apply cleanly over the "Miscellaneous changes to plperl"
patch (which I believe Andrew Dunstan intends to commit shortly).

A backport of the core fix in plperl.c should be simple.

Tim.