FailedAssertion() in 8.2beta1 - Mailing list pgsql-hackers

Hello -hackers,

I've found a bug with 8.2beta1:

1) Log message:

LOG:  duration: 9.144 ms  bind <unnamed>: UPDATE table_list SET description
= $1 WHERE  id = cas_get_table_id ( $2,$3 )
DETAIL:  parameters: $1 = '\tag{image SRC="/vizier/new2.gif"}3rd release of
DENIS (2005Sep)', $2 = 'cas_data_sega', $3 = 'b_denis_denis5'
TRAP: FailedAssertion("!(n < list->length)", File: "list.c", Line: 392)
LOG:  server process (PID 26633) was terminated by signal 6
LOG:  terminating any other active server processes

-----------------------------------------------------
2) gdb bt:


Program received signal SIGABRT, Aborted.
0xb7e62027 in raise () from /lib/tls/libc.so.6
(gdb) bt
#0  0xb7e62027 in raise () from /lib/tls/libc.so.6
#1  0xb7e63747 in abort () from /lib/tls/libc.so.6
#2  0x082bcfd7 in ExceptionalCondition (    conditionName=0x837be2c "!(n < list->length)",    errorType=0x837bb07
"FailedAssertion",fileName=0x837bb00 "list.c",    lineNumber=392) at assert.c:51 
#3  0x081a27de in list_nth_cell (list=0x84d2410, n=5) at list.c:392
#4  0x081a287d in list_nth (list=0x84d2410, n=5) at list.c:413
#5  0x08185324 in ExecOpenScanRelation (estate=0x84f1a34, scanrelid=6)    at execUtils.c:823
#6  0x0818d8a0 in ExecInitIndexScan (node=0x84f0358, estate=0x84f1a34,    eflags=2) at nodeIndexscan.c:508
#7  0x0817b7fb in ExecInitNode (node=0x84f0358, estate=0x84f1a34, eflags=2)    at execProcnode.c:169
#8  0x0818758c in ExecInitAppend (node=0x84f06b0, estate=0x84f1a34,
eflags=2)    at nodeAppend.c:215
#9  0x0817b78b in ExecInitNode (node=0x84f06b0, estate=0x84f1a34, eflags=2)    at execProcnode.c:146
#10 0x0819040d in ExecInitNestLoop (node=0x84f0974, estate=0x84f1a34,
eflags=0)    at nodeNestloop.c:323
#11 0x0817b8bf in ExecInitNode (node=0x84f0974, estate=0x84f1a34, eflags=0)    at execProcnode.c:207
#12 0x08178fa6 in InitPlan (queryDesc=0x84db76c, eflags=0) at execMain.c:628
---Type <return> to continue, or q <return> to quit---
#13 0x081787bd in ExecutorStart (queryDesc=0x84db76c, eflags=0)    at execMain.c:171
#14 0x08229cdf in ProcessQuery (parsetree=0x84d1e74, plan=0x84f0974,    params=0x84c0d4c, dest=0x83bfc10,
completionTag=0xbfedbed0"")    at pquery.c:152 
#15 0x0822b10e in PortalRunMulti (portal=0x849cea4, dest=0x83bfc10,    altdest=0x83bfc10, completionTag=0xbfedbed0 "")
atpquery.c:1145 
#16 0x0822a874 in PortalRun (portal=0x849cea4, count=1, dest=0x847a260,    altdest=0x847a260, completionTag=0xbfedbed0
"")at pquery.c:700 
#17 0x08226f1d in exec_execute_message (portal_name=0x847a154 "",
max_rows=1)    at postgres.c:1775
#18 0x08229316 in PostgresMain (argc=4, argv=0x8426114,    username=0x8426020 "sega") at postgres.c:3452
#19 0x081f7608 in BackendRun (port=0x8439268) at postmaster.c:2848
#20 0x081f6c34 in BackendStartup (port=0x8439268) at postmaster.c:2485
#21 0x081f4cab in ServerLoop () at postmaster.c:1198
#22 0x081f46c2 in PostmasterMain (argc=1, argv=0x840cff0) at
#postmaster.c:950
#23 0x081a1a7c in main (argc=1, argv=0x840cff0) at main.c:187
-------------------------------------------------------
3) gdb bt full

