Re: Query with same plan running longer
From: Lok P <loknath.73_at_gmail.com>
Date: Tue, 1 Mar 2022 00:34:35 +0530
Message-ID: <CAKna9VaaWbW=XFrQ2ZpXJTdH=a-8u+LAJQVWDZzXtMstXwwPww_at_mail.gmail.com>
| 16 | 6.27 | 10 | 0.18 | 0.09 | 18 | 26M |
201K | 196GB | 195GB | 196GB | 96MB | 99.95% |
| Name | Type | Server# | Elapsed | Cpu | IO |
Application | Other | Buffer | Read | Read | Uncompressed | Offload
| Offload | Cell | Wait Events |
| | | | Time(s) | Time(s) | Waits(s) |
| Id | Operation | Name
| Rows | Cost | Time | Start | Execs | Rows | Read | Read |
Date: Tue, 1 Mar 2022 00:34:35 +0530
Message-ID: <CAKna9VaaWbW=XFrQ2ZpXJTdH=a-8u+LAJQVWDZzXtMstXwwPww_at_mail.gmail.com>
The plan which I posted earlier was from dba_hist_reports. And currently
when we run the query , the same plan is not doing ~90%+ cell offloading
and running for 2minutes+. However, I just tried with parallel(2) hints and
surprisingly the plan is almost the same but now cell offloading percent
increased to ~99% and the query was finished in quick time.How is that
happening? We have recently migrated our tablespaces to TDE , can that
cause such an issue?
Global Information
Global Stats
Status : DONE (ALL ROWS)
Instance ID : 1
SQL Execution ID : 16777217
Execution Started : 02/28/2022 04:32:47
First Refresh Time : 02/28/2022 04:32:48
Last Refresh Time : 02/28/2022 04:32:57
Duration : 10s
Module/Action : SQL*Plus/-
Program : sqlplus.exe
Fetch Calls : 18
| Elapsed | Cpu | IO | Application | Other | Fetch | Buffer |
Read | Read | Uncompressed | Offload | Offload | Cell |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Calls | Gets |
Reqs | Bytes | Bytes | Elig Bytes | Returned Bytes | Offload |
| 16 | 6.27 | 10 | 0.18 | 0.09 | 18 | 26M |
201K | 196GB | 195GB | 196GB | 96MB | 99.95% |
Parallel Execution Details (DOP=2 , Servers Allocated=4)
| Name | Type | Server# | Elapsed | Cpu | IO |
Application | Other | Buffer | Read | Read | Uncompressed | Offload
| Offload | Cell | Wait Events |
| | | | Time(s) | Time(s) | Waits(s) |
Waits(s) | Waits(s) | Gets | Reqs | Bytes | Bytes | Elig Bytes
| Returned Bytes | Offload | (sample #) |
========================================================================================================================================================================================================
| PX Coordinator | QC | | 0.47 | 0.20 | |
0.18 | 0.09 | 63 | | . | . | . | . | NaN% | |
| p000 | Set 1 | 1 | 7.66 | 2.75 | 4.91 |
| | 13M | 99612 | 97GB | 97GB | 97GB | 55MB | 99.94% | cell smart table scan (3) |
| p001 | Set 1 | 2 | 7.89 | 2.89 | 5.00 |
| | 13M | 101K | 99GB | 98GB | 99GB | 41MB | 99.96% | cell smart table scan (6) |
| p002 | Set 2 | 1 | 0.22 | 0.22 | 0.00 |
| | 10757 | | . | . | . | . | NaN% | |
| p003 | Set 2 | 2 | 0.21 | 0.21 | 0.00 |
| | 12026 | | . | . | . | . | NaN% | | ========================================================================================================================================================================================================
SQL Plan Monitoring Details (Plan Hash Value=70366485)
| Id | Operation | Name
| Rows | Cost | Time | Start | Execs | Rows | Read | Read |
Mem | Activity | Activity Detail |
| | |
| (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | (Max) | (%) | (# samples) | =====================================================================================================================================================================================================
| 0 | SELECT STATEMENT |
| | | 3 | +8 | 1 | 83472 | | | . | | |
| 1 | SORT ORDER BY |
| 3883 | 2M | 3 | +8 | 1 | 83472 | | | 13MB | | |
| 2 | COUNT STOPKEY |
| | | 1 | +8 | 1 | 83472 | | | . | | |
| 3 | PX COORDINATOR |
| | | 1 | +8 | 5 | 83472 | | | . | | |
| 4 | PX SEND QC (RANDOM) | :TQ10002
| 3883 | 2M | 1 | +8 | 2 | 83472 | | | . | | |
| 5 | COUNT STOPKEY |
| | | 1 | +8 | 2 | 83472 | | | . | | |
| 6 | HASH JOIN |
| 3883 | 2M | 1 | +8 | 2 | 83472 | | | 41MB | 6.67 | Cpu (1) |
| 7 | PX RECEIVE |
| 3808 | 2M | 1 | +8 | 2 | 167K | | | . | | |
| 8 | PX SEND BROADCAST | :TQ10001
| 3808 | 2M | 1 | +8 | 2 | 167K | | | . | | |
| 9 | HASH JOIN |
| 3808 | 2M | 6 | +3 | 2 | 83472 | | | 36MB | | |
| 10 | JOIN FILTER CREATE | :BF0000
| 3815 | 2M | 6 | +3 | 2 | 167K | | | . | | |
| 11 | PX RECEIVE |
| 3815 | 2M | 6 | +3 | 2 | 167K | | | . | | |
| 12 | PX SEND BROADCAST | :TQ10000
| 3815 | 2M | 7 | +2 | 2 | 167K | | | . | 6.67 | Cpu (1) |
| 13 | PX BLOCK ITERATOR |
| 3815 | 2M | 6 | +3 | 2 | 83472 | | | . | | |
| 14 | TABLE ACCESS STORAGE FULL | TAB1
| 3815 | 2M | 8 | +1 | 535 | 83472 | 201K | 196GB | 14MB | 80.00 | Cpu (3) |
| | |
| | | | | | | | | | | cell smart table scan (9) |
| 15 | JOIN FILTER USE | :BF0000
| 2M | 1791 | 1 | +8 | 2 | 10942 | | | . | | |
| 16 | PX BLOCK ITERATOR |
| 2M | 1791 | 1 | +8 | 2 | 10942 | | | . | | |
| 17 | TABLE ACCESS STORAGE FULL | TD
| 2M | 1791 | 1 | +8 | 37 | 10942 | | | . | | |
| 18 | PX BLOCK ITERATOR |
| 959K | 249 | 1 | +8 | 2 | 959K | | | . | | |
| 19 | INDEX STORAGE FAST FULL SCAN | TD_IX1
| 959K | 249 | 1 | +8 | 25 | 959K | | | . | 6.67 | Cpu (1) | =====================================================================================================================================================================================================
On Tue, Mar 1, 2022 at 12:12 AM Lok P <loknath.73_at_gmail.com> wrote:
> Its version 19.9 of oracle. We are seeing suddenly a query taking longer
> even is using same path and looking into the sql monitor report from past
> it shows the cell offloading percentage has been dropped from ~98% to
> ~56%. Want to understand the cause behind this and how to fix it?
>
> Below is the sql monitor for this and majority of time is on step-6 i.e
> full scan of TAB1 , however the read request , read bytes all seems to be
> the same but still there is a big difference in the offloading percentage.
> When I run the query manually and peek into the v$sesstat seeing below
> output from that.
>
> SELECT .....
> FROM TAB1 , TD , CMC
> WHERE ROWNUM <= 100000
> AND TAB1.TDN = td.DID
> AND TAB1.CO_ID = CMC.PME
> AND 1 = 1
> AND ATI IN ('XXXXX')
> AND ( ( ( ( IDR = 'Y' AND TRUNC (SYSDATE) - 15 > I_DT)
> OR IDR = 'N')
> AND PCSC IN ('CR', 'CC', 'CA', 'CI1', 'CR1',
> 'CC2', 'CC3', 'CI4'))
> OR (PCSC IN ('CC1', 'CI', 'CA1', 'CI2', 'CR2',
> 'CC4', 'CA2', 'CI3'))
> OR ( ( ( IDR = 'Y' AND TRUNC (SYSDATE) - 15 > I_DT)
> OR IDR = 'N') AND PCSC IN ('CI4', 'CI5') AND S_DT < TRUNC (SYSDATE))
> OR ( PCSC IN ('CI6', 'CI7') AND S_DT < TRUNC (SYSDATE)))
> AND ( D_DT > SYSDATE - 120 OR (IDR = 'N' AND D_DT IS NULL))
> ORDER BY D_DT ASC, S_AMT DESC
>
> *********** Slow execution *****************
>
> Global Information
> ------------------------------
> Status : DONE (ALL ROWS)
> Instance ID : 1
> Execution Started : 02/26/2022 06:58:23
> First Refresh Time : 02/26/2022 06:58:27
> Last Refresh Time : 02/26/2022 07:00:40
> Duration : 137s
> Module/Action : JDBC Thin Client/-
> Program : JDBC Thin Client
> Fetch Calls : 3877
>
> Global Stats
>
> =====================================================================================================================================
> | Elapsed | Cpu | IO | Application | Fetch | Buffer | Read |
> Read | Uncompressed | Offload | Offload | Cell |
> | Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs |
> Bytes | Bytes | Elig Bytes | Returned Bytes | Offload |
>
> =====================================================================================================================================
> | 137 | 133 | 3.46 | 0.09 | 3877 | 26M | 201K |
> 196GB | 111GB | 196GB | 84GB | 56.90% |
>
> =====================================================================================================================================
>
> SQL Plan Monitoring Details (Plan Hash Value=3977078242)
>
> ====================================================================================================================================================================================
> | Id | Operation | Name |
> Rows | Cost | Time | Start | Execs | Rows | Read | Read |
> Mem | Activity | Activity Detail |
> | | | |
> (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes |
> (Max) | (%) | (# samples) |
>
> ====================================================================================================================================================================================
> | 0 | SELECT STATEMENT | |
> | | 3 | +135 | 1 | 38764 | | | .
> | | |
> | 1 | SORT ORDER BY | |
> 3876 | 4M | 3 | +135 | 1 | 38764 | | | 6MB
> | | |
> | 2 | COUNT STOPKEY | |
> | | 1 | +135 | 1 | 38764 | | | .
> | | |
> | 3 | HASH JOIN | |
> 3876 | 4M | 1 | +135 | 1 | 38764 | | | 15MB
> | | |
> | 4 | HASH JOIN | |
> 3802 | 4M | 132 | +4 | 1 | 38764 | | | 13MB
> | | |
> | 5 | JOIN FILTER CREATE | :BF0000 |
> 3809 | 4M | 132 | +4 | 1 | 38764 | | | .
> | | |
> | 6 | TABLE ACCESS STORAGE FULL | TAB1 |
> 3809 | 4M | 135 | +1 | 1 | 38764 | 201K | 196GB | 7MB
> | | |
> | 7 | JOIN FILTER USE | :BF0000 |
> 2M | 3237 | 1 | +135 | 1 | 15626 | | | .
> | | |
> | 8 | TABLE ACCESS STORAGE FULL | TD |
> 2M | 3237 | 1 | +135 | 1 | 15626 | | | .
> | | |
> | 9 | INDEX STORAGE FAST FULL SCAN | TD_IX1 |
> 959K | 448 | 2 | +135 | 1 | 959K | | | .
> | | |
>
> ====================================================================================================================================================================================
>
> ************** fast execution ***************
>
>
> Global Information
> ------------------------------
> Status : DONE (ALL ROWS)
> Instance ID : 1
> SQL Execution ID : 16777247
> Execution Started : 02/25/2022 15:38:36
> First Refresh Time : 02/25/2022 15:38:40
> Last Refresh Time : 02/25/2022 15:39:09
> Duration : 33s
> Module/Action : JDBC Thin Client/-
> Program : JDBC Thin Client
> Fetch Calls : 1801
>
> Global Stats
>
> =====================================================================================================================================
> | Elapsed | Cpu | IO | Application | Fetch | Buffer | Read |
> Read | Uncompressed | Offload | Offload | Cell |
> | Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs |
> Bytes | Bytes | Elig Bytes | Returned Bytes | Offload |
>
> =====================================================================================================================================
> | 33 | 8.29 | 25 | 0.02 | 1801 | 26M | 204K |
> 195GB | 191GB | 195GB | 3GB | 98.21% |
>
> =====================================================================================================================================
>
> SQL Plan Monitoring Details (Plan Hash Value=3977078242)
>
> ====================================================================================================================================================================================
> | Id | Operation | Name |
> Rows | Cost | Time | Start | Execs | Rows | Read | Read |
> Mem | Activity | Activity Detail |
> | | | |
> (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes |
> (Max) | (%) | (# samples) |
>
> ====================================================================================================================================================================================
> | 0 | SELECT STATEMENT | |
> | | 2 | +32 | 1 | 18003 | | | .
> | | |
> | 1 | SORT ORDER BY | |
> 3866 | 4M | 2 | +32 | 1 | 18003 | | | 3MB
> | | |
> | 2 | COUNT STOPKEY | |
> | | 1 | +32 | 1 | 18003 | | | .
> | | |
> | 3 | HASH JOIN | |
> 3866 | 4M | 1 | +32 | 1 | 18003 | | | 8MB
> | | |
> | 4 | HASH JOIN | |
> 3792 | 4M | 23 | +10 | 1 | 18003 | | | 6MB
> | | |
> | 5 | JOIN FILTER CREATE | :BF0000 |
> 3800 | 4M | 23 | +10 | 1 | 18003 | | | .
> | | |
> | 6 | TABLE ACCESS STORAGE FULL | TAB1 |
> 3800 | 4M | 32 | +1 | 1 | 18003 | 204K | 195GB | 7MB
> | | |
> | 7 | JOIN FILTER USE | :BF0000 |
> 2M | 3237 | 1 | +32 | 1 | 11409 | | | .
> | | |
> | 8 | TABLE ACCESS STORAGE FULL | TD |
> 2M | 3237 | 1 | +32 | 1 | 11409 | | | .
> | | |
> | 9 | INDEX STORAGE FAST FULL SCAN | TD_IX1 |
> 959K | 448 | 1 | +32 | 1 | 959K | | | .
> | | |
>
> ====================================================================================================================================================================================
>
> Predicate Information (identified by operation id):
> ---------------------------------------------------
>
> 2 - filter(ROWNUM<=100000)
> 3 - access("CMC"."PME"=TO_NUMBER("TAB1"."CO_ID"))
> 4 - access("TAB1"."TDN"="TD"."DID")
> 6 - storage("ATI"='XXXXXXX' AND (("PCSC"='CA2' OR "PCSC"='CR2' OR
> "PCSC"='CC4' OR "PCSC"='CI3' OR "PCSC"='CA1' OR "PCSC"='CC1' OR
> "PCSC"='CI' OR "PCSC"='CI2') OR ("PCSC"='CC3' OR "PCSC"='CC2' OR
> "PCSC"='CI4' OR "PCSC"='CR1' OR "PCSC"='CA' OR "PCSC"='CC'
> OR "PCSC"='CI1' OR "PCSC"='CR') AND ("IDR"='N' OR "IDR"='Y' AND
> "I_DT"<TRUNC(SYSDATE_at_!)-15) OR
> ("PCSC"='CI7' OR "PCSC"='CI6') AND "S_DT"<TRUNC(SYSDATE_at_!)
> OR ("PCSC"='CI5' OR "PCSC"='CI4') AND ("IDR"='N' OR "IDR"='Y' AND
> "I_DT"<TRUNC(SYSDATE_at_!)-15) AND "S_DT"<TRUNC(SYSDATE_at_!))
> AND ("D_DT" IS NULL AND "IDR"='N' OR "D_DT">SYSDATE_at_!-120))
> filter("ATI"='XXXXXXX' AND (("PCSC"='CA2' OR "PCSC"='CR2' OR
> "PCSC"='CC4' OR "PCSC"='CI3' OR "PCSC"='CA1' OR "PCSC"='CC1' OR "PCSC"='CI'
> OR "PCSC"='CI2') OR ("PCSC"='CC3' OR "PCSC"='CC2' OR
> "PCSC"='CI4' OR "PCSC"='CR1' OR "PCSC"='CA' OR "PCSC"='CC'
> OR "PCSC"='CI1' OR "PCSC"='CR') AND ("IDR"='N' OR "IDR"='Y' AND
> "I_DT"<TRUNC(SYSDATE_at_!)-15) OR
> ("PCSC"='CI7' OR "PCSC"='CI6') AND "S_DT"<TRUNC(SYSDATE_at_!)
> OR ("PCSC"='CI5' OR "PCSC"='CI4') AND ("IDR"='N' OR "IDR"='Y' AND
> "I_DT"<TRUNC(SYSDATE_at_!)-15) AND "S_DT"<TRUNC(SYSDATE_at_!))
> AND ("D_DT" IS NULL AND "IDR"='N' OR "D_DT">SYSDATE_at_!-120))
> 8 - storage(SYS_OP_BLOOM_FILTER(:BF0000,"TD"."DID"))
> filter(SYS_OP_BLOOM_FILTER(:BF0000,"TD"."DID"))
>
-- http://www.freelists.org/webpage/oracle-lReceived on Mon Feb 28 2022 - 20:04:35 CET