Re: Query is slow when run for first time; subsequent execution is fast

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



2018-01-12 9:03 GMT+01:00 Nandakumar M <m.nanda92@xxxxxxxxx>:
Hello Jeff,

Thanks for the insights.

>Don't keep closing and reopening connections.

Even if I close a connection and open a new one and execute the same query, the planning time is considerably less than the first time. Only when I restart the Postgres server then I face high planning time again.

>The query plan itself is not cached, but all the metadata about the (large number) of tables used in the query is cached.  Apparently reading/parsing that data is the slow step, not coming up with the actual plan.

I enabled logging for parser, planner etc in postgresql.conf and re run the queries. Following is the logs - I am not sure exactly how this should be read, but the major difference in elapsed time seems to be in PLANNER STATISTICS section.

-- start --

1. First run

LOG:  PARSER STATISTICS
DETAIL:  ! system usage stats:
! 0.000482 elapsed 0.000356 user 0.000127 system sec
! [0.004921 user 0.004824 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/102 [0/1076] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [3/5] messages rcvd/sent
! 0/0 [8/11] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  statement: SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  PARSE ANALYSIS STATISTICS
DETAIL:  ! system usage stats:
! 0.030012 elapsed 0.006251 user 0.006894 system sec
! [0.011270 user 0.011777 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/1036 [0/2126] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [3/5] messages rcvd/sent
! 154/5 [163/16] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  REWRITER STATISTICS
DETAIL:  ! system usage stats:
! 0.000058 elapsed 0.000052 user 0.000006 system sec
! [0.011350 user 0.011793 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/6 [0/2132] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [3/5] messages rcvd/sent
! 0/0 [163/16] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  PLANNER STATISTICS
DETAIL:  ! system usage stats:
! 0.326018 elapsed 0.013452 user 0.009604 system sec
! [0.024821 user 0.021400 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/531 [0/2663] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [3/5] messages rcvd/sent
! 51/71 [214/87] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  EXECUTOR STATISTICS
DETAIL:  ! system usage stats:
! 0.000047 elapsed 0.000026 user 0.000019 system sec
! [0.024961 user 0.021461 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/13 [0/2709] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [3/5] messages rcvd/sent
! 0/0 [214/87] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  duration: 357.192 ms


2. Second run


LOG:  PARSER STATISTICS
DETAIL:  ! system usage stats:
! 0.000169 elapsed 0.000161 user 0.000018 system sec
! [0.025308 user 0.021656 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/4 [0/2716] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [4/21] messages rcvd/sent
! 0/0 [215/87] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  statement: SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  PARSE ANALYSIS STATISTICS
DETAIL:  ! system usage stats:
! 0.002665 elapsed 0.001974 user 0.000196 system sec
! [0.027325 user 0.021866 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/17 [0/2734] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [4/21] messages rcvd/sent
! 0/56 [215/144] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  REWRITER STATISTICS
DETAIL:  ! system usage stats:
! 0.000068 elapsed 0.000068 user 0.000000 system sec
! [0.027425 user 0.021876 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/0 [0/2734] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [4/21] messages rcvd/sent
! 0/0 [215/144] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  PLANNER STATISTICS
DETAIL:  ! system usage stats:
! 0.001025 elapsed 0.000917 user 0.000105 system sec
! [0.028363 user 0.021986 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/0 [0/2734] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [4/21] messages rcvd/sent
! 0/1 [215/145] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  EXECUTOR STATISTICS
DETAIL:  ! system usage stats:
! 0.000016 elapsed 0.000016 user 0.000000 system sec
! [0.028449 user 0.021993 sys total]
! 0/0 [0/1] filesystem blocks in/out
! 0/0 [0/2734] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [4/21] messages rcvd/sent
! 0/0 [215/145] voluntary/involuntary context switches
STATEMENT:  SELECT COUNT(*) FROM ChangeDetails LEFT JOIN SDOrganization AaaOrg ON ChangeDetails.SITEID=AaaOrg.ORG_ID LEFT JOIN ApprovalStatusDefinition ON ChangeDetails.APPR_STATUSID=ApprovalStatusDefinition.STATUSID LEFT JOIN CategoryDefinition ON ChangeDetails.CATEGORYID=CategoryDefinition.CATEGORYID LEFT JOIN Change_Fields ON ChangeDetails.CHANGEID=Change_Fields.CHANGEID LEFT JOIN Change_StageDefinition ON ChangeDetails.WFSTAGEID=Change_StageDefinition.WFSTAGEID LEFT JOIN Change_StatusDefinition ON ChangeDetails.WFSTATUSID=Change_StatusDefinition.WFSTATUSID LEFT JOIN AaaUser ChangeManager ON ChangeDetails.CHANGEMANAGERID=ChangeManager.USER_ID LEFT JOIN AaaUser ChangeOriginator ON ChangeDetails.INITIATORID=ChangeOriginator.USER_ID LEFT JOIN AaaUser ChangeOwner ON ChangeDetails.TECHNICIANID=ChangeOwner.USER_ID LEFT JOIN ChangeResolution ON ChangeDetails.CHANGEID=ChangeResolution.CHANGEID LEFT JOIN ChangeTemplate ON ChangeDetails.TEMPLATEID=ChangeTemplate.TEMPLATEID LEFT JOIN ChangeToClosureCode ON ChangeDetails.CHANGEID=ChangeToClosureCode.CHANGEID LEFT JOIN Change_ClosureCode ON ChangeToClosureCode.ID=Change_ClosureCode.ID LEFT JOIN ChangeTypeDefinition ON ChangeDetails.CHANGETYPEID=ChangeTypeDefinition.CHANGETYPEID LEFT JOIN ChangeWF_Definition ON ChangeDetails.WFID=ChangeWF_Definition.ID LEFT JOIN ImpactDefinition ON ChangeDetails.IMPACTID=ImpactDefinition.IMPACTID LEFT JOIN ItemDefinition ON ChangeDetails.ITEMID=ItemDefinition.ITEMID LEFT JOIN PriorityDefinition ON ChangeDetails.PRIORITYID=PriorityDefinition.PRIORITYID LEFT JOIN QueueDefinition ON ChangeDetails.GROUPID=QueueDefinition.QUEUEID LEFT JOIN RiskDefinition ON ChangeDetails.RISKID=RiskDefinition.RISKID LEFT JOIN StageDefinition ON ChangeDetails.STAGEID=StageDefinition.STAGEID LEFT JOIN SubCategoryDefinition ON ChangeDetails.SUBCATEGORYID=SubCategoryDefinition.SUBCATEGORYID LEFT JOIN UrgencyDefinition ON ChangeDetails.URGENCYID=UrgencyDefinition.URGENCYID LEFT JOIN SDUser ON ChangeDetails.INITIATORID=SDUser.USERID;
LOG:  duration: 4.277 ms


-- end --

a. If someone could interpret what exactly the PLANNER STATISTICS section means (to identify the exact bottleneck) it would be great!

b. Sometimes, first execution of a query takes nearly 2 seconds of planning time. This seems to be too high even for the first run of the query. Will some configuration change help speed up the planning time? Also, is there any way to pre warm the caches so that the meta data that is required for the query planning is available in cache before hand?

maybe some your indexes and some system tables are bloated. Try you run VACUUM FULL ANALYZE

Regards

Pavel


Thanks and regards,
Nanda

[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux