Re: High consistent Gets and response time in prod

From: Sayan Malakshinov <xt.and.r_at_gmail.com>
Date: Sat, 1 May 2021 03:07:35 +0300
Message-ID: <CAOVevU7nD-9ocw70eLWXH6GfqxjLJ4n_xQVG508Cq3SBFYhjNA_at_mail.gmail.com>



Oh, sorry, I've just re-read it carefully (it's 3am here and looks like my brain is too tired :)
1. rownum disables adaptive serial direct path reads, so you don't need to care about them
2. index access may not help you in case of lots of uncommitted changes in those long-running transactions (depends on what exactly were changed and how many times)

So it would be better to provide session snapper output and check those long-running sessions and v$transaction

On Sat, May 1, 2021 at 2:55 AM Sayan Malakshinov <xt.and.r_at_gmail.com> wrote:

> Hi Ram,
>
> 11.5M blocks
>
>
> Most likely there were massive deletes and you have a lot of empty blocks.
> Anyway I wouldn't guess and suggest you just start your query and run
> Tanel Poder's session snapper on your session for 5-10 seconds to get real
> info what's going on:
> https://tanelpoder.com/snapper/
> And just post its output here.
> It doesn't require nor diagnostics nor tuning packs.
> Anyway for such a strange query, I would suggest forcing IFS by primary
> key index, to avoid "adaptive serial direct path reads" which lead to
> object checkpoint. for example using SQL Patch which also doesn't require
> those packs.
>
> On Sat, May 1, 2021 at 2:36 AM John Piwowar <jpiwowar_at_gmail.com> wrote:
>
>> You'll probably get better info from dbms_monitor and tkprof than
>> autotrace, but I think your main culprit/clue is the combination of high
>> consistent gets and "parallel queries running against the prod table for
>> 30+ hours." Depending on what those PQ are doing, you are likely to be
>> hitting UNDO pretty hard to get a read-consistent view of even one row.
>>
>> On Fri, Apr 30, 2021 at 3:39 PM Ram Raman <veeeraman_at_gmail.com> wrote:
>>
>>> Hi,
>>>
>>> Fri evening and I have a problem. grrr..
>>>
>>> We have a simple SELECT statement like this:
>>>
>>> select * from c.pd where rownum <=1
>>>
>>> This executes instantly in test, but takes over 2 mins in prod. I did
>>> some autotrace and here are some stats:
>>>
>>> TEST:
>>> =====
>>> ...
>>> Elapsed: 00:00:00.03
>>>
>>> Execution Plan
>>> ----------------------------------------------------------
>>> Plan hash value: 1087134000
>>>
>>>
>>> ---------------------------------------------------------------------------------
>>> | Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
>>> Time |
>>>
>>> ---------------------------------------------------------------------------------
>>> | 0 | SELECT STATEMENT | | 1 | 983 | 2 (0)|
>>> 00:00:01 |
>>> |* 1 | COUNT STOPKEY | | | | |
>>> |
>>> | 2 | TABLE ACCESS FULL| PD | 1 | 983 | 2 (0)| 00:00:01
>>> |
>>>
>>> ---------------------------------------------------------------------------------
>>>
>>> Predicate Information (identified by operation id):
>>> ---------------------------------------------------
>>>
>>> 1 - filter(ROWNUM<=1)
>>>
>>>
>>> Statistics
>>> ----------------------------------------------------------
>>> 0 recursive calls
>>> 0 db block gets
>>> 3 consistent gets
>>> 0 physical reads
>>> 0 redo size
>>> 8556 bytes sent via SQL*Net to client
>>> 408 bytes received via SQL*Net from client
>>> 2 SQL*Net roundtrips to/from client
>>> 0 sorts (memory)
>>> 0 sorts (disk)
>>> 1 rows processed
>>>
>>>
>>> PROD:
>>> =====
>>>
>>> ...
>>> Elapsed: 00:02:13.61
>>>
>>> Execution Plan
>>> ----------------------------------------------------------
>>> Plan hash value: 1087134000
>>>
>>>
>>> ---------------------------------------------------------------------------------
>>> | Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
>>> Time |
>>>
>>> ---------------------------------------------------------------------------------
>>> | 0 | SELECT STATEMENT | | 1 | 993 | 4 (0)|
>>> 00:00:01 |
>>> |* 1 | COUNT STOPKEY | | | | |
>>> |
>>> | 2 | TABLE ACCESS FULL| PD | 1 | 993 | 4 (0)| 00:00:01
>>> |
>>>
>>> ---------------------------------------------------------------------------------
>>>
>>> Predicate Information (identified by operation id):
>>> ---------------------------------------------------
>>>
>>> 1 - filter(ROWNUM<=1)
>>>
>>>
>>> Statistics
>>> ----------------------------------------------------------
>>> 0 recursive calls
>>> 0 db block gets
>>> 11290619 consistent gets
>>> 11289575 physical reads
>>> 8024 redo size
>>> 8510 bytes sent via SQL*Net to client
>>> 408 bytes received via SQL*Net from client
>>> 2 SQL*Net roundtrips to/from client
>>> 0 sorts (memory)
>>> 0 sorts (disk)
>>> 1 rows processed
>>>
>>>
>>> First thing that jumps out is the number of consistent gets, which is in
>>> the same range in prod again and again. In test also, the consistent gets
>>> are in the same range for repeated executions - just couple of dozens.
>>>
>>> I checked the stats and here they are:
>>>
>>> Test:
>>> =====
>>>
>>> TABLE_NAME NUM_ROWS LAST_ANAL BLOCKS
>>> AVG_ROW_LEN PCT_FREE PCT_USED EMPTY_BLOCKS AVG_SPACE
>>> ------------------------ ------------------------ --------- ------------
>>> ----------- ---------- ---------- ------------ ----------
>>> CHAIN_CNT PAR MON COMPRESS
>>> ---------- --- --- --------
>>> PD 989,633 25-FEB-21 143,844
>>> 983 10 0 0
>>> 0 NO YES DISABLED
>>>
>>>
>>>
>>> PROD:
>>> =====
>>>
>>> TABLE_NAME NUM_ROWS LAST_ANAL BLOCKS
>>> AVG_ROW_LEN PCT_FREE PCT_USED EMPTY_BLOCKS AVG_SPACE
>>> ------------------------ ------------------------ --------- ------------
>>> ----------- ---------- ---------- ------------ ----------
>>> CHAIN_CNT PAR MON COMPRESS
>>> ---------- --- --- --------
>>> PD 1,420,080 29-APR-21 11,537,288
>>> 993 10 0 0
>>> 0 NO YES DISABLED
>>>
>>> What is confusing is that the number of blocks the table takes in the
>>> prod. I did some calc and I feel that it should take around 172,000+
>>> blocks, given our block size is 8K, but I am unable to explain 11.5M
>>> blocks.
>>>
>>> 19c, if that helps. Table definitions are identical in prod and test.
>>> Recollecting the table stats in prod at 50% has not helped with the query
>>> which I did few minutes ago. Stats almost remain the same - just the number
>>> of rows has increased by a few hundred. I see some parallel queries
>>> running against the prod table for 30+ hours.
>>>
>>> Thanks a lot,
>>> Ram.
>>>
>>>
>>>
>
> --
> Best regards,
> Sayan Malakshinov
> Oracle performance tuning engineer
> Oracle ACE Associate
> http://orasql.org
>

-- 
Best regards,
Sayan Malakshinov
Oracle performance tuning engineer
Oracle ACE Associate
http://orasql.org

--
http://www.freelists.org/webpage/oracle-l
Received on Sat May 01 2021 - 02:07:35 CEST

Original text of this message