Forum OpenACS Development: Re: acs_object__new slowness...

Collapse
Posted by Jeff Davis on
I tracked down the last bottleneck with creating users (and it ends up not being a problem with acs_objects). The problem is with the rel_constraint__violation check in membership_rels_in_tr. The second query in that function is very fast but the first gets much slower as users are added to the system. Here it is:
 for constraint_violated in
     select constraint_id, constraint_name
       from rel_constraints_violated_one
       where rel_id = violation__rel_id
       LIMIT 1 
    LOOP
This is checking for violated rel_constraints with rel_side = 'one' and takes about 2 seconds on my system even though rel_constraints only has one entry (and that with rel_side 'two'):
 constraint_id |               constraint_name               | rel_segment | rel_side | required_rel_segment 
---------------+---------------------------------------------+-------------+----------+----------------------
        924494 | Members of foo must be members of Main Site |      924493 | two      |                  432
In fact I can't find anywhere in the code that anything with rel_side one ever gets created nor does openacs.org or any other site I checked have rel_side 'one' entries.

In any case, the query plan for that seemingly innocuous query is entertainingly horrible:


                                                                                        QUERY PLAN                                                                                        
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Merge Join  (cost=2.04..16701.25 rows=1 width=262) (actual time=1208.71..1208.71 rows=0 loops=1)
   Merge Cond: ("outer".container_id = "inner".element_id)
   Join Filter: ("inner".segment_id = "outer".required_rel_segment)
   Filter: ("inner".element_id IS NULL)
   ->  Nested Loop  (cost=1.02..16310.71 rows=1 width=159) (actual time=1208.71..1208.71 rows=0 loops=1)
         Join Filter: (("inner".object_type = "outer".rel_type) AND ("inner".tree_sortkey >= "outer".tree_sortkey) AND ("inner".tree_sortkey <= tree_right("outer".tree_sortkey)))
         ->  Nested Loop  (cost=1.02..16307.39 rows=1 width=132) (actual time=1208.70..1208.70 rows=0 loops=1)
               Join Filter: ("inner".object_type = "outer".rel_type)
               ->  Nested Loop  (cost=1.02..16304.40 rows=1 width=105) (actual time=1208.70..1208.70 rows=0 loops=1)
                     Join Filter: ("outer".group_id = "inner".group_id)
                     ->  Index Scan using group_elem_idx_container_idx on group_element_index  (cost=0.00..16301.51 rows=2 width=26) (actual time=1067.93..1201.84 rows=2 loops=1)
                           Filter: (rel_id = 129804)
                     ->  Materialize  (cost=2.06..2.06 rows=1 width=79) (actual time=3.43..3.43 rows=0 loops=2)
                           ->  Hash Join  (cost=1.02..2.06 rows=1 width=79) (actual time=6.85..6.85 rows=0 loops=1)
                                 Hash Cond: ("outer".segment_id = "inner".rel_segment)
                                 ->  Seq Scan on rel_segments rs  (cost=0.00..1.02 rows=2 width=23) (actual time=0.03..0.04 rows=6 loops=1)
                                 ->  Hash  (cost=1.01..1.01 rows=1 width=56) (actual time=6.69..6.69 rows=0 loops=1)
                                       ->  Index Scan using jcd_rel_constraint_relside on rel_constraints rel  (cost=0.00..1.01 rows=1 width=56) (actual time=6.68..6.68 rows=0 loops=1)
                                             Index Cond: (rel_side = 'one'::bpchar)
               ->  Seq Scan on acs_object_types o2  (cost=0.00..2.44 rows=44 width=27) (never executed)
         ->  Seq Scan on acs_object_types o1  (cost=0.00..2.44 rows=44 width=27) (never executed)
   ->  Materialize  (cost=3742888.01..3742888.01 rows=67268 width=103) (never executed)
         ->  Nested Loop  (cost=1.02..3742888.01 rows=67268 width=103) (never executed)
               Join Filter: (("outer".tree_sortkey >= "inner".tree_sortkey) AND ("outer".tree_sortkey <= tree_right("inner".tree_sortkey)) AND ("outer".group_id = "inner".group_id))
               ->  Nested Loop  (cost=0.00..1804822.87 rows=598630 width=53) (never executed)
                     Join Filter: ("inner".object_type = "outer".rel_type)
                     ->  Index Scan using group_elem_idx_element_idx on group_element_index  (cost=0.00..14919.17 rows=598630 width=26) (never executed)
                     ->  Seq Scan on acs_object_types o1  (cost=0.00..2.44 rows=44 width=27) (never executed)
               ->  Materialize  (cost=3.71..3.71 rows=2 width=50) (never executed)
                     ->  Hash Join  (cost=1.02..3.71 rows=2 width=50) (never executed)
                           Hash Cond: ("outer".object_type = "inner".rel_type)
                           ->  Seq Scan on acs_object_types o2  (cost=0.00..2.44 rows=44 width=27) (never executed)
                           ->  Hash  (cost=1.02..1.02 rows=2 width=23) (never executed)
                                 ->  Seq Scan on rel_segments rs  (cost=0.00..1.02 rows=2 width=23) (never executed)
 Total runtime: 1209.02 msec
(35 rows)
Maybe someone who actually understands rel_segments (hint Don :) ) can look into why this is so awful. Given how bad the query is it might be worth adding something that checks that any rel_side 'one' constraints exist before running it.