Forum OpenACS Development: Re: acs_object__new slowness...
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 LOOPThis 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 | 432In 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.