Forum OpenACS Development: Re: Slow bugtracker when accepting a patch
Posted by
Dave Bauer
on 09/18/05 09:14 PM
Ok here is what I have found
Original query
openacs.org=# explain analyze select bt_patch_actions.action_id,
bt_patch_actions.action,
bt_patch_actions.actor as actor_user_id,
actor.first_names as actor_first_names,
actor.last_name as actor_last_name,
actor.email as actor_email,
bt_patch_actions.action_date,
to_char(bt_patch_actions.action_date, 'fmMM/DDfm/YYYY') as action_date_pretty,
bt_patch_actions.comment_text,
bt_patch_actions.comment_format
from bt_patch_actions,
cc_users actor
where bt_patch_actions.patch_id = '320984'
and actor.user_id = bt_patch_actions.actor
QUERY PLAN \
----------------------------------------------------------------------------------------------------------------------------------------------\-----------------------------------------------------------
Sort (cost=404.01..404.02 rows=1 width=328) (actual time=20062.009..20062.016 rows=2 loops=1)
Sort Key: bt_patch_actions.action_date
-> Nested Loop (cost=0.00..404.00 rows=1 width=328) (actual time=171.294..20061.424 rows=2 loops=1)
-> Nested Loop (cost=0.00..398.00 rows=1 width=332) (actual time=171.081..20061.074 rows=2 loops=1)
-> Nested Loop (cost=0.00..392.00 rows=1 width=280) (actual time=170.972..20060.851 rows=2 loops=1)
Join Filter: ("outer".group_id = "inner".object_id)
-> Nested Loop (cost=0.00..390.93 rows=1 width=288) (actual time=170.858..20060.572 rows=3 loops=1)
Join Filter: ("inner".actor = "outer".person_id)
-> Nested Loop (cost=0.00..336.26 rows=1 width=164) (actual time=0.510..2933.461 rows=9170 loops=1)
-> Nested Loop (cost=0.00..330.24 rows=1 width=160) (actual time=0.445..2132.939 rows=9170 loops=1)
-> Nested Loop (cost=0.00..324.22 rows=1 width=156) (actual time=0.341..1176.314 rows=9170 loops=1)
-> Index Scan using group_elem_idx_rel_type_idx on group_element_index (cost=0.00..318.22 rows=\1 width=16) (actual time=0.260..366.296 rows=9170 loops=1)
Index Cond: ((rel_type)::text = 'membership_rel'::text)
Filter: (((ancestor_rel_type)::text = 'membership_rel'::text) AND (container_id = group_id)\)
-> Index Scan using persons_pk on persons pe (cost=0.00..5.99 rows=1 width=140) (actual time=0.\047..0.063 rows=1 loops=9170)
Index Cond: ("outer".element_id = pe.person_id)
-> Index Scan using acs_objects_pk on acs_objects o (cost=0.00..6.01 rows=1 width=4) (actual time=0.0\63..0.081 rows=1 loops=9170)
Index Cond: ("outer".person_id = o.object_id)
-> Index Scan using users_pk on users u (cost=0.00..6.01 rows=1 width=4) (actual time=0.045..0.064 rows=1 l\oops=9170)
Index Cond: (u.user_id = "outer".object_id)
-> Seq Scan on bt_patch_actions (cost=0.00..54.56 rows=8 width=124) (actual time=1.822..1.843 rows=2 loops=9170)
Filter: (patch_id = 320984)
-> Seq Scan on acs_magic_objects amo (cost=0.00..1.06 rows=1 width=4) (actual time=0.052..0.061 rows=1 loops=3)
Filter: ((name)::text = 'registered_users'::text)
-> Index Scan using parties_pk on parties pa (cost=0.00..5.99 rows=1 width=72) (actual time=0.068..0.078 rows=1 loops=2)
Index Cond: ("outer".element_id = pa.party_id)
-> Index Scan using membership_rel_rel_id_pk on membership_rels mr (cost=0.00..5.98 rows=1 width=4) (actual time=0.075..0.082 rows=\1 loops=2)
Index Cond: ("outer".rel_id = mr.rel_id)
Total runtime: 20063.022 ms
(29 rows)First I see a join on cc_users, which is a slow view, and not necessary in this case, since we are joining against an existing list of user_ids in the database. I see a sequential scan on bt_patch_actions. This table has 1496 rows, so we might need an index on there.
First we join on acs_users_all instead of cc_users
openacs.org=# explain analyze select bt_patch_actions.action_id,
bt_patch_actions.action,
bt_patch_actions.actor as actor_user_id,
actor.first_names as actor_first_names,
actor.last_name as actor_last_name,
actor.email as actor_email,
bt_patch_actions.action_date,
to_char(bt_patch_actions.action_date, 'fmMM/DDfm/YYYY') as action_date_pretty,
bt_patch_actions.comment_text,
bt_patch_actions.comment_format
from bt_patch_actions,
acs_users_all actor
where bt_patch_actions.patch_id = '320984'
and actor.user_id = bt_patch_actions.actor;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=0.00..90.75 rows=2 width=376) (actual time=1.704..1.972 rows=2 loops=1)
-> Nested Loop (cost=0.00..78.70 rows=2 width=384) (actual time=1.631..1.821 rows=2 loops=1)
-> Nested Loop (cost=0.00..66.71 rows=2 width=244) (actual time=1.571..1.680 rows=2 loops=1)
-> Seq Scan on bt_patch_actions (cost=0.00..54.70 rows=2 width=172) (actual time=1.452..1.471 rows=2 loops=1)
Filter: (patch_id = 320984)
-> Index Scan using parties_pk on parties pa (cost=0.00..5.99 rows=1 width=72) (actual time=0.062..0.068 rows=1 loops=2)
Index Cond: ("outer".actor = pa.party_id)
-> Index Scan using persons_pk on persons pe (cost=0.00..5.99 rows=1 width=140) (actual time=0.026..0.038 rows=1 loops=2)
Index Cond: ("outer".actor = pe.person_id)
-> Index Scan using users_pk on users u (cost=0.00..6.01 rows=1 width=4) (actual time=0.017..0.024 rows=1 loops=2)
Index Cond: (u.user_id = "outer".party_id)
Total runtime: 2.206 ms
(12 rows)This is 10x faster.
Adding an index on bt_patch_actions.patch_id
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------\---------------------
Nested Loop (cost=0.00..40.18 rows=2 width=376) (actual time=0.299..0.611 rows=2 loops=1)
-> Nested Loop (cost=0.00..28.18 rows=2 width=248) (actual time=0.220..0.431 rows=2 loops=1)
-> Nested Loop (cost=0.00..16.13 rows=2 width=244) (actual time=0.147..0.277 rows=2 loops=1)
-> Index Scan using bt_patch_actions_patch_id_fk on bt_patch_actions (cost=0.00..4.13 rows=2 width=172) (actual time=0.027..0.042 rows=2 loops=1)
Index Cond: (patch_id = 320984)
-> Index Scan using parties_pk on parties pa (cost=0.00..5.99 rows=1 width=72) (actual time=0.075..0.087 rows=1 loops=2)
Index Cond: ("outer".actor = pa.party_id)
-> Index Scan using users_pk on users u (cost=0.00..6.01 rows=1 width=4) (actual time=0.038..0.048 rows=1 loops=2)
Index Cond: (u.user_id = "outer".party_id)
-> Index Scan using persons_pk on persons pe (cost=0.00..5.99 rows=1 width=140) (actual time=0.031..0.042 rows=1 loops=2)
Index Cond: ("outer".actor = pe.person_id)
Total runtime: 0.827 ms
(12 rows)Now that's fast!
I vacuumed the bt_patch_actions table after adding the index. I also tested with the index, joining on cc_users. The result was 1551 ms, faster, but still not fast enough.
I have made the query change on openacs.org and CVS. It looks like the new