(gdb) bt full
#0  0xb7e62027 in raise () from /lib/tls/libc.so.6
No symbol table info available.
#1  0xb7e63747 in abort () from /lib/tls/libc.so.6
No symbol table info available.
#2  0x082bcfd7 in ExceptionalCondition (    conditionName=0x837be2c "!(n < list->length)",    errorType=0x837bb07
"FailedAssertion",fileName=0x837bb00 "list.c",    lineNumber=392) at assert.c:51 
No locals.
#3  0x081a27de in list_nth_cell (list=0x84d2410, n=5) at list.c:392        match = (ListCell *) 0x84f3e2c
#4  0x081a287d in list_nth (list=0x84d2410, n=5) at list.c:413
No locals.
#5  0x08185324 in ExecOpenScanRelation (estate=0x84f1a34, scanrelid=6)    at execUtils.c:823        rtentry =
(RangeTblEntry*) 0x84f3e2c        reloid = 139411100        lockmode = 1        resultRelInfos = (ResultRelInfo *)
0x84f1ac0       i = 1 
#6  0x0818d8a0 in ExecInitIndexScan (node=0x84f0358, estate=0x84f1a34,    eflags=2) at nodeIndexscan.c:508
indexstate= (IndexScanState *) 0x84f3e2c 
---Type <return> to continue, or q <return> to quit---        currentRelation = 0x2        relistarget = 0 '\0'
#7  0x0817b7fb in ExecInitNode (node=0x84f0358, estate=0x84f1a34, eflags=2)    at execProcnode.c:169        result =
(PlanState*) 0x84f1a34        subps = (List *) 0x0        l = (ListCell *) 0x1 
#8  0x0818758c in ExecInitAppend (node=0x84f06b0, estate=0x84f1a34, eflags=2)    at nodeAppend.c:215        appendstate
=(AppendState *) 0x84f3d8c        appendplanstates = (PlanState **) 0x84f3e18        nplans = 2        i = 0
initNode= (Plan *) 0x84f0358 
#9  0x0817b78b in ExecInitNode (node=0x84f06b0, estate=0x84f1a34, eflags=2)    at execProcnode.c:146        result =
(PlanState*) 0x84f2a44        subps = (List *) 0x0        l = (ListCell *) 0x0 
#10 0x0819040d in ExecInitNestLoop (node=0x84f0974, estate=0x84f1a34, eflags=0)    at nodeNestloop.c:323        nlstate
=(NestLoopState *) 0x84f279c 
#11 0x0817b8bf in ExecInitNode (node=0x84f0974, estate=0x84f1a34, eflags=0)
---Type <return> to continue, or q <return> to quit---    at execProcnode.c:207        result = (PlanState *) 0xb
subps = (List *) 0x84f2618        l = (ListCell *) 0xbfedbc98 
#12 0x08178fa6 in InitPlan (queryDesc=0x84db76c, eflags=0) at execMain.c:628        operation = CMD_UPDATE
parseTree= (Query *) 0x84d1e74        plan = (Plan *) 0x84f0974        estate = (EState *) 0x84f1a34        planstate =
(PlanState*) 0x8445180        rangeTable = (List *) 0x84d2410        tupType = 0xbfedbca8        l = (ListCell *) 0x0 
#13 0x081787bd in ExecutorStart (queryDesc=0x84db76c, eflags=0)    at execMain.c:171        estate = (EState *)
0x84f1a34       oldcontext = 0x8445180 
#14 0x08229cdf in ProcessQuery (parsetree=0x84d1e74, plan=0x84f0974,    params=0x84c0d4c, dest=0x83bfc10,
completionTag=0xbfedbed0"")    at pquery.c:152        operation = 2        queryDesc = (QueryDesc *) 0x84db76c 
#15 0x0822b10e in PortalRunMulti (portal=0x849cea4, dest=0x83bfc10,
---Type <return> to continue, or q <return> to quit---    altdest=0x83bfc10, completionTag=0xbfedbed0 "") at
pquery.c:1145       query = (Query *) 0x84d1e74        plan = (Plan *) 0x84f0974        querylist_item = (ListCell *)
0x84b6124       planlist_item = (ListCell *) 0x84f0d5c 
#16 0x0822a874 in PortalRun (portal=0x849cea4, count=1, dest=0x847a260,    altdest=0x847a260, completionTag=0xbfedbed0
"")at pquery.c:700        save_exception_stack = (sigjmp_buf *) 0xbfedbf90        save_context_stack =
(ErrorContextCallback*) 0x0        local_sigjmp_buf = {{__jmpbuf = {138646120, 138177888, 1, -1074938296,
-1074938560,136488740}, __mask_was_saved = 0, __saved_mask = {__val = {        138907248, 138905072, 14, 0, 14, 64,
138903960,3220028872, 137127149,        138903884, 3, 3220028920, 137199637, 0, 1, 3220028904, 3220028928,
138177888,1, 3220029016, 138912352, 138903884, 3220028928, 7908, 0,        64, 3, 0, 138912340, 138912056, 138687444,
3220028952}}}}       result = 8 '\b'        saveTopTransactionResourceOwner = 0x8444b9c
saveTopTransactionContext= 0x8443460        saveActivePortal = 0x0        saveActiveSnapshot = 0x84cbb78
saveResourceOwner= 0x8444b9c        savePortalContext = 0x0        saveQueryContext = 0x0 
---Type <return> to continue, or q <return> to quit---        saveMemoryContext = 0x84433d4
#17 0x08226f1d in exec_execute_message (portal_name=0x847a154 "", max_rows=1)    at postgres.c:1775        dest =
DestRemoteExecute       receiver = (DestReceiver *) 0x847a260        portal = 0x849cea4        completed = 8 '\b'
completionTag =
"\000m<\b\001\000\000\000Ь╬М©Ф\023\032\b\034©М©U║G\b\004\000\000\000UP\"\bт3D\b\000\001\000\000(©М©Ё\021\032\b\000\000\000\001\034©М©\004\000\000\000\224\025\032\b"
      sourceText = 0x84b7a40 "UPDATE table_list SET description = $1 WHERE  id = cas_get_table_id ( $2,$3 )"
