Thread: 8.3b2 XPath-based function index server crash

Hello, I currently have a table in Postgres 8.1 with a text column that
contains XML. I use the xml2 module to define several XPath-based function
indices on that column, and this has worked very well.

I'm trying not to evaluate the native XML support in 8.3b2. I dumped this
table from 8.1, then loaded the data into a new table in 8.3 with the text
column re-defined as the xml type. The load happened without any errors.

Now I am trying to define equivalent XPath based function indices on the
xml column, but am running into a problem where the server processes the
'add index' command for a while, then crashes with a seg fault. While
investigating, I found I was able to reproduce the crash consistently by
executing a select statement with a large offset and limit in the query.

Initially I had thought some particular row in the xml column was causing
a problem. However, if I query directly for any specific row by its
primary key, the server does not crash and returns the result without
error.

Here are some details of the xml functions I am trying to perform. In 8.1,
I have an xml2 module function index defined like

"assigned_area_idx" btree (xpath_string(xml,
'/als:auto-lead-service/als:meta[@key="AREA"][1]'::text))

Here "xml" in the text column. In 8.3, then, I was trying to mimic this
same index with this:

create index assigned_area_idx ON lead (
    XMLSERIALIZE( CONTENT
(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()', xml,
        ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
);

Is this the correct way to define such an index? I tried several different
ways, and this seemed to be the only way I could get it to be accepted.
However, after running for a while, this command fails and the postgres
server crashes.

So I explored with a SELECT statement, thinking there was some specific
XML document causing the crash. I could consistently execute this
statement to get a crash:

select XMLSERIALIZE( CONTENT
(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()', xml,
        ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
from lead order by id limit 1 offset 83367;

The query would take a long time to execute, and then crash. I took some
samples with Instruments (OS X) and found while the server was processing
this select, it was spending a ton of time in libxml2, as if it was
evaluating the XMLSERIALIZE on every row leading up to the first returned
offset row. Is that expected for this type of query (i.e. I was thinking
it would just find the first offset row, then execute the XMLSERIALIZE
statement on that row)?

If I query for that same row using its primary key instead of the offset,
the query runs fine and returns the expected results, i.e.

select id, XMLSERIALIZE( CONTENT
(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()', xml,
        ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
from lead where id = 84521;

-- m@

"Matt Magoffin" <postgresql.org@msqr.us> writes:
> So I explored with a SELECT statement, thinking there was some specific
> XML document causing the crash. I could consistently execute this
> statement to get a crash:

> select XMLSERIALIZE( CONTENT
> (xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()', xml,
>         ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
> from lead order by id limit 1 offset 83367;

Could you put together a self-contained example?  It would probably take
someone else a long time to guess at all the details you've left out.

One point in particular is that this query would not use the index
you mentioned, so I doubt that's relevant.

            regards, tom lane

In article <8105.1195417999@sss.pgh.pa.us>,
 tgl@sss.pgh.pa.us (Tom Lane) wrote:

> "Matt Magoffin" <postgresql.org@msqr.us> writes:
> > So I explored with a SELECT statement, thinking there was some specific
> > XML document causing the crash. I could consistently execute this
> > statement to get a crash:
>
> > select XMLSERIALIZE( CONTENT
> > (xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()', xml,
> >         ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
> > from lead order by id limit 1 offset 83367;
>
> Could you put together a self-contained example?  It would probably take
> someone else a long time to guess at all the details you've left out.
>
> One point in particular is that this query would not use the index
> you mentioned, so I doubt that's relevant.
>
>             regards, tom lane

Sorry if I left any relavent details out. I've been looking at this for
a while so many things are probably obvious only to me. Could you hint
at which additional details you think would be useful here?

-- m@

On Mon, Nov 19, 2007 at 10:02:20AM +1300, Matt Magoffin wrote:
> Sorry if I left any relavent details out. I've been looking at this for
> a while so many things are probably obvious only to me. Could you hint
> at which additional details you think would be useful here?

What's being asked for is a self contained example. Can you make a
single script file that when you run it on a blank database causes the
error?

If you can't, that in itself is a useful fact. But then we need schema
dumps and such things. EXPLAIN output for the queries that break.

Have a nice day,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> Those who make peaceful revolution impossible will make violent revolution inevitable.
>  -- John F Kennedy

Matt Magoffin <postgresql.org@msqr.us> writes:
> Sorry if I left any relavent details out. I've been looking at this for
> a while so many things are probably obvious only to me. Could you hint
> at which additional details you think would be useful here?

What I asked for was a self-contained example with which someone else
could reproduce the problem.

            regards, tom lane

> On Mon, Nov 19, 2007 at 10:02:20AM +1300, Matt Magoffin wrote:
>> Sorry if I left any relavent details out. I've been looking at this for
>> a while so many things are probably obvious only to me. Could you hint
>> at which additional details you think would be useful here?
>
> What's being asked for is a self contained example. Can you make a
> single script file that when you run it on a blank database causes the
> error?
>
> If you can't, that in itself is a useful fact. But then we need schema
> dumps and such things. EXPLAIN output for the queries that break.

I understand. I cannot make the SELECT query nor the ADD INDEX command
break on an empty database. I cannot share this database data, either.
I'll try to fill in any missing details. My table schema is this:

create table lead_test (
    id int8 not null,
    xml xml,
    processing_state varchar(20) not null,
    created timestamp with time zone not null,
    last_processed timestamp with time zone,
    processing_step int4, processing_attempts int4,
    primary key (id)
);

I have approximately 400k rows loaded in one particular database.

Back in 8.1, I have some additional indices defined using the xml2 module,
like this one:

create index assigned_area_idx ON lead (
    xpath_string(xml, '/als:auto-lead-service/als:meta[@key="AREA"][1]')
);

I was first trying to do the same sort of thing in 8.3 using the native
XML support, like this:

create index assigned_area_idx ON lead (
    xmlserialize(content(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()',
xml,
        ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
);

I'm not sure if this is the correct way to do this in 8.3, but what I want
is a text-based index that I can query against like I do in 8.1. On an
empty table, this works fine. However, on my table with data in it, this
produces a crash, and the log file contains this:

DEBUG:  00000: ProcessUtility
LOCATION:  PortalRunUtility, pquery.c:1142
STATEMENT:  create index assigned_area_idx ON lead (
    xmlserialize(content(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()',
xml,
    ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as text)
    );

... time passes here with heavy CPU use...

DEBUG:  00000: StartTransaction
LOCATION:  ShowTransactionState, xact.c:3995
DEBUG:  00000: name: unnamed; blockState:       DEFAULT; state: INPROGR,
xid/subid/cid: 0/1/0, nestlvl: 1, children: <>
LOCATION:  ShowTransactionStateRec, xact.c:4020
DEBUG:  00000: CommitTransaction
LOCATION:  ShowTransactionState, xact.c:3995
DEBUG:  00000: name: unnamed; blockState:       STARTED; state: INPROGR,
xid/subid/cid: 0/1/0, nestlvl: 1, children: <>
LOCATION:  ShowTransactionStateRec, xact.c:4020
DEBUG:  00000: autovacuum: processing database "lms_infiniti"
LOCATION:  AutoVacWorkerMain, autovacuum.c:1600
DEBUG:  00000: StartTransaction
LOCATION:  ShowTransactionState, xact.c:3995
DEBUG:  00000: name: unnamed; blockState:       DEFAULT; state: INPROGR,
xid/subid/cid: 0/1/0, nestlvl: 1, children: <>
LOCATION:  ShowTransactionStateRec, xact.c:4020
DEBUG:  00000: pg_authid: vac: 0 (threshold 50), anl: 0 (threshold 50)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_database: vac: 0 (threshold 50), anl: 0 (threshold 50)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_attribute: vac: 0 (threshold 543), anl: 0 (threshold 296)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_class: vac: 0 (threshold 111), anl: 0 (threshold 81)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_index: vac: 0 (threshold 81), anl: 0 (threshold 65)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_opclass: vac: 0 (threshold 72), anl: 0 (threshold 61)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_am: vac: 0 (threshold 51), anl: 0 (threshold 50)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_amop: vac: 0 (threshold 119), anl: 0 (threshold 85)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_amproc: vac: 0 (threshold 99), anl: 0 (threshold 74)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: pg_trigger: vac: 0 (threshold 63), anl: 0 (threshold 56)
LOCATION:  relation_needs_vacanalyze, autovacuum.c:2566
DEBUG:  00000: CommitTransaction
LOCATION:  ShowTransactionState, xact.c:3995
DEBUG:  00000: name: unnamed; blockState:       STARTED; state: INPROGR,
xid/subid/cid: 0/1/0, nestlvl: 1, children: <>
LOCATION:  ShowTransactionStateRec, xact.c:4020
DEBUG:  00000: proc_exit(0)
LOCATION:  proc_exit, ipc.c:95
DEBUG:  00000: shmem_exit(0)
LOCATION:  shmem_exit, ipc.c:156
DEBUG:  00000: exit(0)
LOCATION:  proc_exit, ipc.c:113
DEBUG:  00000: reaping dead processes
LOCATION:  reaper, postmaster.c:2081
DEBUG:  00000: server process (PID 966) exited with exit code 0
LOCATION:  LogChildExit, postmaster.c:2485
DEBUG:  00000: reaping dead processes
LOCATION:  reaper, postmaster.c:2081
DEBUG:  00000: server process (PID 965) was terminated by signal 11:
Segmentation fault
LOCATION:  LogChildExit, postmaster.c:2505
LOG:  00000: server process (PID 965) was terminated by signal 11:
Segmentation fault
LOCATION:  LogChildExit, postmaster.c:2505
LOG:  00000: terminating any other active server processes
LOCATION:  HandleChildCrash, postmaster.c:2350
DEBUG:  00000: sending SIGQUIT to process 959
LOCATION:  HandleChildCrash, postmaster.c:2405
DEBUG:  00000: sending SIGQUIT to process 960
LOCATION:  HandleChildCrash, postmaster.c:2417
DEBUG:  00000: sending SIGQUIT to process 961
LOCATION:  HandleChildCrash, postmaster.c:2429
DEBUG:  00000: sending SIGQUIT to process 962
LOCATION:  HandleChildCrash, postmaster.c:2459
DEBUG:  00000: forked new backend, pid=968 socket=7
LOCATION:  BackendStartup, postmaster.c:2818
LOG:  00000: connection received: host=[local]
LOCATION:  BackendInitialize, postmaster.c:2995
FATAL:  57P03: the database system is in recovery mode
LOCATION:  ProcessStartupPacket, postmaster.c:1649
DEBUG:  00000: proc_exit(1)
LOCATION:  proc_exit, ipc.c:95
DEBUG:  00000: shmem_exit(1)
LOCATION:  shmem_exit, ipc.c:156
DEBUG:  00000: exit(1)
LOCATION:  proc_exit, ipc.c:113
DEBUG:  00000: reaping dead processes
LOCATION:  reaper, postmaster.c:2081
DEBUG:  00000: server process (PID 968) exited with exit code 1
LOCATION:  LogChildExit, postmaster.c:2485
DEBUG:  00000: reaping dead processes
LOCATION:  reaper, postmaster.c:2081
LOG:  00000: all server processes terminated; reinitializing
LOCATION:  PostmasterStateMachine, postmaster.c:2658
DEBUG:  00000: shmem_exit(0)
LOCATION:  shmem_exit, ipc.c:156
DEBUG:  00000: invoking IpcMemoryCreate(size=38330368)
LOCATION:  CreateSharedMemoryAndSemaphores, ipci.c:128
LOG:  00000: database system was interrupted; last known up at 2007-11-19
11:02:35 NZDT
LOCATION:  StartupXLOG, xlog.c:4787
DEBUG:  00000: checkpoint record is at 1/1513CA4C
LOCATION:  StartupXLOG, xlog.c:4857
DEBUG:  00000: redo record is at 1/1513CA4C; shutdown TRUE
LOCATION:  StartupXLOG, xlog.c:4883
DEBUG:  00000: next transaction ID: 0/562; next OID: 802816
LOCATION:  StartupXLOG, xlog.c:4887
DEBUG:  00000: next MultiXactId: 1; next MultiXactOffset: 0
LOCATION:  StartupXLOG, xlog.c:4890
LOG:  00000: database system was not properly shut down; automatic
recovery in progress
LOCATION:  StartupXLOG, xlog.c:4954
LOG:  00000: redo starts at 1/1513CA8C
LOCATION:  StartupXLOG, xlog.c:5016
LOG:  00000: record with zero length at 1/151498E0
LOCATION:  ReadRecord, xlog.c:3099
LOG:  00000: redo done at 1/1514805C
LOCATION:  StartupXLOG, xlog.c:5086
DEBUG:  00000: transaction ID wrap limit is 2147484026, limited by
database "template1"
LOCATION:  SetTransactionIdLimit, varsup.c:283
DEBUG:  00000: proc_exit(0)
LOCATION:  proc_exit, ipc.c:95
DEBUG:  00000: shmem_exit(0)
LOCATION:  shmem_exit, ipc.c:156
DEBUG:  00000: exit(0)
LOCATION:  proc_exit, ipc.c:113
DEBUG:  00000: reaping dead processes
LOCATION:  reaper, postmaster.c:2081
LOG:  00000: autovacuum launcher started
LOCATION:  AutoVacLauncherMain, autovacuum.c:519
LOG:  00000: database system is ready to accept connections
LOCATION:  reaper, postmaster.c:2155

That is my original problem, and primary task. To try to investigate
further, I originally thought perhaps there was some specific XML document
that would cause this crash, and tried to narrow it down by using a SELECT
statement to see if I could find where it crashed. So I used SELECT
statements with OFFSET to narrow it down, until I found the server would
consistently crash on a specific offset, for example

select
id,xmlserialize(content(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()',
xml,  ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as
text) from lead order by id limit 1 offset 100000;

However, if I alter the SQL to lookup that same row by its primary key, like

select
id,xmlserialize(content(xpath('/als:auto-lead-service/als:meta[@key="AREA"][1]/text()',
xml,  ARRAY[ARRAY['als','http://autoleadservice.com/xml/als']]))[1] as
text) from lead where id = 38373893;

it runs fine without any error. So it then seemed like the crash only
occurs after processing the XML on many rows over time.

The EXPLAIN output isn't very much, I get only:

                                QUERY PLAN
--------------------------------------------------------------------------
 Limit  (cost=103905.81..103905.82 rows=1 width=40)
   ->  Sort  (cost=103655.81..104622.53 rows=386688 width=40)
         Sort Key: id
         ->  Seq Scan on lead  (cost=0.00..46622.60 rows=386688 width=40)
(4 rows)

Hope this helps, please let me know any more details that would be helpful.

"Matt Magoffin" <postgresql.org@msqr.us> writes:
> I understand. I cannot make the SELECT query nor the ADD INDEX command
> break on an empty database. I cannot share this database data, either.

So try to make a test case using dummy data, or with suitably obscured
versions of your real data.

Also, consider compiling a debug-enabled build and showing us a gdb
stack trace from the core dump.

            regards, tom lane

> "Matt Magoffin" <postgresql.org@msqr.us> writes:
>> I understand. I cannot make the SELECT query nor the ADD INDEX command
>> break on an empty database. I cannot share this database data, either.
>
> So try to make a test case using dummy data, or with suitably obscured
> versions of your real data.
>
> Also, consider compiling a debug-enabled build and showing us a gdb
> stack trace from the core dump.

Generating obscured dummy data would be a difficult task. Here's a
stacktrace from gdb after the server crashed:

(gdb) c
Continuing.
Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_INVALID_ADDRESS at address: 0x00a04000
0xffff8820 in __memcpy ()
(gdb) bt
#0  0xffff8820 in __memcpy ()
#1  0x004d9098 in xmlBufferAdd ()
#2  0x004e0dc4 in xmlParserInputBufferCreateMem ()
#3  0x004ced98 in xmlCtxtReadMemory ()
#4  0x0026ea0c in xpath (fcinfo=0x37) at xml.c:3183
#5  0x001095bc in ExecMakeFunctionResultNoSets (fcache=0x10563fc,
econtext=0x10562a8, isNull=0xbfffd4f8 "\004Y?P", isDone=0x0) at
execQual.c:1412
#6  0x00109640 in ExecEvalArrayRef (astate=0x1056364, econtext=0x10562a8,
isNull=0xbfffd4f8 "\004Y?P", isDone=0x0) at execQual.c:254
#7  0x0010d550 in ExecEvalXml (xmlExpr=0x1056324, econtext=0x10562a8,
isNull=0xbfffd5d8 "\001)?\f", isDone=<value temporarily unavailable, due
to optimizations>) at execQual.c:3012
#8  0x0010ae18 in ExecEvalExprSwitchContext (expression=<value temporarily
unavailable, due to optimizations>, econtext=<value temporarily
unavailable, due to optimizations>, isNull=<value temporarily unavailable,
due to optimizations>, isDone=<value temporarily unavailable, due to
optimizations>) at execQual.c:3726
#9  0x00076490 in FormIndexDatum (indexInfo=0x1044ef4, slot=0x1044e1c,
estate=0x105621c, values=0xbfffd69c, isnull=0xbfffd67c "") at index.c:1041
#10 0x000770e8 in IndexBuildHeapScan (heapRelation=0x7a7428,
indexRelation=0x7a9ca0, indexInfo=0x1044ef4, callback=0x36c90
<btbuildCallback>, callback_state=0xbfffda08) at index.c:1705
#11 0x00036bfc in btbuild (fcinfo=<value temporarily unavailable, due to
optimizations>) at nbtree.c:119
#12 0x002875a8 in OidFunctionCall3 (functionId=<value temporarily
unavailable, due to optimizations>, arg1=8025128, arg2=8035488,
arg3=17059572) at fmgr.c:1580
#13 0x00074e94 in index_build (heapRelation=0x7a7428,
indexRelation=0x7a9ca0, indexInfo=0x1044ef4, isprimary=0 '\0') at
index.c:1331
#14 0x000762ac in index_create (heapRelationId=601643,
indexRelationName=0x1044fe0 "assigned_area_idx", indexRelationId=983040,
indexInfo=0x1044ef4, accessMethodObjectId=403, tableSpaceId=0,
classObjectId=0x10505c0, coloptions=0x10509e0, reloptions=0, isprimary=0
'\0', isconstraint=0 '\0', allow_system_table_mods=0 '\0', skip_build=0
'\0', concurrent=6 '\006') at index.c:817
#15 0x000cef14 in DefineIndex (heapRelation=0x1044eb4,
indexRelationName=0x1044fe0 "assigned_area_idx", indexRelationId=0,
accessMethodName=0x1044f80 "btree", tableSpaceName=0x273a "",
attributeList=0x1044db4, predicate=0x19, options=0x0, src_options=0x0,
unique=0 '\0', primary=0 '\0', isconstraint=0 '\0', is_alter_table=0 '\0',
check_rights=1 '\001', skip_build=0 '\0', quiet=0 '\0', concurrent=0 '\0')
at indexcmds.c:453
#16 0x001c8aec in ProcessUtility (parsetree=0x103ac88,
queryString=0x1044c1c "create index assigned_area_idx ON lead

(\nXMLSERIALIZE(CONTENT(xpath('/als:auto-lead-service/als:meta[@key=\"com.autoleadservice.service.AssignDealer.AREA\"][1]/text()',
xml,\nARRAY[ARRAY['als','http://au"..., params=0x0, isTopLevel=1 '\001',
dest=0x103ad04, completionTag=<value temporarily unavailable, due to
optimizations>) at utility.c:919
#17 0x001c566c in PortalRunUtility (portal=0x104bc1c,
utilityStmt=0x103ac88, isTopLevel=1 '\001', dest=0x103ad04,
completionTag=0xbfffe4ca "") at pquery.c:1173
#18 0x001c5af0 in PortalRunMulti (portal=0x104bc1c, isTopLevel=1 '\001',
dest=0x103ad04, altdest=0x103ad04, completionTag=0xbfffe4ca "") at
pquery.c:1266
#19 0x001c647c in PortalRun (portal=0x104bc1c, count=2147483647,
isTopLevel=0 '\0', dest=0x103ad04, altdest=0x103ad04,
completionTag=0xbfffe4ca "") at pquery.c:813
#20 0x001c1584 in exec_simple_query (query_string=0x1039e1c "create index
assigned_area_idx ON lead
(\nXMLSERIALIZE(CONTENT(xpath('/als:auto-lead-service/als:meta[@key=\"AREA\"][1]/text()',
xml,\nARRAY[ARRAY['als','http://au"...) at postgres.c:962
#21 0x001c335c in PostgresMain (argc=4, argv=<value temporarily
unavailable, due to optimizations>, username=0x1001650 "lms") at
postgres.c:3529
#22 0x00188f58 in ServerLoop () at postmaster.c:3175
#23 0x0018a464 in PostmasterMain (argc=8, argv=0x800420) at postmaster.c:1026
#24 0x0012d49c in main (argc=8, argv=0x800420) at main.c:188

"Matt Magoffin" <postgresql.org@msqr.us> writes:
> (gdb) bt
> #0  0xffff8820 in __memcpy ()
> #1  0x004d9098 in xmlBufferAdd ()
> #2  0x004e0dc4 in xmlParserInputBufferCreateMem ()
> #3  0x004ced98 in xmlCtxtReadMemory ()
> #4  0x0026ea0c in xpath (fcinfo=0x37) at xml.c:3183
> #5  0x001095bc in ExecMakeFunctionResultNoSets (fcache=0x10563fc,
> econtext=0x10562a8, isNull=0xbfffd4f8 "\004Y?P", isDone=0x0) at
> execQual.c:1412

[ squint... ]  Hmm, that seems to be in the same general area as some
post-beta2 fixes.  Before we spend more time on this, could you update
to 8.3beta3 and see if the problem is still there?  b3 is not officially
announced yet, but the tarballs are up.

            regards, tom lane

> "Matt Magoffin" <postgresql.org@msqr.us> writes:
>> (gdb) bt
>> #0  0xffff8820 in __memcpy ()
>> #1  0x004d9098 in xmlBufferAdd ()
>> #2  0x004e0dc4 in xmlParserInputBufferCreateMem ()
>> #3  0x004ced98 in xmlCtxtReadMemory ()
>> #4  0x0026ea0c in xpath (fcinfo=0x37) at xml.c:3183
>> #5  0x001095bc in ExecMakeFunctionResultNoSets (fcache=0x10563fc,
>> econtext=0x10562a8, isNull=0xbfffd4f8 "\004Y?P", isDone=0x0) at
>> execQual.c:1412
>
> [ squint... ]  Hmm, that seems to be in the same general area as some
> post-beta2 fixes.  Before we spend more time on this, could you update
> to 8.3beta3 and see if the problem is still there?  b3 is not officially
> announced yet, but the tarballs are up.

Sure, I'll give it a shot and report back.

-- m@

> "Matt Magoffin" <postgresql.org@msqr.us> writes:
>> (gdb) bt
>> #0  0xffff8820 in __memcpy ()
>> #1  0x004d9098 in xmlBufferAdd ()
>> #2  0x004e0dc4 in xmlParserInputBufferCreateMem ()
>> #3  0x004ced98 in xmlCtxtReadMemory ()
>> #4  0x0026ea0c in xpath (fcinfo=0x37) at xml.c:3183
>> #5  0x001095bc in ExecMakeFunctionResultNoSets (fcache=0x10563fc,
>> econtext=0x10562a8, isNull=0xbfffd4f8 "\004Y?P", isDone=0x0) at
>> execQual.c:1412
>
> [ squint... ]  Hmm, that seems to be in the same general area as some
> post-beta2 fixes.  Before we spend more time on this, could you update
> to 8.3beta3 and see if the problem is still there?  b3 is not officially
> announced yet, but the tarballs are up.

I tried looking for the 8.3b3 tarballs, but can't find them on any
download host I've tried (starting with ftp.postgresql.org, looking in the
source directory). Are they available some place else?

-- m@

>>> (gdb) bt
>>> #0  0xffff8820 in __memcpy ()
>>> #1  0x004d9098 in xmlBufferAdd ()
>>> #2  0x004e0dc4 in xmlParserInputBufferCreateMem ()
>>> #3  0x004ced98 in xmlCtxtReadMemory ()
>>> #4  0x0026ea0c in xpath (fcinfo=0x37) at xml.c:3183
>>> #5  0x001095bc in ExecMakeFunctionResultNoSets (fcache=0x10563fc,
>>> econtext=0x10562a8, isNull=0xbfffd4f8 "\004Y?P", isDone=0x0) at
>>> execQual.c:1412
>>
>> [ squint... ]  Hmm, that seems to be in the same general area as some
>> post-beta2 fixes.  Before we spend more time on this, could you update
>> to 8.3beta3 and see if the problem is still there?  b3 is not officially
>> announced yet, but the tarballs are up.
>
> I tried looking for the 8.3b3 tarballs, but can't find them on any
> download host I've tried (starting with ftp.postgresql.org, looking in the
> source directory). Are they available some place else?

I took the latest snapshot from /dev, but I still get the same crash:

Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_INVALID_ADDRESS at address: 0x00a4b000
0xffff8b1c in __memcpy ()
(gdb) bt
#0  0xffff8b1c in __memcpy ()
#1  0x004da098 in xmlBufferAdd ()
#2  0x004e1dc4 in xmlParserInputBufferCreateMem ()
#3  0x004cfd98 in xmlCtxtReadMemory ()
#4  0x0026c32c in xpath (fcinfo=<value temporarily unavailable, due to
optimizations>) at xml.c:3355
#5  0x001095cc in ExecMakeFunctionResultNoSets (fcache=0x10613fc,
econtext=0x10612a8, isNull=0xbfffd4f8 "\004\004?,", isDone=0x0) at
execQual.c:1412
#6  0x00109650 in ExecEvalArrayRef (astate=0x1061364, econtext=0x10612a8,
isNull=0xbfffd4f8 "\004\004?,", isDone=0x0) at execQual.c:254
#7  0x0010d560 in ExecEvalXml (xmlExpr=0x1061324, econtext=0x10612a8,
isNull=0xbfffd5d8 "\001)?\f", isDone=<value temporarily unavailable, due
to optimizations>) at execQual.c:3012
#8  0x0010ae28 in ExecEvalExprSwitchContext (expression=<value temporarily
unavailable, due to optimizations>, econtext=<value temporarily
unavailable, due to optimizations>, isNull=<value temporarily unavailable,
due to optimizations>, isDone=<value temporarily unavailable, due to
optimizations>) at execQual.c:3726
#9  0x00075e00 in FormIndexDatum (indexInfo=0x1054a1c, slot=0x105451c,
estate=0x106121c, values=0xbfffd69c, isnull=0xbfffd67c "") at index.c:1065
#10 0x00076a58 in IndexBuildHeapScan (heapRelation=0x7bc220,
indexRelation=0x7bedcc, indexInfo=0x1054a1c, callback=0x36690
<btbuildCallback>, callback_state=0xbfffda08) at index.c:1734
#11 0x000365fc in btbuild (fcinfo=<value temporarily unavailable, due to
optimizations>) at nbtree.c:119
#12 0x00287168 in OidFunctionCall3 (functionId=<value temporarily
unavailable, due to optimizations>, arg1=8110624, arg2=8121804,
arg3=17123868) at fmgr.c:1580
#13 0x000747a4 in index_build (heapRelation=0x7bc220,
indexRelation=0x7bedcc, indexInfo=0x1054a1c, isprimary=0 '\0') at
index.c:1355
#14 0x00075c20 in index_create (heapRelationId=601643,
indexRelationName=0x1053fa0 "assigned_area_idx", indexRelationId=991232,
indexInfo=0x1054a1c, accessMethodObjectId=403, tableSpaceId=0,
classObjectId=0x10550c4, coloptions=0x10554e4, reloptions=0, isprimary=0
'\0', isconstraint=0 '\0', allow_system_table_mods=0 '\0', skip_build=0
'\0', concurrent=0 '\0') at index.c:841
#15 0x000ce824 in DefineIndex (heapRelation=0x1053fcc,
indexRelationName=0x1053fa0 "assigned_area_idx", indexRelationId=0,
accessMethodName=0x105400c "btree", tableSpaceName=0x273a "",
attributeList=0x1054020, predicate=0x19, options=0x0, src_options=0x0,
unique=0 '\0', primary=0 '\0', isconstraint=0 '\0', is_alter_table=0 '\0',
check_rights=1 '\001', skip_build=0 '\0', quiet=0 '\0', concurrent=0 '\0')
at indexcmds.c:452
#16 0x001c946c in ProcessUtility (parsetree=0x103ac88,
queryString=0x1053e1c "create index assigned_area_idx ON lead
(\nXMLSERIALIZE(CONTENT(xpath('/als:auto-lead-service/als:meta[@key=\"AREA\"][1]/text()',
xml,\nARRAY[ARRAY['als','http://au"..., params=0x0, isTopLevel=1 '\001',
dest=0x103ad04, completionTag=<value temporarily unavailable, due to
optimizations>) at utility.c:919
#17 0x001c5fec in PortalRunUtility (portal=0x1047c1c,
utilityStmt=0x103ac88, isTopLevel=1 '\001', dest=0x103ad04,
completionTag=0xbfffe4ca "") at pquery.c:1173
#18 0x001c6470 in PortalRunMulti (portal=0x1047c1c, isTopLevel=1 '\001',
dest=0x103ad04, altdest=0x103ad04, completionTag=0xbfffe4ca "") at
pquery.c:1266
#19 0x001c6dfc in PortalRun (portal=0x1047c1c, count=2147483647,
isTopLevel=0 '\0', dest=0x103ad04, altdest=0x103ad04,
completionTag=0xbfffe4ca "") at pquery.c:813
#20 0x001c1f04 in exec_simple_query (query_string=0x1039e1c "create index
assigned_area_idx ON lead

(\nXMLSERIALIZE(CONTENT(xpath('/als:auto-lead-service/als:meta[@key=\"com.autoleadservice.service.AssignDealer.AREA\"][1]/text()',
xml,\nARRAY[ARRAY['als','http://au"...) at postgres.c:963
#21 0x001c3cdc in PostgresMain (argc=4, argv=<value temporarily
unavailable, due to optimizations>, username=0x1001454 "lms") at
postgres.c:3531
#22 0x001894e8 in ServerLoop () at postmaster.c:3180
#23 0x0018a9f4 in PostmasterMain (argc=8, argv=0x800420) at postmaster.c:1028
#24 0x0012d4ac in main (argc=8, argv=0x800420) at main.c:188

"Matt Magoffin" <postgresql.org@msqr.us> writes:
> I took the latest snapshot from /dev, but I still get the same crash:

Drat :-(.  Please try a bit harder at generating a self-contained
test case.  Given where the crash is happening, I suspect it may be
only weakly if at all dependent on your input data, so you may not need
to work that hard at generating dummy data.  In any case it's unlikely
to depend much on the content (as opposed to the XML structure) of your
data, so possibly you could sanitize your real data sufficiently by
stripping out everything but the XML tags.

            regards, tom lane

> "Matt Magoffin" <postgresql.org@msqr.us> writes:
>> I took the latest snapshot from /dev, but I still get the same crash:
>
> Drat :-(.  Please try a bit harder at generating a self-contained
> test case.  Given where the crash is happening, I suspect it may be
> only weakly if at all dependent on your input data, so you may not need
> to work that hard at generating dummy data.  In any case it's unlikely
> to depend much on the content (as opposed to the XML structure) of your
> data, so possibly you could sanitize your real data sufficiently by
> stripping out everything but the XML tags.

Hmm. I do have a load testing program with which I _might_ be able to get
to generate a sufficient amount of dummy data. However, it apparently will
require many tens of thousands of rows to reproduce the problem. Will I be
able to post a dump file from this table somewhere? I don't have a public
server I could host it from.

-- m@

"Matt Magoffin" <postgresql.org@msqr.us> writes:
> Hmm. I do have a load testing program with which I _might_ be able to get
> to generate a sufficient amount of dummy data. However, it apparently will
> require many tens of thousands of rows to reproduce the problem. Will I be
> able to post a dump file from this table somewhere? I don't have a public
> server I could host it from.

You could email it to me off-list, as long as it doesn't come to more
than say a few tens of megabytes (don't forget the possibility of
compressing the dump).

            regards, tom lane