FailedAssertion() in 8.2beta1

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 "") at pquery.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юД(at)\b 8У╥"
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_list
rule_insert_table AS
ON INSERT TO cas_metadata_sega.table_list DO INSTEAD INSERT INTO cas_metadata_sega.table_user_list (catalog_id, name, info, description) SELECT new.catalog_id, new.name, new.info, new.description
rule_update_table AS
ON UPDATE TO cas_metadata_sega.table_list DO INSTEAD UPDATE cas_metadata_sega.table_user_list SET 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 | Argument data 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(at)sai(dot)msu(dot)ru