prepStmtName= 0x8390509 "<unnamed>"        portalParams = 0x84c0d4c        save_log_statement_stats = 0 '\0'
is_xact_command= 0 '\0'        execute_is_fetch = 0 '\0'        was_logged = 0 '\0'        msec_str =
"\000\000\000\000Ю╬М©\004\000\000\000T╒G\b\000\001\000\000\000\000\000\000\220©М©\005\000\000"
#18 0x08229316 in PostgresMain (argc=4, argv=0x8426114,    username=0x8426020 "sega") at postgres.c:3452
portal_name= 0x847a154 "" 
---Type <return> to continue, or q <return> to quit---        max_rows = 1        flag = -1        dbname = 0x840e4c0
"cas"       userDoption = 0x0        secure = 0 '\0'        errs = 0        debug_flag = -1        guc_names = (List *)
0x0       guc_values = (List *) 0x0        ctx = PGC_USERSET        gucsource = PGC_S_CLIENT        am_superuser = 0
'\0'       firstchar = 69        stack_base = 8 '\b'        input_message = {data = 0x847a154 "", len = 5, maxlen =
256, cursor = 5}        local_sigjmp_buf = {{__jmpbuf = {138646120, 138177888, 1, -1074937704,      -1074938064,
136482612},__mask_was_saved = 1, __saved_mask = {__val = {        1073347075, 4294967294, 0 <repeats 14 times>,
4294967295,0, 0,        3085552756, 0, 0, 0, 138663032, 3086246240, 200, 138586480, 138578288,        3086301216,
138177888,1, 3220029528}}}}        send_ready_for_query = 0 '\0' 
#19 0x081f7608 in BackendRun (port=0x8439268) at postmaster.c:2848
---Type <return> to continue, or q <return> to quit---        av = (char **) 0x8426114        maxac = 10        ac = 4
     secs = 213543661        usecs = 873423        protobuf = "-v196608\000
