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

Поиск

Список

Период

Сортировка

От	Nandakumar M
Тема	Query is slow when run for first time; subsequent execution is fast
Дата	10 января 2018 г. 17:59:50
Msg-id	CANcFUu4e1zZQCvt9rjQGNUFV-kxv7F8Somk5Zgq2tXCO9dZhDg@mail.gmail.com обсуждение исходный текст
Ответы	Re: Query is slow when run for first time; subsequent execution is fast (Jeff Janes <jeff.janes@gmail.com>)
Список	pgsql-performance

Дерево обсуждения

Hello,

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.

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.

-- 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=#

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)

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

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

В списке pgsql-performance по дате отправления:

Предыдущее

От: Laurenz Albe
Дата: 10 января 2018 г., 16:41:04
Сообщение: Re: View preformance oracle to postgresql

Следующее

От: Dinesh Chandra 12108
Дата: 10 января 2018 г., 18:42:24
Сообщение: RE: Re: Unable to connect Postgres using psql while postgres is alreadyrunning.

Вход в личный кабинет

Восстановление пароля

Подтверждение аккаунта

Изменение пароля

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

Предыдущее

Следующее