Possible bug in PostgreSQL 8.3beta4 (postgres process segfaults)

On 12/12/2007, Lawrence Oluyede <l.oluyede@gmail.com> wrote:

While developing a Python program I encountered a situation that makes
on of the PostgreSQL 8.3b4's processes crash badly with a segfault.
Let me explain.

After enabling "debug5" as log level I was able to locate and
reproduce the exact sequence of SQL queries made against my test
database
and crash postgres again using only "psql". See for yourself:

foodb=# \o out.txt
foodb=# SELECT * FROM foobaz.instrument WHERE code = 'TEST0118';
LOG: duration: 3.683 ms statement: SELECT * FROM foobaz.instrument
WHERE code = 'TEST0118';
foodb=# SELECT xpath('//sp:description/text()', content,
ARRAY[ARRAY['sp', 'http://www.foobaz.com/&#39;]])
foodb-# FROM foobaz.instrument WHERE code = 'TEST0018';
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.

The pgsql log file contains these error logs (the pid 753 is a
postgres child process):

"""""""""
[loluyede:foodb:2007-12-11 14:38:20.992 CET]LOG: 00000: duration:
0.090 ms statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ
COMMITTED
[loluyede:foodb:2007-12-11 14:38:20.992 CET]LOCATION:
exec_simple_query, postgres.c:1040
[::2007-12-11 14:38:20.993 CET]LOG: 00000: server process (PID 753)
was terminated by signal 11: Segmentation fault
[::2007-12-11 14:38:20.993 CET]LOCATION: LogChildExit, postmaster.c:2510
[::2007-12-11 14:38:20.993 CET]LOG: 00000: terminating any other
active server processes
[::2007-12-11 14:38:20.993 CET]LOCATION: HandleChildCrash, postmaster.c:2355
[::2007-12-11 14:38:20.997 CET]LOG: 00000: all server processes
terminated; reinitializing
[::2007-12-11 14:38:20.997 CET]LOCATION: PostmasterStateMachine,
postmaster.c:2663
[::2007-12-11 14:38:21.000 CET]LOG: 00000: database system was
interrupted; last known up at 2007-12-11 14:38:02 CET
[::2007-12-11 14:38:21.000 CET]LOCATION: StartupXLOG, xlog.c:4789
[::2007-12-11 14:38:21.000 CET]DEBUG: 00000: checkpoint record is at 0/2AB634A0
""""""""

The out.txt file contains the output of the "SELECT *" statement

code | kind | last_modified |
created | modified_by | created_by |
content
----------+------------+-------------------------------+------------------------------+-------------+------------+----------------------------------------------------------------------
TEST0118 | bazfoo | 2007-12-12 08:17:01.846919+01 | 2007-12-12
08:17:00.32337+01 | anonymous | anonymous | <xml ... >
(1 row)

The "instrument" table has the following schema:

"""
CREATE TABLE foobaz.instrument
(
-- Inherited: code character varying(32) NOT NULL,
-- Inherited: kind character varying(32) NOT NULL DEFAULT
'bazfoo'::character varying,
last_modified timestamp with time zone NOT NULL,
created timestamp with time zone NOT NULL DEFAULT
('now'::text)::timestamp(3) with time zone,
modified_by character varying(64),
created_by character varying(64) NOT NULL DEFAULT
'anonymous'::character varying,
content xml NOT NULL,
CONSTRAINT instrument_pkey PRIMARY KEY (code),
CONSTRAINT instrument_kind_check CHECK (kind::text = 'bazfoo'::text)
)
INHERITS (foobaz.instrument_base)
WITH (OIDS=FALSE);
"""

Its "parent" table is instrument_base and has the following schema:

"""
CREATE TABLE foobaz.instrument_base
(
code character varying(32) NOT NULL,
kind character varying(32) NOT NULL,
CONSTRAINT instrument_base_pkey PRIMARY KEY (code)
)
WITH (OIDS=FALSE);
"""

PostgreSQL is again 8.3beta 4 on Ubuntu Linux 7.10.
It's compiled with the following flags:
./configure --with-python --with-openssl --with-pam --with-libxml
--with-libxslt --enable-thread-safety --enable-debug

libxml is 2.6.30, libxslt is 1.1.21

I think that is all.

Is it a bug or am I doing something wrong?

--
Lawrence, oluyede.org - neropercaso.it
"It is difficult to get a man to understand
something when his salary depends on not
understanding it" - Upton Sinclair

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

On 12/12/2007, Lawrence Oluyede <l.oluyede@gmail.com> wrote:

Here it is:

postgres$ gdb /usr/local/pgsql/bin/postgres core.1600
(gdb) bt
#0 0x082c101c in pfree (pointer=0x8472f00) at mcxt.c:591
#1 0xb7e46513 in xmlCleanupCharEncodingHandlers () from /usr/lib/libxml2.so.2
#2 0xb7e4f091 in xmlCleanupParser () from /usr/lib/libxml2.so.2
#3 0x082940e4 in xpath (fcinfo=0xbfee59c4) at xml.c:3441
#4 0x0817107f in ExecMakeFunctionResult (fcache=0x84723d0,
econtext=0x8472348, isNull=0x8472fa8 "", isDone=0x8472fb8) at
execQual.c:1351
#5 0x0816f522 in ExecProject (projInfo=0x8472e98, isDone=0xbfee5c78)
at execQual.c:4601
#6 0x08175987 in ExecScan (node=0x84722c0, accessMtd=0x817e310
<IndexNext>) at execScan.c:143
#7 0x0817e2e7 in ExecIndexScan (node=0x84722c0) at nodeIndexscan.c:147
#8 0x0816ee7a in ExecProcNode (node=0x84722c0) at execProcnode.c:338
#9 0x0816e113 in ExecutorRun (queryDesc=0x845e908,
direction=ForwardScanDirection, count=0) at execMain.c:1233
#10 0x08204ea0 in PortalRunSelect (portal=0x84577a0, forward=<value
optimized out>, count=0, dest=0x845d1c8) at pquery.c:943
#11 0x08205eaa in PortalRun (portal=0x84577a0, count=2147483647,
isTopLevel=1 '\001', dest=0x845d1c8, altdest=0x845d1c8,
completionTag=0xbfee5ee8 "") at pquery.c:797
#12 0x082013c3 in exec_simple_query (
query_string=0x8453790 "SELECT xpath('//sp:description/text()',
content, ARRAY[ARRAY['sp',
'http://www.statpro.net/xml/structure/1.0&#39;]])\n FROM instrument
WHERE code = 'TEST0018';") at postgres.c:963
#13 0x08202ebc in PostgresMain (argc=4, argv=<value optimized out>,
username=0x83d2330 "postgres") at postgres.c:3531
#14 0x081d76cf in ServerLoop () at postmaster.c:3180
#15 0x081d83a5 in PostmasterMain (argc=3, argv=0x83ccb08) at postmaster.c:1028
#16 0x081909a0 in main (argc=3, argv=0x82c0c00) at main.c:188
(gdb) l
586 header = (StandardChunkHeader *)
587 ((char *) pointer - STANDARDCHUNKHEADERSIZE);
588
589 AssertArg(MemoryContextIsValid(header->context));
590
591 (*header->context->methods->free_p) (header->context, pointer);
592 }
593
594 /*
595 * repalloc

I also uploaded the entire core file on the net, if you want to inspect it:
http://www.oluyede.org/temp/core.1600 (it's ~ 30M)

thank you

--
Lawrence, oluyede.org - neropercaso.it
"It is difficult to get a man to understand
something when his salary depends on not
understanding it" - Upton Sinclair