У╥АШ\031\b\004\000\000\000\000\000\000\000юД@\b8У╥"        i = 4 
#20 0x081f6c34 in BackendStartup (port=0x8439268) at postmaster.c:2485        bn = (Backend *) 0x840e4c0        pid = 0
#21 0x081f4cab in ServerLoop () at postmaster.c:1198        timeout = {tv_sec = 59, tv_usec = 940000}        selres = 1
      i = 0        port = (Port *) 0x8439268        rmask = {fds_bits = {8, 0 <repeats 31 times>}}        readmask =
{fds_bits= {24, 0 <repeats 31 times>}}        nSockets = 5        now = 1160228461        last_touch_time = 1160227556
     earlier = {tv_sec = 1160227556, tv_usec = 769522}        later = {tv_sec = 1160227563, tv_usec = 174421} 
---Type <return> to continue, or q <return> to quit---
#22 0x081f46c2 in PostmasterMain (argc=1, argv=0x840cff0) at postmaster.c:950        opt = -1        status = 0
userDoption= 0x0        i = 64 
#23 0x081a1a7c in main (argc=1, argv=0x840cff0) at main.c:187
No locals.
(gdb)
---------------------------------------
4) The table_list which is being updated during the failure is

cas=# \d cas_metadata_sega.table_list     View "cas_metadata_sega.table_list"   Column    |       Type        |
Modifiers 
-------------+-------------------+----------- id          | integer           | catalog_id  | bigint            | name
     | character varying | info        | character varying | description | character varying |  
View definition: SELECT table_user_list.id, table_user_list.catalog_id, table_user_list.name, table_user_list.info,
table_user_list.description  FROM cas_metadata_sega.table_user_list 
UNION ALL SELECT table_list.id, table_list.catalog_id, table_list.name, table_list.info, table_list.description   FROM
cas_metadata.table_list;
Rules: rule_delete_table AS    ON DELETE TO cas_metadata_sega.table_list DO INSTEAD  DELETE FROM
cas_metadata_sega.table_user_listrule_insert_table AS    ON INSERT TO cas_metadata_sega.table_list DO INSTEAD  INSERT
INTOcas_metadata_sega.table_user_list (catalog_id, name, info, description)  SELECT new.catalog_id, new.name, new.info,
new.descriptionrule_update_table AS    ON UPDATE TO cas_metadata_sega.table_list DO INSTEAD  UPDATE
cas_metadata_sega.table_user_listSET catalog_id = new.catalog_id, name = new.name, info = new.info, description =
new.description WHERE table_user_list.id = new.id 
-------------------------------------------
5) The table_user_list which is actually being updated:

cas=# \d cas_metadata_sega.table_user_list                               Table "cas_metadata_sega.table_user_list"
Column   |       Type        |                              Modifiers  
-------------+-------------------+---------------------------------------------------------------------- id          |
integer          | not null default nextval('cas_metadata.table_list_id_seq'::regclass) catalog_id  | bigint
|name        | character varying | not null info        | character varying | description | character varying |  
Indexes:    "table_user_list_pkey" PRIMARY KEY, btree (id)    "table_user_list_catalog_id_key" UNIQUE, btree
(catalog_id,name) 
Foreign-key constraints:    "table_user_list_catalog_id_fkey" FOREIGN KEY (catalog_id) REFERENCES
cas_metadata_sega.catalog_user_list(id)ON UPDATE CASCADE ON DELETE CASCADE 
----------------------------------------------

6)The function used in the query:

cas=# \df+ cas_metadata.cas_get_table_id
                          List of functions    Schema    |       Name       | Result data type |
Argumentdata types                   |   Owner   | Language |                                    Source code
                       | Description  

--------------+------------------+------------------+---------------------------------------------------------+-----------+----------+-----------------------------------------------------------------------------------+-------------
cas_metadata| cas_get_table_id | integer          | catalog character varying, table_name character varying | cas_admin
|sql      | SELECT id FROM table_list WHERE name = $2 AND catalog_id = cas_get_catalog_id($1) |  
(1 row)
---------------------------------
7) The query was executed from JDBC in large transaction

8) PG have been compiled with following flags:
CONFIGURE = '--enable-cassert' '--with-perl' '--with-python' '--prefix=/opt/pgsql8.2' 'CFLAGS=-g'

9) the only change in the posgresql.conf was
log_min_duration_statement  -1 -->  0


Regards,    Sergey

*******************************************************************
Sergey E. Koposov
Max Planck Institute for Astronomy/Sternberg Astronomical Institute
Tel: +49-6221-528-349
Web: http://lnfm1.sai.msu.ru/~math
E-mail: math@sai.msu.ru