Re: "explain analyze" a procedure verbosely - to find which statement in it takes longer

This seems to have helped:

# create index pref_cards_rid_index on pref_cards(rid);
CREATE INDEX

# \d pref_cards;
Table "public.pref_cards"
Column | Type | Modifiers
---------+-----------------------------+---------------
rid | integer | not null
id | character varying(32) | not null
bid | character varying(32) | not null
trix | integer | not null
pos | integer | not null
money | integer | not null
last_ip | inet |
quit | boolean |
stamp | timestamp without time zone | default now()
Indexes:
"pref_cards_pkey" PRIMARY KEY, btree (id, rid)
"pref_cards_rid_index" btree (rid)
Foreign-key constraints:
"pref_cards_id_fkey" FOREIGN KEY (id) REFERENCES pref_users(id) ON
DELETE CASCADE
"pref_cards_rid_fkey" FOREIGN KEY (rid) REFERENCES
pref_rounds(rid) ON DELETE CASCADE

# explain analyze delete from pref_rounds r
using temp_rids t
where r.rid = t.rid;
QUERY PLAN

------------------------------------------------------------------------------------------------------------------
------------------------
Nested Loop (cost=0.00..20270.01 rows=2880 width=6) (actual
time=0.110..117.658 rows=3022 loops=1)
-> Seq Scan on temp_rids t (cost=0.00..40.80 rows=2880 width=4)
(actual time=0.047..1.413 rows=3022 loops=1)
-> Index Scan using pref_rounds_pkey on pref_rounds r
(cost=0.00..7.01 rows=1 width=10) (actual time=0.036..0
.037 rows=1 loops=3022)
Index Cond: (r.rid = t.rid)
Trigger for constraint pref_cards_rid_fkey: time=762.161 calls=3022
Trigger for constraint pref_discuss_rid_fkey: time=115.801 calls=3022
Trigger for constraint pref_votes_rid_fkey: time=74.814 calls=3022
Total runtime: 1316.472 ms
(8 rows)

On Thu, Feb 7, 2013 at 11:34 AM, Alexander Farber
<alexander(dot)farber(at)gmail(dot)com> wrote:
> # explain analyze delete from pref_rounds r
> using temp_rids t
> where r.rid = t.rid;
> QUERY PLAN
>
> ------------------------------------------------------------------------------------------------------------------
> ------------------------
> Nested Loop (cost=0.00..20270.01 rows=2880 width=6) (actual
> time=4.246..120.058 rows=3022 loops=1)
> -> Seq Scan on temp_rids t (cost=0.00..40.80 rows=2880 width=4)
> (actual time=0.008..1.194 rows=3022 loops=1)
> -> Index Scan using pref_rounds_pkey on pref_rounds r
> (cost=0.00..7.01 rows=1 width=10) (actual time=0.037..0
> .038 rows=1 loops=3022)
> Index Cond: (r.rid = t.rid)
> Trigger for constraint pref_cards_rid_fkey: time=1106450.109 calls=3022
> Trigger for constraint pref_discuss_rid_fkey: time=171.322 calls=3022
> Trigger for constraint pref_votes_rid_fkey: time=85.484 calls=3022
> Total runtime: 1107082.899 ms
> (8 rows)
>
> So it probably spends most of its time
> in the pref_cards, thorugh the FK "rid"?
>
> Which index would be to add here best?
>
> Regards
> Alex
>
> On Wed, Feb 6, 2013 at 11:03 AM, Alexander Farber >
>> create or replace function pref_delete_user(_id varchar,
>> _reason varchar) returns void as $BODY$
>> begin
>>
>> insert into pref_ban2 select
>> id,
>> first_name,
>> last_name,
>> city,
>> last_ip
>> from pref_users where id=_id;
>>
>> update pref_ban2 set reason=_reason where id=_id;
>>
>> create temporary table temp_gids (gid int not null) on
>> commit drop;
>> insert into temp_gids (gid) select gid from
>> pref_scores where id=_id;
>>
>> delete from pref_games p
>> using temp_gids t
>> where p.gid = t.gid;
>>
>> create temporary table temp_rids (rid int not null) on
>> commit drop;
>> insert into temp_rids (rid) select rid from pref_cards
>> where id=_id;
>>
>> delete from pref_rounds r
>> using temp_rids t
>> where r.rid = t.rid;
>>
>> delete from pref_users where id=_id;
>>
>> end;
>> $BODY$ language plpgsql;
>>
>> create table pref_users (
>> id varchar(32) primary key,
>> first_name varchar(64),
>> last_name varchar(64),
>> female boolean,
>> avatar varchar(128),
>> city varchar(64),
>> login timestamp default current_timestamp,
>> logout timestamp,
>> last_ip inet,
>> vip timestamp,
>> mail varchar(256),
>> medals integer not null default 0
>> );
>>
>> create table pref_rounds (
>> rid serial primary key,
>> cards text,
>> stamp timestamp default current_timestamp
>> );
>>
>> create table pref_cards (
>> rid integer references pref_rounds on delete cascade,
>> id varchar(32) references pref_users on delete cascade,
>> bid varchar(32) not null,
>> trix integer not null,
>> pos integer not null,
>> money integer not null,
>> last_ip inet,
>> quit boolean,
>> stamp timestamp default current_timestamp,
>> primary key(id, rid) /* added recently */
>> );
>>
>> create table pref_games (
>> gid serial primary key,
>> rounds integer not null,
>> stamp timestamp default current_timestamp
>> );
>>
>> create table pref_scores (
>> id varchar(32) references pref_users on delete cascade,
>> gid integer references pref_games on delete cascade,
>> money integer not null,
>> last_ip inet,
>> quit boolean,
>> primary key(id, gid); /* added recently */
>> );
>>
>> create table pref_ban2 (
>> id varchar(32) primary key, /* not a foreign key,
>> since banned */
>> first_name varchar(64),
>> last_name varchar(64),
>> city varchar(64),
>> last_ip inet,
>> reason varchar(128),
>> created timestamp default current_timestamp
>> );