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

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?

Thanks and regards,
Nanda