Content-Type: multipart/alternative;
 boundary="------------BiKYLLcGJKM5TsW7NUIsfodp"
Message-ID: <f4680777-8023-6627-bd23-98563b6512e2@gmail.com>
Date: Thu, 2 Feb 2023 12:57:04 -0600
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101
 Thunderbird/102.4.2
Subject: Re: too high planning time
Content-Language: en-US
To: pgsql-admin@lists.postgresql.org
References: 
 <CAC0w7LKjDd16T80CYejmMrht1Ddjcf1P8jg1POdH=RyRxCHLXA@mail.gmail.com>
 <1536295.1675351465@sss.pgh.pa.us>
 <CAC0w7LKLV5XV=dW-9Y4g2Tezq+aBnSa5Gz6GKrHf_gdf1kG7Gg@mail.gmail.com>
From: Ron <ronljohnsonjr@gmail.com>
In-Reply-To: 
 <CAC0w7LKLV5XV=dW-9Y4g2Tezq+aBnSa5Gz6GKrHf_gdf1kG7Gg@mail.gmail.com>
Archived-At: 
 <https://www.postgresql.org/message-id/f4680777-8023-6627-bd23-98563b6512e2%40gmail.com>
Precedence: bulk

This is a multi-part message in MIME format.
--------------BiKYLLcGJKM5TsW7NUIsfodp
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit

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.
--------------BiKYLLcGJKM5TsW7NUIsfodp
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: 8bit

<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
  </head>
  <body>
    pg_stat_activity is the place to look.<br>
    <br>
    This tells you all of the blocked pids:<br>
    <font face="monospace">SELECT pid<br>
           , username<br>
           , pg_blocking_pids(pid) AS blocked_by<br>
           , left(query, 100) as blocked_query<br>
      FROM pg_stat_activity<br>
      WHERE CARDINALITY(blocking_pids(pid)) &gt; 0;<br>
    </font><br>
    From there, you can see what the blocking pid is doing.<br>
    <br>
    <div class="moz-cite-prefix">On 2/2/23 12:21, Kenny Bachman wrote:<br>
    </div>
    <blockquote type="cite"
cite="mid:CAC0w7LKLV5XV=dW-9Y4g2Tezq+aBnSa5Gz6GKrHf_gdf1kG7Gg@mail.gmail.com">
      <meta http-equiv="content-type" content="text/html; charset=UTF-8">
      <div dir="ltr">In fact, when I run the query for the second time,
        it returns very fast results. But after a while the problem
        reoccurs.
        <div>Not just for these queries, but almost all queries in the
          database are slowed down this way. <br>
        </div>
        <div>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?<br>
        </div>
        <div><br>
        </div>
        <div>thanks a lot for your comments and help</div>
        <div>Kenny</div>
      </div>
      <br>
      <div class="gmail_quote">
        <div dir="ltr" class="gmail_attr">Tom Lane &lt;<a
            href="mailto:tgl@sss.pgh.pa.us" moz-do-not-send="true"
            class="moz-txt-link-freetext">tgl@sss.pgh.pa.us</a>&gt;, 2
          Şub 2023 Per, 18:24 tarihinde şunu yazdı:<br>
        </div>
        <blockquote class="gmail_quote" style="margin:0px 0px 0px
          0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Kenny
          Bachman &lt;<a href="mailto:kenny.bachman17@gmail.com"
            target="_blank" moz-do-not-send="true"
            class="moz-txt-link-freetext">kenny.bachman17@gmail.com</a>&gt;
          writes:<br>
          &gt; EXPLAIN ANALYZE select<br>
          &gt;     i."DefinitionId",<br>
          &gt; from<br>
          &gt;     "T_WF_INSTANCE" i<br>
          &gt; where<br>
          &gt;     i."InstanceId" = 10045683193;<br>
          <br>
          &gt;        QUERY PLAN<br>
          <br>
          &gt;
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------<br>
          &gt;  Index Scan using<br>
          &gt;
          "T_WF_INSTANCE_InstanceId_ApplicationCd_EntityStatusCd_idx" on<br>
          &gt; "T_WF_INSTANCE" i  (cost=0.57..2.79 rows=1 width=34)
          (actual<br>
          &gt; time=2.522..2.522 rows=1 loops=1)<br>
          &gt;    Index Cond: ("InstanceId" = '10045683193'::bigint)<br>
          <br>
          &gt; * Planning Time: 8460.446 ms Execution Time: 2.616 ms*<br>
          &gt; (4 rows)<br>
          <br>
          It's hard to believe that such a simple query could take that<br>
          long to plan.  What I'm wondering is if the planner got
          blocked<br>
          on some other session's exclusive lock.  Not a lock on<br>
          "T_WF_INSTANCE" itself, because we'd have got that lock during<br>
          parsing before the "Planning Time" measurement starts.  But<br>
          there's going to be a physical access to the table's index<br>
          to determine its tree height, so an ex-lock on the index could<br>
          explain this.  Or an ex-lock on catalogs, particularly
          pg_statistic.<br>
          What else is going on in your database when this happens?<br>
          <br>
                                  regards, tom lane<br>
        </blockquote>
      </div>
    </blockquote>
    <br>
    <div class="moz-signature">-- <br>
      Born in Arizona, moved to Babylonia.</div>
  </body>
</html>

--------------BiKYLLcGJKM5TsW7NUIsfodp--