Hello,
Repeatedly, I came across instances where any query when run for the first time takes longer time to execute (nearly 2 second sometimes), but subsequent execution of the same query is very fast (less than 20 milliseconds).
-- end --
In the above thread Tom Lane mentions that the plan is never cached for raw queries. Yet, this is exactly what seems to be happening in my case. Am I missing something? Please let me know how I can make sure the query execution for the first time is fast too.
Thanks and regards,
This is my first question in postgres mailing list. If there are any mistakes, please don't mind.
I am using PostgreSQL 9.4.4 on a Mac machine executing queries on postgres server through the psql client.
I am using PostgreSQL 9.4.4 on a Mac machine executing queries on postgres server through the psql client.
servicedesk=# select version();
version
--------------------------------------------------------------------------------------------------------------------------------------------------------------------
PostgreSQL 9.4.4 on x86_64-apple-darwin, compiled by i686-apple-darwin11-llvm-gcc-4.2 (GCC) 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2336.11.00), 64-bit
(1 row)
Repeatedly, I came across instances where any query when run for the first time takes longer time to execute (nearly 2 second sometimes), but subsequent execution of the same query is very fast (less than 20 milliseconds).
The tables involved in the query also have very less number of rows (less than 50).
On running explain (analyze, buffers) got the following results.
On running explain (analyze, buffers) got the following results.
-- start --
servicedesk=#
servicedesk=# explain (analyze, buffers, verbose) 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;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=13.25..13.26 rows=1 width=160) (actual time=0.018..0.018 rows=1 loops=1)
Output: count(*)
Buffers: shared hit=1
-> Seq Scan on public.changedetails (cost=0.00..12.60 rows=260 width=160) (actual time=0.007..0.008 rows=2 loops=1)
Output: changedetails.changeid, changedetails.initiatorid, changedetails.technicianid, changedetails.stageid, changedetails.priorityid, changedetails.categoryid, changedetails.subcategoryid, changedetails.itemid, changedetails.appr_statusid, changedetails.changetypeid, changedetails.urgencyid, changedetails.title, changedetails.description, changedetails.createdtime, changedetails.scheduledstarttime, changedetails.scheduledendtime, changedetails.completedtime, changedetails.notespresent, changedetails.siteid, changedetails.groupid, changedetails.templateid, changedetails.wfid, changedetails.wfstageid, changedetails.wfstatusid, changedetails.isemergency, changedetails.isretrospective, changedetails.reasonforchangeid, changedetails.closurecodeid, changedetails.changemanagerid, changedetails.riskid, changedetails.impactid, changedetails.slaid, changedetails.isoverdue
Buffers: shared hit=1
Planning time: 468.239 ms
Execution time: 0.104 ms
(8 rows)
servicedesk=#
servicedesk=# explain (analyze, buffers, verbose) 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;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=13.25..13.26 rows=1 width=160) (actual time=0.009..0.009 rows=1 loops=1)
Output: count(*)
Buffers: shared hit=1
-> Seq Scan on public.changedetails (cost=0.00..12.60 rows=260 width=160) (actual time=0.005..0.005 rows=2 loops=1)
Output: changedetails.changeid, changedetails.initiatorid, changedetails.technicianid, changedetails.stageid, changedetails.priorityid, changedetails.categoryid, changedetails.subcategoryid, changedetails.itemid, changedetails.appr_statusid, changedetails.changetypeid, changedetails.urgencyid, changedetails.title, changedetails.description, changedetails.createdtime, changedetails.scheduledstarttime, changedetails.scheduledendtime, changedetails.completedtime, changedetails.notespresent, changedetails.siteid, changedetails.groupid, changedetails.templateid, changedetails.wfid, changedetails.wfstageid, changedetails.wfstatusid, changedetails.isemergency, changedetails.isretrospective, changedetails.reasonforchangeid, changedetails.closurecodeid, changedetails.changemanagerid, changedetails.riskid, changedetails.impactid, changedetails.slaid, changedetails.isoverdue
Buffers: shared hit=1
Planning time: 1.058 ms
Execution time: 0.066 ms
(8 rows)
-- end --
From the above result, it is clear that the query execution is very fast but planning time is high in the first run (468.239 ms).
I am not using prepared statements. Postgres documentation and previous questions in the pgsql-performance mailing list mention that the query plan is cached only when prepared statements are used.
https://www.postgresql.org/message-id/15600.1346885470%40sss.pgh.pa.us
I am not using prepared statements. Postgres documentation and previous questions in the pgsql-performance mailing list mention that the query plan is cached only when prepared statements are used.
https://www.postgresql.org/message-id/15600.1346885470%40sss.pgh.pa.us
In the above thread Tom Lane mentions that the plan is never cached for raw queries. Yet, this is exactly what seems to be happening in my case. Am I missing something? Please let me know how I can make sure the query execution for the first time is fast too.
Thanks and regards,
Nanda
