Re: Bug #514: Backend crashes periodically

From: Warren Volz <wrv(at)po(dot)cwru(dot)edu>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: Bug #514: Backend crashes periodically
Date: 2001-11-12 04:20:20
Message-ID: p05100307b814fd582686@[129.22.34.247]
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Tom,

Yeah, there is a trigger. Here are the relevant bits of the schema,
followed by the output of EXPLAIN VERBOSE on a similar query.

Thanks,
Warren

--
-- Table structure for table 'session'
--
CREATE TABLE session (
session_key CHAR(40) PRIMARY KEY,
sis_user_id INTEGER NOT NULL REFERENCES sis_user
(sis_user_id),
last_access_time DATETIME NOT NULL DEFAULT TEXT 'now'
);

-- A rule for keeping the last_visit updated.
CREATE RULE session_del AS ON DELETE TO session DO
UPDATE sis_user
SET last_visit = OLD.last_access_time
WHERE OLD.sis_user_id = sis_user.sis_user_id;

CREATE TABLE sis_user (
sis_user_id INTEGER PRIMARY KEY REFERENCES member
(member_id),
last_name CHAR(30),
cwrunet_id CHAR(10) UNIQUE,
email_address CHAR(80) NOT NULL UNIQUE,
description VARCHAR(128),
field_of_study VARCHAR(80),
favorite_quote VARCHAR(128),
last_visit DATETIME NOT NULL DEFAULT TEXT 'now',
second_to_last_visit DATETIME NOT NULL DEFAULT TEXT 'now',
email_bounced SMALLINT NOT NULL DEFAULT 0,
on_vacation_until DATETIME,
password CHAR(13),
privacy INTEGER NOT NULL,
last_ip_address CHAR(15) DEFAULT '0.0.0.0',
checked_mail BOOLEAN NOT NULL DEFAULT FALSE,
num_messages INTEGER DEFAULT 0
);

sis=> explain verbose delete from session where
session_key='ys!aoUC3kAF2UJ46vz6pSIz1UpsfuLps71YwaT+P';
NOTICE: QUERY DUMP:

