pg.ddx.io pgsql-admin@postgresql.org mailing list archive
help / color / mirror / Atom feedtoo high planning time
4+ messages / 3 participants
[nested] [flat]
* too high planning time
@ 2023-02-02 09:54 Kenny Bachman <kenny.bachman17@gmail.com>
0 siblings, 1 reply; 4+ messages in thread
From: Kenny Bachman @ 2023-02-02 09:54 UTC (permalink / raw)
To: Pgsql-admin <pgsql-admin@lists.postgresql.org>
Hello Team,
I have a problem with the explain analyze' output of some queries. There is
too high planning time, but the execution time is relatively low. What is
the possible reason behind this problem? I also ran the vacuum and analyze
commands for the table.
EXPLAIN ANALYZE select
i."DefinitionId",
from
"T_WF_INSTANCE" i
where
i."InstanceId" = 10045683193;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Index Scan using
"T_WF_INSTANCE_InstanceId_ApplicationCd_EntityStatusCd_idx" on
"T_WF_INSTANCE" i (cost=0.57..2.79 rows=1 width=34) (actual
time=2.522..2.522 rows=1 loops=1)
Index Cond: ("InstanceId" = '10045683193'::bigint)
* Planning Time: 8460.446 ms Execution Time: 2.616 ms*
(4 rows)
Thank you,
Kenny
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: too high planning time
@ 2023-02-02 15:24 Tom Lane <tgl@sss.pgh.pa.us>
parent: Kenny Bachman <kenny.bachman17@gmail.com>
0 siblings, 1 reply; 4+ messages in thread
From: Tom Lane @ 2023-02-02 15:24 UTC (permalink / raw)
To: Kenny Bachman <kenny.bachman17@gmail.com>; +Cc: Pgsql-admin <pgsql-admin@lists.postgresql.org>
Kenny Bachman <kenny.bachman17@gmail.com> writes:
> EXPLAIN ANALYZE select
> i."DefinitionId",
> from
> "T_WF_INSTANCE" i
> where
> i."InstanceId" = 10045683193;
> QUERY PLAN
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> Index Scan using
> "T_WF_INSTANCE_InstanceId_ApplicationCd_EntityStatusCd_idx" on
> "T_WF_INSTANCE" i (cost=0.57..2.79 rows=1 width=34) (actual
> time=2.522..2.522 rows=1 loops=1)
> Index Cond: ("InstanceId" = '10045683193'::bigint)
> * Planning Time: 8460.446 ms Execution Time: 2.616 ms*
> (4 rows)
It's hard to believe that such a simple query could take that
long to plan. What I'm wondering is if the planner got blocked
on some other session's exclusive lock. Not a lock on
"T_WF_INSTANCE" itself, because we'd have got that lock during
parsing before the "Planning Time" measurement starts. But
there's going to be a physical access to the table's index
to determine its tree height, so an ex-lock on the index could
explain this. Or an ex-lock on catalogs, particularly pg_statistic.
What else is going on in your database when this happens?
regards, tom lane
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: too high planning time
@ 2023-02-02 18:21 Kenny Bachman <kenny.bachman17@gmail.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 4+ messages in thread
From: Kenny Bachman @ 2023-02-02 18:21 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Pgsql-admin <pgsql-admin@lists.postgresql.org>
In fact, when I run the query for the second time, it returns very fast
results. But after a while the problem reoccurs.
Not just for these queries, but almost all queries in the database are
slowed down this way.
Is it normal to have a lock on the catalog or system tables? What should I
do when this happens on pg_statistic or other catalogs?
thanks a lot for your comments and help
Kenny
Tom Lane <tgl@sss.pgh.pa.us>, 2 Şub 2023 Per, 18:24 tarihinde şunu yazdı:
> Kenny Bachman <kenny.bachman17@gmail.com> writes:
> > EXPLAIN ANALYZE select
> > i."DefinitionId",
> > from
> > "T_WF_INSTANCE" i
> > where
> > i."InstanceId" = 10045683193;
>
> > QUERY PLAN
>
> >
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> > Index Scan using
> > "T_WF_INSTANCE_InstanceId_ApplicationCd_EntityStatusCd_idx" on
> > "T_WF_INSTANCE" i (cost=0.57..2.79 rows=1 width=34) (actual
> > time=2.522..2.522 rows=1 loops=1)
> > Index Cond: ("InstanceId" = '10045683193'::bigint)
>
> > * Planning Time: 8460.446 ms Execution Time: 2.616 ms*
> > (4 rows)
>
> It's hard to believe that such a simple query could take that
> long to plan. What I'm wondering is if the planner got blocked
> on some other session's exclusive lock. Not a lock on
> "T_WF_INSTANCE" itself, because we'd have got that lock during
> parsing before the "Planning Time" measurement starts. But
> there's going to be a physical access to the table's index
> to determine its tree height, so an ex-lock on the index could
> explain this. Or an ex-lock on catalogs, particularly pg_statistic.
> What else is going on in your database when this happens?
>
> regards, tom lane
>
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: too high planning time
@ 2023-02-02 18:57 Ron <ronljohnsonjr@gmail.com>
parent: Kenny Bachman <kenny.bachman17@gmail.com>
0 siblings, 0 replies; 4+ messages in thread
From: Ron @ 2023-02-02 18:57 UTC (permalink / raw)
To: pgsql-admin@lists.postgresql.org
pg_stat_activity is the place to look.
This tells you all of the blocked pids:
SELECT pid
, username
, pg_blocking_pids(pid) AS blocked_by
, left(query, 100) as blocked_query
FROM pg_stat_activity
WHERE CARDINALITY(blocking_pids(pid)) > 0;
From there, you can see what the blocking pid is doing.
On 2/2/23 12:21, Kenny Bachman wrote:
> In fact, when I run the query for the second time, it returns very fast
> results. But after a while the problem reoccurs.
> Not just for these queries, but almost all queries in the database are
> slowed down this way.
> Is it normal to have a lock on the catalog or system tables? What should I
> do when this happens on pg_statistic or other catalogs?
>
> thanks a lot for your comments and help
> Kenny
>
> Tom Lane <tgl@sss.pgh.pa.us>, 2 Şub 2023 Per, 18:24 tarihinde şunu yazdı:
>
> Kenny Bachman <kenny.bachman17@gmail.com> writes:
> > EXPLAIN ANALYZE select
> > i."DefinitionId",
> > from
> > "T_WF_INSTANCE" i
> > where
> > i."InstanceId" = 10045683193;
>
> > QUERY PLAN
>
> >
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> > Index Scan using
> > "T_WF_INSTANCE_InstanceId_ApplicationCd_EntityStatusCd_idx" on
> > "T_WF_INSTANCE" i (cost=0.57..2.79 rows=1 width=34) (actual
> > time=2.522..2.522 rows=1 loops=1)
> > Index Cond: ("InstanceId" = '10045683193'::bigint)
>
> > * Planning Time: 8460.446 ms Execution Time: 2.616 ms*
> > (4 rows)
>
> It's hard to believe that such a simple query could take that
> long to plan. What I'm wondering is if the planner got blocked
> on some other session's exclusive lock. Not a lock on
> "T_WF_INSTANCE" itself, because we'd have got that lock during
> parsing before the "Planning Time" measurement starts. But
> there's going to be a physical access to the table's index
> to determine its tree height, so an ex-lock on the index could
> explain this. Or an ex-lock on catalogs, particularly pg_statistic.
> What else is going on in your database when this happens?
>
> regards, tom lane
>
--
Born in Arizona, moved to Babylonia.
^ permalink raw reply [nested|flat] 4+ messages in thread
end of thread, other threads:[~2023-02-02 18:57 UTC | newest]
Thread overview: 4+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-02-02 09:54 too high planning time Kenny Bachman <kenny.bachman17@gmail.com>
2023-02-02 15:24 ` Tom Lane <tgl@sss.pgh.pa.us>
2023-02-02 18:21 ` Kenny Bachman <kenny.bachman17@gmail.com>
2023-02-02 18:57 ` Ron <ronljohnsonjr@gmail.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox