Обсуждение: [GENERAL] How to evaluate "explain analyze" correctly after "explain" for thesame statement ?

Поиск
Список
Период
Сортировка

[GENERAL] How to evaluate "explain analyze" correctly after "explain" for thesame statement ?

От
Patrick B
Дата:
Hi all,

I just got a quick question about warm-cache. I'm using PG 9.2.

When I execute this statement soon after I start/restart the database:

explain select id from test where id = 124;

The runtime is 40ms.

Then, If I execute this statement just after the above one;

explain analyze select id from test where id = 124;

The runtime is 0.8ms.

Probably the statement is cached, right?


So, I do (To clear the cache):

  • service postgresql stop
  • echo 3 > /proc/sys/vm/drop_caches
  • service postgresql start
But, then, executing the statement again, it runs in 0.8 ms. 

How can I clean the cache to get the REAL runtime for that statement?
Thanks
Patrick

Re: [GENERAL] How to evaluate "explain analyze" correctly after"explain" for the same statement ?

От
Steve Atkins
Дата:
> On Feb 15, 2017, at 3:58 PM, Patrick B <patrickbakerbr@gmail.com> wrote:
>
> Hi all,
>
> I just got a quick question about warm-cache. I'm using PG 9.2.
>
> When I execute this statement soon after I start/restart the database:
>
> explain select id from test where id = 124;
>
> The runtime is 40ms.
>
> Then, If I execute this statement just after the above one;
>
> explain analyze select id from test where id = 124;
>
> The runtime is 0.8ms.

This doesn't make seem to make sense.

"explain select ..." doesn't run the query. All it shows is the plan the planner chose and some estimates of the "cost"
ofdifferent steps, with no time. Where are you getting 40ms from in this case? 

"explain analyze select ..." does run the query, along with some - potentially non-trivial - instrumentation to measure
eachstep of the plan, so you can see whether the planner estimates are reasonable or wildly off. 

Cheers,
  Steve



Re: [GENERAL] How to evaluate "explain analyze" correctly after"explain" for the same statement ?

От
Patrick B
Дата:


2017-02-16 13:25 GMT+13:00 Steve Atkins <steve@blighty.com>:

> On Feb 15, 2017, at 3:58 PM, Patrick B <patrickbakerbr@gmail.com> wrote:
>
> Hi all,
>
> I just got a quick question about warm-cache. I'm using PG 9.2.
>
> When I execute this statement soon after I start/restart the database:
>
> explain select id from test where id = 124;
>
> The runtime is 40ms.
>
> Then, If I execute this statement just after the above one;
>
> explain analyze select id from test where id = 124;
>
> The runtime is 0.8ms.

This doesn't make seem to make sense.

"explain select ..." doesn't run the query. All it shows is the plan the planner chose and some estimates of the "cost" of different steps, with no time. Where are you getting 40ms from in this case?

From my DB-VISUALIZER - it shows how long the query took.
 

"explain analyze select ..." does run the query, along with some - potentially non-trivial - instrumentation to measure each step of the plan, so you can see whether the planner estimates are reasonable or wildly off.


Well.. that is what's happening.

For the first time I ran the query, it took >10 seconds. Now it is taking less than a second.
How can I clear for good the cache? So i can have a real idea of how long the query takes to run?


 

Patrick B <patrickbakerbr@gmail.com> writes:
> For the first time I ran the query, it took >10 seconds. Now it is taking
> less than a second.
> How can I clear for good the cache? So i can have a real idea of how long
> the query takes to run?

TBH, I think you're probably obsessing over the wrong thing.  It's
highly unlikely that cache effects would be sufficient to explain
a 10-second runtime for a query that otherwise takes less than 1 msec.
What seems more likely is that the query was waiting on a lock, or
something else that created a non-cache-related bottleneck.