{ NESTLOOP :startup_cost 0.00 :total_cost 35.23 :rows 35 :width 145
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
:restypmod -1 :resname sis_user_id :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 1 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 1}} { TARGETENTRY :resdom { RESDOM :resno 2 :restype 1042
:restypmod 34 :resname last_name :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 2 :vartype 1042 :vartypmod 34 :varlevelsup 0 :varnoold 4
:varoattno 2}} { TARGETENTRY :resdom { RESDOM :resno 3 :restype 1042
:restypmod 14 :resname cwrunet_id :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 3 :vartype 1042 :vartypmod 14 :varlevelsup 0 :varnoold 4
:varoattno 3}} { TARGETENTRY :resdom { RESDOM :resno 4 :restype 1042
:restypmod 84 :resname email_address :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 4 :vartype 1042 :vartypmod 84 :varlevelsup 0 :varnoold 4
:varoattno 4}} { TARGETENTRY :resdom { RESDOM :resno 5 :restype 1043
:restypmod 132 :resname description :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 5 :vartype 1043 :vartypmod 132 :varlevelsup 0 :varnoold 4
:varoattno 5}} { TARGETENTRY :resdom { RESDOM :resno 6 :restype 1043
:restypmod 84 :resname field_of_study :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 6 :vartype 1043 :vartypmod 84 :varlevelsup 0 :varnoold 4
:varoattno 6}} { TARGETENTRY :resdom { RESDOM :resno 7 :restype 1043
:restypmod 132 :resname favorite_quote :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 7 :vartype 1043 :vartypmod 132 :varlevelsup 0 :varnoold 4
:varoattno 7}} { TARGETENTRY :resdom { RESDOM :resno 8 :restype 1184
:restypmod -1 :resname last_visit :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65001
:varattno 1 :vartype 1184 :vartypmod -1 :varlevelsup 0 :varnoold 1
:varoattno 3}} { TARGETENTRY :resdom { RESDOM :resno 9 :restype 1184
:restypmod -1 :resname second_to_last_visit :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 8 :vartype 1184 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 9}} { TARGETENTRY :resdom { RESDOM :resno 10 :restype 21
:restypmod -1 :resname email_bounced :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 9 :vartype 21 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 10}} { TARGETENTRY :resdom { RESDOM :resno 11 :restype
1184 :restypmod -1 :resname on_vacation_until :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 10 :vartype 1184 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 11}} { TARGETENTRY :resdom { RESDOM :resno 12 :restype
1042 :restypmod 17 :resname password :reskey 0 :reskeyop 0
:ressortgroupref 0 :resjunk false } :expr { VAR :varno 65000
:varattno 11 :vartype 1042 :vartypmod 17 :varlevelsup 0 :varnoold 4
:varoattno 12}} { TARGETENTRY :resdom { RESDOM :resno 13 :restype 23
:restypmod -1 :resname privacy :reskey 0 :reskeyop 0 :ressortgroupref
0 :resjunk false } :expr { VAR :varno 65000 :varattno 12 :vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 4 :varoattno 13}} {
TARGETENTRY :resdom { RESDOM :resno 14 :restype 1042 :restypmod 19
:resname last_ip_address :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 65000 :varattno 13 :vartype 1042
:vartypmod 19 :varlevelsup 0 :varnoold 4 :varoattno 14}} {
TARGETENTRY :resdom { RESDOM :resno 15 :restype 16 :restypmod -1
:resname checked_mail :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 65000 :varattno 14 :vartype 16
:vartypmod -1 :varlevelsup 0 :varnoold 4 :varoattno 15}} {
TARGETENTRY :resdom { RESDOM :resno 16 :restype 23 :restypmod -1
:resname num_messages :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 65000 :varattno 15 :vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 4 :varoattno 16}} {
TARGETENTRY :resdom { RESDOM :resno 17 :restype 27 :restypmod -1
:resname ctid :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk true
} :expr { VAR :varno 65000 :varattno 16 :vartype 27 :vartypmod -1
:varlevelsup 0 :varnoold 4 :varoattno -1}}) :qpqual <> :lefttree {
SEQSCAN :startup_cost 0.00 :total_cost 1.43 :rows 1 :width 12
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 1184
:restypmod -1 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 1 :varattno 3 :vartype 1184
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 3}} {
TARGETENTRY :resdom { RESDOM :resno 2 :restype 23 :restypmod -1
:resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
:expr { VAR :varno 1 :varattno 2 :vartype 23 :vartypmod -1
:varlevelsup 0 :varnoold 1 :varoattno 2}}) :qpqual ({ EXPR :typeOid
16 :opType op :oper { OPER :opno 1054 :opid 1048 :opresulttype 16 }
:args ({ VAR :varno 1 :varattno 1 :vartype 1042 :vartypmod 44
:varlevelsup 0 :varnoold 1 :varoattno 1} { CONST :consttype 1042
:constlen -1 :constbyval false :constisnull false :constvalue 44 [
44 0 0 0 121 115 33 97 111 85 67 51 107 65 70 50 85 74 52 54 118 122
54 112 83 73 122 49 85 112 115 102 117 76 112 115 55 49 89 119 97 84
43 80 ] })}) :lefttree <> :righttree <> :extprm () :locprm ()
:initplan <> :nprm 0 :scanrelid 1 } :righttree { INDEXSCAN
:startup_cost 0.00 :total_cost 33.36 :rows 35 :width 133
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 23
:restypmod -1 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 4 :varattno 1 :vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 4 :varoattno 1}} {
TARGETENTRY :resdom { RESDOM :resno 2 :restype 1042 :restypmod 34
:resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
:expr { VAR :varno 4 :varattno 2 :vartype 1042 :vartypmod 34
:varlevelsup 0 :varnoold 4 :varoattno 2}} { TARGETENTRY :resdom {
RESDOM :resno 3 :restype 1042 :restypmod 14 :resname <> :reskey 0
:reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 4
:varattno 3 :vartype 1042 :vartypmod 14 :varlevelsup 0 :varnoold 4
:varoattno 3}} { TARGETENTRY :resdom { RESDOM :resno 4 :restype 1042
:restypmod 84 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 4 :varattno 4 :vartype 1042
:vartypmod 84 :varlevelsup 0 :varnoold 4 :varoattno 4}} {
TARGETENTRY :resdom { RESDOM :resno 5 :restype 1043 :restypmod 132
:resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
:expr { VAR :varno 4 :varattno 5 :vartype 1043 :vartypmod 132
:varlevelsup 0 :varnoold 4 :varoattno 5}} { TARGETENTRY :resdom {
RESDOM :resno 6 :restype 1043 :restypmod 84 :resname <> :reskey 0
:reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 4
:varattno 6 :vartype 1043 :vartypmod 84 :varlevelsup 0 :varnoold 4
:varoattno 6}} { TARGETENTRY :resdom { RESDOM :resno 7 :restype 1043
:restypmod 132 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 4 :varattno 7 :vartype 1043
:vartypmod 132 :varlevelsup 0 :varnoold 4 :varoattno 7}} {
TARGETENTRY :resdom { RESDOM :resno 8 :restype 1184 :restypmod -1
:resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
:expr { VAR :varno 4 :varattno 9 :vartype 1184 :vartypmod -1
:varlevelsup 0 :varnoold 4 :varoattno 9}} { TARGETENTRY :resdom {
RESDOM :resno 9 :restype 21 :restypmod -1 :resname <> :reskey 0
:reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 4
:varattno 10 :vartype 21 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 10}} { TARGETENTRY :resdom { RESDOM :resno 10 :restype
1184 :restypmod -1 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref
0 :resjunk false } :expr { VAR :varno 4 :varattno 11 :vartype 1184
:vartypmod -1 :varlevelsup 0 :varnoold 4 :varoattno 11}} {
TARGETENTRY :resdom { RESDOM :resno 11 :restype 1042 :restypmod 17
:resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
:expr { VAR :varno 4 :varattno 12 :vartype 1042 :vartypmod 17
:varlevelsup 0 :varnoold 4 :varoattno 12}} { TARGETENTRY :resdom {
RESDOM :resno 12 :restype 23 :restypmod -1 :resname <> :reskey 0
:reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 4
:varattno 13 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 13}} { TARGETENTRY :resdom { RESDOM :resno 13 :restype
1042 :restypmod 19 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref
0 :resjunk false } :expr { VAR :varno 4 :varattno 14 :vartype 1042
:vartypmod 19 :varlevelsup 0 :varnoold 4 :varoattno 14}} {
TARGETENTRY :resdom { RESDOM :resno 14 :restype 16 :restypmod -1
:resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
:expr { VAR :varno 4 :varattno 15 :vartype 16 :vartypmod -1
:varlevelsup 0 :varnoold 4 :varoattno 15}} { TARGETENTRY :resdom {
RESDOM :resno 15 :restype 23 :restypmod -1 :resname <> :reskey 0
:reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 4
:varattno 16 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 4
:varoattno 16}} { TARGETENTRY :resdom { RESDOM :resno 16 :restype 27
:restypmod -1 :resname <> :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk false } :expr { VAR :varno 4 :varattno -1 :vartype 27
:vartypmod -1 :varlevelsup 0 :varnoold 4 :varoattno -1}}) :qpqual <>
:lefttree <> :righttree <> :extprm () :locprm () :initplan <> :nprm 0
:scanrelid 4 :indxid ( 183804) :indxqual (({ EXPR :typeOid 16
:opType op :oper { OPER :opno 96 :opid 65 :opresulttype 16 } :args ({
VAR :varno 4 :varattno 1 :vartype 23 :vartypmod -1 :varlevelsup 0
:varnoold 4 :varoattno 1} { VAR :varno 65001 :varattno 2 :vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 2})}))
:indxqualorig (({ EXPR :typeOid 16 :opType op :oper { OPER :opno 96
:opid 65 :opresulttype 16 } :args ({ VAR :varno 65001 :varattno 2
:vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 2} {
VAR :varno 4 :varattno 1 :vartype 23 :vartypmod -1 :varlevelsup 0
:varnoold 4 :varoattno 1})})) :indxorderdir 0 } :extprm () :locprm ()
:initplan <> :nprm 0 :jointype 0 :joinqual <>}
NOTICE: QUERY PLAN:

Nested Loop (cost=0.00..35.23 rows=35 width=145)
-> Seq Scan on session (cost=0.00..1.43 rows=1 width=12)
-> Index Scan using sis_user_pkey on sis_user (cost=0.00..33.36
rows=35 width=133)

NOTICE: QUERY DUMP:

{ SEQSCAN :startup_cost 0.00 :total_cost 1.43 :rows 1 :width 6
:qptargetlist ({ TARGETENTRY :resdom { RESDOM :resno 1 :restype 27
:restypmod -1 :resname ctid :reskey 0 :reskeyop 0 :ressortgroupref 0
:resjunk true } :expr { VAR :varno 1 :varattno -1 :vartype 27
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno -1}}) :qpqual ({
EXPR :typeOid 16 :opType op :oper { OPER :opno 1054 :opid 1048
:opresulttype 16 } :args ({ VAR :varno 1 :varattno 1 :vartype 1042
:vartypmod 44 :varlevelsup 0 :varnoold 1 :varoattno 1} { CONST
:consttype 1042 :constlen -1 :constbyval false :constisnull false
:constvalue 44 [ 44 0 0 0 121 115 33 97 111 85 67 51 107 65 70 50 85
74 52 54 118 122 54 112 83 73 122 49 85 112 115 102 117 76 112 115 55
49 89 119 97 84 43 80 ] })}) :lefttree <> :righttree <> :extprm ()
:locprm () :initplan <> :nprm 0 :scanrelid 1 }
NOTICE: QUERY PLAN:

Seq Scan on session (cost=0.00..1.43 rows=1 width=6)

EXPLAIN

At 10:53 PM -0500 11/11/01, Tom Lane wrote:
>Warren Volz <wrv(at)po(dot)cwru(dot)edu> writes:
>> p debug_query_string output:
>
>> $1 = 0x820caa0 "DELETE FROM session WHERE session_key =
>> 'bRUjmnqcb5prUNRE.Bb0sq+fZB69dkdVlCAKNBsb'"
>
>BTW, do you have rules or triggers on that table? The backtrace shows
>the system executing a nestloop join, which implies at least a two-table
>query, which says that there's more going on than meets the eye here.
>It would be useful to see the full schema for this table and any related
>tables, as well as an EXPLAIN VERBOSE for the above query.
>
> regards, tom lane

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Tom Lane 2001-11-12 05:58:51 Re: Bug #514: Backend crashes periodically
Previous Message Tom Lane 2001-11-12 03:53:08 Re: Bug #514: Backend crashes periodically