On Saturday 02 June 2007 11:21:41 Michael Fuhr wrote:
> If you post an example query and the
> EXPLAIN ANALYZE output then we might be able to see if the slowness
> is due to query plans.
Query 1:
(SELECT
project.path AS rbac_project_path_string,
role_operation.resource_name AS rbac_resource_name,
role_operation.resource_value AS rbac_resource_value
FROM
project project,
role role,
role_default_user role_default_user,
role_operation role_operation
WHERE
role.id=role_default_user.role_id
AND role_default_user.project_id=project.id
AND role.id=role_operation.role_id
AND role.is_deleted=false
AND role_operation.object_type_id='Scm.Repository'
AND role_operation.operation_category='use'
AND role_operation.operation_name='access'
AND project.path='projects.barnes_and_nobles_college_bookse_3'
AND project.is_deleted=false
AND role_default_user.default_user_class_id='1'
)
UNION
(SELECT
project.path AS rbac_project_path_string,
role_operation.resource_name AS rbac_resource_name,
role_operation.resource_value AS rbac_resource_value
FROM
project project,
role role,
role_default_user role_default_user,
role_operation role_operation
WHERE
role.id=role_default_user.role_id
AND role_default_user.project_id=project.id
AND role.id=role_operation.role_id
AND role.is_deleted=false
AND role_operation.object_type_id='Scm.Repository'
AND role_operation.operation_category='use'
AND role_operation.operation_name='access'
AND project.path='projects.barnes_and_nobles_college_bookse_3'
AND project.is_deleted=false
AND role_default_user.default_user_class_id='2'
)
UNION
(SELECT
project.path AS rbac_project_path_string,
role_operation.resource_name AS rbac_resource_name,
role_operation.resource_value AS rbac_resource_value
FROM
project project,
role role,
role_default_user role_default_user,
role_operation role_operation
WHERE
role.id=role_default_user.role_id
AND role_default_user.project_id=project.id
AND role.id=role_operation.role_id
AND role.is_deleted=false
AND role_operation.object_type_id='Scm.Repository'
AND role_operation.operation_category='use'
AND role_operation.operation_name='access'
AND project.path='projects.barnes_and_nobles_college_bookse_3'
AND project.is_deleted=false
AND role_default_user.default_user_class_id='3'
)
UNION
(SELECT
project.path AS rbac_project_path_string,
role_operation.resource_name AS rbac_resource_name,
role_operation.resource_value AS rbac_resource_value
FROM
sfuser sfuser,
project project,
role role,
projectmembership projectmembership,
role_default_user role_default_user,
role_operation role_operation
WHERE
role.id=role_default_user.role_id
AND role_default_user.project_id=project.id
AND role.id=role_operation.role_id
AND role.is_deleted=false
AND role_operation.object_type_id='Scm.Repository'
AND role_operation.operation_category='use'
AND role_operation.operation_name='access'
AND project.path='projects.barnes_and_nobles_college_bookse_3'
AND project.is_deleted=false
AND role_default_user.default_user_class_id='4'
AND projectmembership.member_id=sfuser.id
AND role_default_user.project_id=projectmembership.project_id
AND sfuser.username='rtrejo'
)
UNION
(SELECT
project.path AS rbac_project_path_string,
role_operation.resource_name AS rbac_resource_name,
role_operation.resource_value AS rbac_resource_value
FROM
sfuser sfuser,
project project,
role role,
role_user role_user,
role_operation role_operation
WHERE
role.id=role_user.role_id
AND role_user.project_id=project.id
AND role.id=role_operation.role_id
AND role.is_deleted=false
AND role_operation.object_type_id='Scm.Repository'
AND role_operation.operation_category='use'
AND role_operation.operation_name='access'
AND role_user.user_id=sfuser.id
AND project.path='projects.barnes_and_nobles_college_bookse_3'
AND project.is_deleted=false
AND sfuser.username='rtrejo'
);
take 0m1.693s according to 'time'
Explain attached as explain1
Query 2:
SELECT
artifact.id AS id,
artifact.priority AS priority,
project.path AS projectPathString,
project.title AS projectTitle,
folder.project_id AS projectId,
folder.path AS folderPathString,
folder.title AS folderTitle,
item.folder_id AS folderId,
item.title AS title,
item.name AS name,
artifact.description AS description,
field_value.value AS artifactGroup,
field_value2.value AS status,
field_value2.value_class AS statusClass,
field_value3.value AS category,
field_value4.value AS customer,
sfuser.username AS submittedByUsername,
sfuser.full_name AS submittedByFullname,
item.date_created AS submittedDate,
artifact.close_date AS closeDate,
sfuser2.username AS assignedToUsername,
sfuser2.full_name AS assignedToFullname,
item.date_last_modified AS lastModifiedDate,
artifact.estimated_hours AS estimatedHours,
artifact.actual_hours AS actualHours,
item.version AS version
FROM
relationship relationship,
sfuser sfuser,
sfuser sfuser2,
field_value field_value3,
item item,
project project,
field_value field_value2,
field_value field_value,
artifact artifact,
folder folder,
field_value field_value4
WHERE
artifact.id=item.id
AND item.folder_id=folder.id
AND folder.project_id=project.id
AND artifact.group_fv=field_value.id
AND artifact.status_fv=field_value2.id
AND artifact.category_fv=field_value3.id
AND artifact.customer_fv=field_value4.id
AND item.created_by_id=sfuser.id
AND relationship.is_deleted=false
AND relationship.relationship_type_name='ArtifactAssignment'
AND relationship.origin_id=sfuser2.id
AND artifact.id=relationship.target_id
AND item.is_deleted=false
AND ((project.path='projects.union_gas_gdar_ebt' AND ((folder.path IN
('tracker.cutover_tasks', 'tracker.peer_review_tracker', 'tracker.tars_0', 'tracker.reviews', 'tracker.defects', 'tracker.tars', 'tracker.database_change_requests'))
OR folder.path LIKE 'tracker.cutover_tasks.%' OR folder.path
LIKE 'tracker.peer_review_tracker.%' OR folder.path LIKE 'tracker.tars_0.%'
OR folder.path LIKE 'tracker.reviews.%' OR folder.path LIKE 'tracker.defects.
%' OR folder.path LIKE 'tracker.tars.%' OR folder.path
LIKE 'tracker.database_change_requests.%')))
AND folder.project_id='proj1775'
AND item.folder_id='tracker11923'
AND folder.path='tracker.defects'
AND (sfuser2.username='nobody' AND field_value2.value_class='Open');
takes 0m9.506s according to time.. it's attached as explain2
TIA, again
--
Douglas J Hunley (doug at hunley.homeip.net) - Linux User #174778
http://doug.hunley.homeip.net
It's not the pace of life that concerns me, it's the sudden stop at the end.
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Unique (cost=101.98..102.03 rows=5 width=56) (actual time=3049.469..3049.479 rows=1 loops=1)
-> Sort (cost=101.98..101.99 rows=5 width=56) (actual time=3049.461..3049.465 rows=1 loops=1)
Sort Key: rbac_project_path_string, rbac_resource_name, rbac_resource_value
-> Append (cost=0.00..101.92 rows=5 width=56) (actual time=2101.795..3049.325 rows=1 loops=1)
-> Nested Loop (cost=0.00..13.35 rows=1 width=56) (actual time=505.275..505.275 rows=0 loops=1)
-> Nested Loop (cost=0.00..12.97 rows=1 width=30) (actual time=505.268..505.268 rows=0 loops=1)
-> Nested Loop (cost=0.00..8.68 rows=1 width=42) (actual time=0.347..346.759 rows=7294 loops=1)
-> Index Scan using role_oper_obj_oper on role_operation (cost=0.00..4.40 rows=1 width=30) (actual time=0.235..71.840 rows=7294 loops=1)
Index Cond: (((object_type_id)::text = 'Scm.Repository'::text) AND ((operation_category)::text = 'use'::text) AND ((operation_name)::text = 'access'::text))
-> Index Scan using role_pk on "role" (cost=0.00..4.27 rows=1 width=12) (actual time=0.020..0.024 rows=1 loops=7294)
Index Cond: (("role".id)::text = (role_operation.role_id)::text)
Filter: (NOT is_deleted)
-> Index Scan using role_def_u_prj_idx on role_default_user (cost=0.00..4.27 rows=1 width=24) (actual time=0.015..0.015 rows=0 loops=7294)
Index Cond: ((("role".id)::text = (role_default_user.role_id)::text) AND (role_default_user.default_user_class_id = 1))
-> Index Scan using project_pk on project (cost=0.00..0.37 rows=1 width=50) (never executed)
Index Cond: ((role_default_user.project_id)::text = (project.id)::text)
Filter: (((path)::text = 'projects.barnes_and_nobles_college_bookse_3'::text) AND (NOT is_deleted))
-> Nested Loop (cost=0.00..13.35 rows=1 width=56) (actual time=442.680..442.680 rows=0 loops=1)
-> Nested Loop (cost=0.00..12.97 rows=1 width=30) (actual time=442.674..442.674 rows=0 loops=1)
-> Nested Loop (cost=0.00..8.68 rows=1 width=42) (actual time=0.124..289.008 rows=7294 loops=1)
-> Index Scan using role_oper_obj_oper on role_operation (cost=0.00..4.40 rows=1 width=30) (actual time=0.093..35.719 rows=7294 loops=1)
Index Cond: (((object_type_id)::text = 'Scm.Repository'::text) AND ((operation_category)::text = 'use'::text) AND ((operation_name)::text = 'access'::text))
-> Index Scan using role_pk on "role" (cost=0.00..4.27 rows=1 width=12) (actual time=0.018..0.021 rows=1 loops=7294)
Index Cond: (("role".id)::text = (role_operation.role_id)::text)
Filter: (NOT is_deleted)
-> Index Scan using role_def_u_prj_idx on role_default_user (cost=0.00..4.27 rows=1 width=24) (actual time=0.014..0.014 rows=0 loops=7294)
Index Cond: ((("role".id)::text = (role_default_user.role_id)::text) AND (role_default_user.default_user_class_id = 2))
-> Index Scan using project_pk on project (cost=0.00..0.37 rows=1 width=50) (never executed)
Index Cond: ((role_default_user.project_id)::text = (project.id)::text)
Filter: (((path)::text = 'projects.barnes_and_nobles_college_bookse_3'::text) AND (NOT is_deleted))
-> Nested Loop (cost=0.00..13.35 rows=1 width=56) (actual time=184.063..184.063 rows=0 loops=1)
-> Nested Loop (cost=0.00..9.07 rows=1 width=80) (actual time=184.055..184.055 rows=0 loops=1)
-> Nested Loop (cost=0.00..8.69 rows=1 width=54) (actual time=8.814..183.848 rows=4 loops=1)
-> Index Scan using role_oper_obj_oper on role_operation (cost=0.00..4.40 rows=1 width=30) (actual time=0.095..34.567 rows=7294 loops=1)
Index Cond: (((object_type_id)::text = 'Scm.Repository'::text) AND ((operation_category)::text = 'use'::text) AND ((operation_name)::text = 'access'::text))
-> Index Scan using role_def_u_prj_idx on role_default_user (cost=0.00..4.27 rows=1 width=24) (actual time=0.014..0.014 rows=0 loops=7294)
Index Cond: (((role_operation.role_id)::text = (role_default_user.role_id)::text) AND (role_default_user.default_user_class_id = 3))
-> Index Scan using project_pk on project (cost=0.00..0.37 rows=1 width=50) (actual time=0.042..0.042 rows=0 loops=4)
Index Cond: ((role_default_user.project_id)::text = (project.id)::text)
Filter: (((path)::text = 'projects.barnes_and_nobles_college_bookse_3'::text) AND (NOT is_deleted))
-> Index Scan using role_pk on "role" (cost=0.00..4.27 rows=1 width=12) (never executed)
Index Cond: (("role".id)::text = (role_default_user.role_id)::text)
Filter: (NOT is_deleted)
-> Nested Loop (cost=0.00..16.02 rows=1 width=56) (actual time=202.991..202.991 rows=0 loops=1)
-> Nested Loop (cost=0.00..15.73 rows=1 width=42) (actual time=202.984..202.984 rows=0 loops=1)
-> Nested Loop (cost=0.00..11.45 rows=1 width=66) (actual time=202.978..202.978 rows=0 loops=1)
Join Filter: ((projectmembership.member_id)::text = (sfuser.id)::text)
-> Nested Loop (cost=0.00..10.13 rows=4 width=78) (actual time=10.425..190.540 rows=437 loops=1)
-> Nested Loop (cost=0.00..8.69 rows=1 width=54) (actual time=8.747..182.982 rows=10 loops=1)
-> Index Scan using role_oper_obj_oper on role_operation (cost=0.00..4.40 rows=1 width=30) (actual time=0.093..34.379 rows=7294 loops=1)
Index Cond: (((object_type_id)::text = 'Scm.Repository'::text) AND ((operation_category)::text = 'use'::text) AND ((operation_name)::text = 'access'::text))
-> Index Scan using role_def_u_prj_idx on role_default_user (cost=0.00..4.27 rows=1 width=24) (actual time=0.014..0.014 rows=0 loops=7294)
Index Cond: (((role_operation.role_id)::text = (role_default_user.role_id)::text) AND (role_default_user.default_user_class_id = 4))
-> Index Scan using pjmb_projmember on projectmembership (cost=0.00..1.13 rows=25 width=24) (actual time=0.053..0.453 rows=44 loops=10)
Index Cond: ((role_default_user.project_id)::text = (projectmembership.project_id)::text)
-> Index Scan using sfuser_username on sfuser (cost=0.00..0.32 rows=1 width=12) (actual time=0.014..0.018 rows=1 loops=437)
Index Cond: ((username)::text = 'rtrejo'::text)
-> Index Scan using role_pk on "role" (cost=0.00..4.27 rows=1 width=12) (never executed)
Index Cond: (("role".id)::text = (role_default_user.role_id)::text)
Filter: (NOT is_deleted)
-> Index Scan using project_pk on project (cost=0.00..0.28 rows=1 width=50) (never executed)
Index Cond: ((role_default_user.project_id)::text = (project.id)::text)
Filter: (((path)::text = 'projects.barnes_and_nobles_college_bookse_3'::text) AND (NOT is_deleted))
-> Nested Loop (cost=2.40..45.80 rows=1 width=56) (actual time=766.764..1714.288 rows=1 loops=1)
Join Filter: ((role_user.user_id)::text = (sfuser.id)::text)
-> Nested Loop (cost=2.40..45.49 rows=1 width=68) (actual time=762.629..1712.222 rows=82 loops=1)
-> Nested Loop (cost=2.40..44.63 rows=3 width=42) (actual time=0.356..944.773 rows=37814 loops=1)
-> Nested Loop (cost=0.00..8.68 rows=1 width=42) (actual time=0.134..272.836 rows=7294 loops=1)
-> Index Scan using role_oper_obj_oper on role_operation (cost=0.00..4.40 rows=1 width=30) (actual time=0.098..34.408 rows=7294 loops=1)
Index Cond: (((object_type_id)::text = 'Scm.Repository'::text) AND ((operation_category)::text = 'use'::text) AND ((operation_name)::text = 'access'::text))
-> Index Scan using role_pk on "role" (cost=0.00..4.27 rows=1 width=12) (actual time=0.016..0.019 rows=1 loops=7294)
Index Cond: (("role".id)::text = (role_operation.role_id)::text)
Filter: (NOT is_deleted)
-> Bitmap Heap Scan on role_user (cost=2.40..35.73 rows=18 width=36) (actual time=0.029..0.050 rows=5 loops=7294)
Recheck Cond: (("role".id)::text = (role_user.role_id)::text)
-> Bitmap Index Scan on role_user_proj_idx (cost=0.00..2.39 rows=18 width=0) (actual time=0.021..0.021 rows=5 loops=7294)
Index Cond: (("role".id)::text = (role_user.role_id)::text)
-> Index Scan using project_pk on project (cost=0.00..0.27 rows=1 width=50) (actual time=0.014..0.014 rows=0 loops=37814)
Index Cond: ((role_user.project_id)::text = (project.id)::text)
Filter: (((path)::text = 'projects.barnes_and_nobles_college_bookse_3'::text) AND (NOT is_deleted))
-> Index Scan using sfuser_username on sfuser (cost=0.00..0.30 rows=1 width=12) (actual time=0.012..0.015 rows=1 loops=82)
Index Cond: ((username)::text = 'rtrejo'::text)
Total runtime: 3050.582 ms
(83 rows)
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=6.67..616.24 rows=1 width=629) (actual time=11870.870..11870.870 rows=0 loops=1)
-> Nested Loop (cost=6.67..611.96 rows=1 width=555) (actual time=11870.863..11870.863 rows=0 loops=1)
-> Nested Loop (cost=6.67..607.64 rows=1 width=492) (actual time=11870.857..11870.857 rows=0 loops=1)
-> Nested Loop (cost=6.67..606.26 rows=1 width=471) (actual time=11870.850..11870.850 rows=0 loops=1)
-> Nested Loop (cost=6.67..605.92 rows=1 width=473) (actual time=11870.844..11870.844 rows=0 loops=1)
-> Nested Loop (cost=6.67..605.58 rows=1 width=475) (actual time=11870.838..11870.838 rows=0 loops=1)
-> Nested Loop (cost=6.67..605.23 rows=1 width=477) (actual time=11870.831..11870.831 rows=0 loops=1)
-> Nested Loop (cost=6.67..602.90 rows=3 width=393) (actual time=62.032..10750.797 rows=29905 loops=1)
-> Nested Loop (cost=6.67..595.64 rows=21 width=387) (actual time=61.558..6905.828 rows=126625 loops=1)
-> Nested Loop (cost=6.67..585.73 rows=21 width=46) (actual time=61.399..1590.547 rows=126625 loops=1)
-> Index Scan using sfuser_username on sfuser sfuser2 (cost=0.00..4.27 rows=1 width=45) (actual time=0.122..0.127 rows=1 loops=1)
Index Cond: ((username)::text = 'nobody'::text)
-> Bitmap Heap Scan on relationship (cost=6.67..577.58 rows=311 width=25) (actual time=61.260..783.652 rows=126625 loops=1)
Recheck Cond: ((relationship.origin_id)::text = (sfuser2.id)::text)
Filter: ((NOT is_deleted) AND ((relationship_type_name)::text = 'ArtifactAssignment'::text))
-> Bitmap Index Scan on relation_origin (cost=0.00..6.62 rows=311 width=0) (actual time=57.009..57.009 rows=220230 loops=1)
Index Cond: ((relationship.origin_id)::text = (sfuser2.id)::text)
-> Index Scan using artifact_pk on artifact (cost=0.00..0.46 rows=1 width=341) (actual time=0.025..0.029 rows=1 loops=126625)
Index Cond: ((artifact.id)::text = (relationship.target_id)::text)
-> Index Scan using field_value_pk on field_value field_value2 (cost=0.00..0.33 rows=1 width=32) (actual time=0.021..0.022 rows=0 loops=126625)
Index Cond: ((artifact.status_fv)::text = (field_value2.id)::text)
Filter: ((value_class)::text = 'Open'::text)
-> Index Scan using item_pk on item (cost=0.00..0.76 rows=1 width=110) (actual time=0.031..0.031 rows=0 loops=29905)
Index Cond: ((artifact.id)::text = (item.id)::text)
Filter: ((NOT is_deleted) AND ((folder_id)::text = 'tracker11923'::text))
-> Index Scan using field_value_pk on field_value field_value4 (cost=0.00..0.33 rows=1 width=24) (never executed)
Index Cond: ((artifact.customer_fv)::text = (field_value4.id)::text)
-> Index Scan using field_value_pk on field_value (cost=0.00..0.33 rows=1 width=24) (never executed)
Index Cond: ((artifact.group_fv)::text = (field_value.id)::text)
-> Index Scan using field_value_pk on field_value field_value3 (cost=0.00..0.33 rows=1 width=24) (never executed)
Index Cond: ((artifact.category_fv)::text = (field_value3.id)::text)
-> Index Scan using sfuser_pk on sfuser (cost=0.00..1.37 rows=1 width=45) (never executed)
Index Cond: ((item.created_by_id)::text = (sfuser.id)::text)
-> Index Scan using folder_pk on folder (cost=0.00..4.31 rows=1 width=77) (never executed)
Index Cond: ('tracker11923'::text = (id)::text)
Filter: ((((path)::text = ANY (('{tracker.cutover_tasks,tracker.peer_review_tracker,tracker.tars_0,tracker.reviews,tracker.defects,tracker.tars,tracker.database_change_requests}'::character varying[])::text[])) OR ((path)::text ~~ 'tracker.cutover_tasks.%'::text) OR ((path)::text ~~ 'tracker.peer_review_tracker.%'::text) OR ((path)::text ~~ 'tracker.tars_0.%'::text) OR ((path)::text ~~ 'tracker.reviews.%'::text) OR ((path)::text ~~ 'tracker.defects.%'::text) OR ((path)::text ~~ 'tracker.tars.%'::text) OR ((path)::text ~~ 'tracker.database_change_requests.%'::text)) AND ((project_id)::text = 'proj1775'::text) AND ((path)::text = 'tracker.defects'::text))
-> Index Scan using project_pk on project (cost=0.00..4.27 rows=1 width=86) (never executed)
Index Cond: ('proj1775'::text = (id)::text)
Filter: ((path)::text = 'projects.union_gas_gdar_ebt'::text)
Total runtime: 11871.582 ms
(40 rows)