Also, I think you're coming at things from completely the wrong direction
if you believe that the worst-case, nothing-in-any-level-of-cache case
is the "true" runtime.  Most people who are worried about performance
spend a great deal of effort ensuring that that case doesn't happen to
them in practice.  As an example, the first few queries in a fresh
session will almost always run slower than later queries, because it
takes some time to ramp up the new backend's local catalog caches to have
all the useful data in them.  But the correct response to that observation
is to try to make sure your sessions last awhile and execute many queries,
not to decide that the uncached state is the "true" runtime.  It's only
representative if you're intentionally shooting yourself in the foot.

            regards, tom lane


Re: [GENERAL] How to evaluate "explain analyze" correctly after"explain" for the same statement ?

От
Patrick B
Дата:
2017-02-16 14:08 GMT+13:00 Tom Lane <tgl@sss.pgh.pa.us>:
Patrick B <patrickbakerbr@gmail.com> writes:
> For the first time I ran the query, it took >10 seconds. Now it is taking
> less than a second.
> How can I clear for good the cache? So i can have a real idea of how long
> the query takes to run?

TBH, I think you're probably obsessing over the wrong thing.  It's
highly unlikely that cache effects would be sufficient to explain
a 10-second runtime for a query that otherwise takes less than 1 msec.
What seems more likely is that the query was waiting on a lock, or
something else that created a non-cache-related bottleneck.

Also, I think you're coming at things from completely the wrong direction
if you believe that the worst-case, nothing-in-any-level-of-cache case
is the "true" runtime.  Most people who are worried about performance
spend a great deal of effort ensuring that that case doesn't happen to
them in practice.  As an example, the first few queries in a fresh
session will almost always run slower than later queries, because it
takes some time to ramp up the new backend's local catalog caches to have
all the useful data in them.  But the correct response to that observation
is to try to make sure your sessions last awhile and execute many queries,
not to decide that the uncached state is the "true" runtime.  It's only
representative if you're intentionally shooting yourself in the foot.

                        regards, tom lane


I've got two different scenarios:

Production database server > PG 9.2
  • I ran one single time, in a slave server that no queries go to that server, and it took >10 seconds.
Test database server > PG 9.2
  • This is the server that I'm working on. When I ran the query here for the first time, it also took >10 seconds. And it is not a LOCK as no one was/is using this database server. (using explain analyze)
  • When I ran the query for the second time (using explain analyze), it took 1 second to run.
  • On the third time, it took < than 1 second.
  • This server I can reboot the machine/PG or stop/start Postgres Process.
  • I've already done: service postgresql stop; 
    sync; echo 3 > /proc/sys/vm/drop_caches; service postgresql start

I've made some changes to the query and would like to get its real runtime so I can compare and keep working if I need to.

The question is:

How can I clear the cache, to get a real good estimation of how much the query is taking to run?

P.

Re: [GENERAL] How to evaluate "explain analyze" correctly after"explain" for the same statement ?

От
Patrick B
Дата:
2017-02-16 14:57 GMT+13:00 Patrick B <patrickbakerbr@gmail.com>:
I've got two different scenarios:

Production database server > PG 9.2
  • I ran one single time, in a slave server that no queries go to that server, and it took >10 seconds.
Test database server > PG 9.2
  • This is the server that I'm working on. When I ran the query here for the first time, it also took >10 seconds. And it is not a LOCK as no one was/is using this database server. (using explain analyze)
  • When I ran the query for the second time (using explain analyze), it took 1 second to run.
  • On the third time, it took < than 1 second.
  • This server I can reboot the machine/PG or stop/start Postgres Process.
  • I've already done: service postgresql stop; 
    sync; echo 3 > /proc/sys/vm/drop_caches; service postgresql start

I've made some changes to the query and would like to get its real runtime so I can compare and keep working if I need to.

The question is:

How can I clear the cache, to get a real good estimation of how much the query is taking to run?

P.


BTW

          ->  Index Only Scan Backward using ix_geo_time_end_user on geo mg  (cost=0.00..7369.78 rows=24149 width=8) (actual time=0.020..0.020 rows=0 loops=1)

one of the reasons the query is too expensive... the index has 6GB.