Re: BUG #5798: Some weird error with pl/pgsql procedure

Just an idea from code examination:

I think problem in
" RETURNING ctid"
part of query
and next comment in slot_getattr:
/*
* system attributes are handled by heap_getsysattr
*/

So, may be RETURNING implementation somehow incorrectely handle system
attributes in returing values list.

On Sun, Feb 20, 2011 at 1:13 AM, Maxim Boguk <maxim(dot)boguk(at)gmail(dot)com> wrote:

> Hi all and Hi Robert
>
> I finally managed create working slave server with non-stripped Postgresql
> 8.4.7 and working gdb.
> (sorry for such long delay).
> And i can reproduce situation quite easy now, so i managed get stack
> backtrace with that error.
> What i need to do now? I have some expirience with gbd now but i have no
> idea where to look next.
>
> Full backtrace:
>
> Breakpoint 1, slot_getattr (slot=0xdd09ea468, attnum=-1, isnull=0xdd09b4a68
> "") at heaptuple.c:1185
> 1185 elog(ERROR, "cannot extract system
> attribute from virtual tuple");
> (gdb) bt
> #0 slot_getattr (slot=0xdd09ea468, attnum=-1, isnull=0xdd09b4a68 "") at
> heaptuple.c:1185
> #1 0x000000000058a5f8 in ExecEvalScalarVar (exprstate=0xdd09b4b60,
> econtext=0xdd09b4a80, isNull=0xdd09b4a68 "", isDone=0xdd09b4ce0)
> at execQual.c:787
> #2 0x00000000005933d7 in ExecTargetList (targetlist=0xdd09b4cb0,
> econtext=0xdd09b4a80, values=0xdd09b4a50, isnull=0xdd09b4a68 "",
> itemIsDone=0xdd09b4ce0, isDone=0x0) at execQual.c:5118
> #3 0x00000000005939a3 in ExecProject (projInfo=0xdd09b4be0, isDone=0x0) at
> execQual.c:5333
> #4 0x00000000005879c7 in ExecProcessReturning
> (projectReturning=0xdd09b4be0, tupleSlot=0xdd09ea468, planSlot=0xdd09ea3a8,
> dest=0xdd09de5c8) at execMain.c:2273
> #5 0x00000000005875fe in ExecUpdate (slot=0xdd09ea468,
> tupleid=0x7fffffffd2e0, planSlot=0xdd09ea3a8, dest=0xdd09de5c8,
> estate=0xdd09e6030) at execMain.c:2142
> #6 0x0000000000586c68 in ExecutePlan (estate=0xdd09e6030,
> planstate=0xdd09ea550, operation=CMD_UPDATE, numberTuples=0,
> direction=ForwardScanDirection, dest=0xdd09de5c8) at execMain.c:1681
> #7 0x00000000005849a5 in standard_ExecutorRun (queryDesc=0xdd09de658,
> direction=ForwardScanDirection, count=0) at execMain.c:309
> #8 0x00000000005848a5 in ExecutorRun (queryDesc=0xdd09de658,
> direction=ForwardScanDirection, count=0) at execMain.c:258
> #9 0x0000000000673d43 in ProcessQuery (plan=0xdd0998890,
> sourceText=0xdd09c5830 "UPDATE ONLY bill.ctrl_servers SET opt = opt
> WHERE ctid=ANY($1) RETURNING ctid", params=0xdd09c58c0,
> dest=0xdd09de5c8, completionTag=0x7fffffffd4e0 "") at pquery.c:196
> #10 0x00000000006754e5 in PortalRunMulti (portal=0xdd08c8140, isTopLevel=0
> '\000', dest=0xdd09de5c8, altdest=0x9dfdc0,
> completionTag=0x7fffffffd4e0 "") at pquery.c:1269
> #11 0x0000000000675127 in FillPortalStore (portal=0xdd08c8140, isTopLevel=0
> '\000') at pquery.c:1061
> #12 0x00000000006757f8 in PortalRunFetch (portal=0xdd08c8140,
> fdirection=FETCH_FORWARD, count=10, dest=0x9dfe40) at pquery.c:1397
> #13 0x00000000005b24e1 in _SPI_cursor_operation (portal=0xdd08c8140,
> direction=FETCH_FORWARD, count=10, dest=0x9dfe40) at spi.c:2088
> #14 0x00000000005b11a8 in SPI_cursor_fetch (portal=0xdd08c8140, forward=1
> '\001', count=10) at spi.c:1258
> #15 0x0000000dd0b1e199 in exec_for_query (estate=0x7fffffffda50,
> stmt=0xdd098bfc8, portal=0xdd08c8140, prefetch_ok=1 '\001')
> at pl_exec.c:4262
> #16 0x0000000dd0b1bc43 in exec_stmt_dynfors (estate=0x7fffffffda50,
> stmt=0xdd098bfc8) at pl_exec.c:3107
> #17 0x0000000dd0b1881a in exec_stmt (estate=0x7fffffffda50,
> stmt=0xdd098bfc8) at pl_exec.c:1308
> #18 0x0000000dd0b1859a in exec_stmts (estate=0x7fffffffda50,
> stmts=0xdd098bc28) at pl_exec.c:1203
> #19 0x0000000dd0b18f38 in exec_stmt_while (estate=0x7fffffffda50,
> stmt=0xdd098d6f8) at pl_exec.c:1608
> #20 0x0000000dd0b18733 in exec_stmt (estate=0x7fffffffda50,
> stmt=0xdd098d6f8) at pl_exec.c:1264
> #21 0x0000000dd0b1859a in exec_stmts (estate=0x7fffffffda50,
> stmts=0xdd098a650) at pl_exec.c:1203
> #22 0x0000000dd0b183df in exec_stmt_block (estate=0x7fffffffda50,
> block=0xdd098d778) at pl_exec.c:1140
> #23 0x0000000dd0b16a29 in plpgsql_exec_function (func=0xdd087abd8,
> fcinfo=0x7fffffffdcf0) at pl_exec.c:315
> #24 0x0000000dd0b1260f in plpgsql_call_handler (fcinfo=0x7fffffffdcf0) at
> pl_handler.c:95
> ---Type <return> to continue, or q <return> to quit---
> #25 0x000000000058c902 in ExecMakeTableFunctionResult
> (funcexpr=0xdd08ca730, econtext=0xdd08ca460, expectedDesc=0xdd08ca5f0,
> randomAccess=0 '\000') at execQual.c:2016
> #26 0x00000000005a3e7d in FunctionNext (node=0xdd08ca350) at
> nodeFunctionscan.c:64
> #27 0x0000000000593a10 in ExecScan (node=0xdd08ca350, accessMtd=0x5a3e10
> <FunctionNext>) at execScan.c:68
> #28 0x00000000005a3eea in ExecFunctionScan (node=0xdd08ca350) at
> nodeFunctionscan.c:98
> #29 0x0000000000588fdf in ExecProcNode (node=0xdd08ca350) at
> execProcnode.c:385
> #30 0x0000000000586794 in ExecutePlan (estate=0xdd08ca030,
> planstate=0xdd08ca350, operation=CMD_SELECT, numberTuples=0,
> direction=ForwardScanDirection, dest=0xdd08996f0) at execMain.c:1504
> #31 0x00000000005849a5 in standard_ExecutorRun (queryDesc=0xdd082f430,
> direction=ForwardScanDirection, count=0) at execMain.c:309
> #32 0x00000000005848a5 in ExecutorRun (queryDesc=0xdd082f430,
> direction=ForwardScanDirection, count=0) at execMain.c:258
> #33 0x0000000000674e18 in PortalRunSelect (portal=0xdd08c8030, forward=1
> '\001', count=0, dest=0xdd08996f0) at pquery.c:953
> #34 0x0000000000674ab9 in PortalRun (portal=0xdd08c8030,
> count=9223372036854775807, isTopLevel=1 '\001', dest=0xdd08996f0,
> altdest=0xdd08996f0, completionTag=0x7fffffffe570 "") at pquery.c:779
> #35 0x000000000066f0e6 in exec_simple_query (
> query_string=0x8037e5030 "\nSELECT * from
> __clear_table_tail('ctrl_servers', 'bill', 'opt', 13, 1)\n") at
> postgres.c:997
> #36 0x0000000000672f72 in PostgresMain (argc=4, argv=0x803732930,
> username=0x803732900 "pgsql") at postgres.c:3676
> #37 0x000000000063b5cd in BackendRun (port=0x803703c00) at
> postmaster.c:3467
> #38 0x000000000063ab2a in BackendStartup (port=0x803703c00) at
> postmaster.c:3081
> #39 0x00000000006382dc in ServerLoop () at postmaster.c:1387
> #40 0x0000000000637abb in PostmasterMain (argc=3, argv=0x7fffffffeb88) at
> postmaster.c:1040
> #41 0x00000000005c0b5a in main (argc=3, argv=0x7fffffffeb88) at main.c:188
>
>
>
> On Wed, Jan 5, 2011 at 4:28 PM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
>
>> On Wed, Dec 22, 2010 at 4:53 PM, Maxim Boguk <maxim(dot)boguk(at)gmail(dot)com>
>> wrote:
>> > About stack backtrace I not sure how to get it (and even worse the
>> > database is heavily loaded production DB so I not sure creating core
>> > dump would be good idea).
>> > Still I would like to receive any help with creating a stack backtrace.
>>
>> Well, if you can reproduce this problem in a given session, you can
>> use pg_backend_pid() at the start of the session to get the backend
>> ID, and then if your build has debugging symbols (or separate
>> debuginfos you can install), you could attach gdb to it, set a
>> breakpoint at the lines in heaptuple.c that can throw this error,
>> reproduce the problem, and then get a backtrace. But if it's
>> happening randomly I don't have a lot of ideas.
>>
>> I do wonder if this could be related to using TIDs that don't actually
>> exist in the table. That might be worth some experimentation.
>>
>> --
>> Robert Haas
>> EnterpriseDB: http://www.enterprisedb.com
>> The Enterprise PostgreSQL Company
>>
>
>
>
> --
> Maxim Boguk
> Senior Postgresql DBA.
>
> Skype: maxim.boguk
> Jabber: maxim(dot)boguk(at)gmail(dot)com
>
> LinkedIn profile: http://nz.linkedin.com/in/maximboguk
> If they can send one man to the moon... why can't they send them all?
>
>
> МойКруг: http://mboguk.moikrug.ru/
> Сила солому ломит, но не все в нашей жизни - солома, да и сила далеко не
> все.
>

--
Maxim Boguk
Senior Postgresql DBA.

Skype: maxim.boguk
Jabber: maxim(dot)boguk(at)gmail(dot)com

LinkedIn profile: http://nz.linkedin.com/in/maximboguk
If they can send one man to the moon... why can't they send them all?

МойКруг: http://mboguk.moikrug.ru/
Сила солому ломит, но не все в нашей жизни - солома, да и сила далеко не
все.