Re: Query with same plan running longer
Date: Tue, 1 Mar 2022 01:21:08 +0530
Message-ID: <CAKna9Va+K=t4AWK7rkdk3r8zN9q5KCTdca7FHSECy_ybK9Z2sw_at_mail.gmail.com>
I tried running the query by setting "_serial_direct_read"=always at
session level, but it didn't work. It's again showing ~50% cell offloading
percent with the same plan and running for ~2minutes+.
But I again tried by forcing full hints for all the tables in the
query(without any Parallel hint) and the seeing cell offloading percent
~90%+ and also the query finishing in quick time. Is it because we are just
getting to the edge of any limit related to cell offloading percentage
which is causing such behaviour?
Global Information
Global Stats
On Tue, Mar 1, 2022 at 12:48 AM Laurentiu Oprea <laurentiu.oprea06_at_gmail.com>
wrote:
Status : DONE (ALL ROWS)
Instance ID : 1
SQL Execution ID : 16777216
Execution Started : 02/28/2022 14:36:49
First Refresh Time : 02/28/2022 14:36:58
Last Refresh Time : 02/28/2022 14:37:04
Duration : 15s
Module/Action : SQL*Plus/-
Program : sqlplus.exe
Fetch Calls : 3
| 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 |
| 15 | 1.74 | 13 | 0.02 | 3 | 26M | 201K |
196GB | 195GB | 196GB | 66MB | 99.97% |
=====================================================================================================================================
===============================================================================================================================================================================================
| 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 | |
| | 1 | +15 | 1 | 6357 | | | . |
| |
| 1 | SORT ORDER BY | |
3786 | 4M | 1 | +15 | 1 | 6357 | | | 1MB
| | |
| 2 | COUNT STOPKEY | |
| | 1 | +15 | 1 | 6357 | | | . |
| |
| 3 | HASH JOIN | |
3786 | 4M | 1 | +15 | 1 | 6357 | | | 5MB
| | |
| 4 | JOIN FILTER CREATE | :BF0000 |
3713 | 4M | 1 | +15 | 1 | 6357 | | | .
| | |
| 5 | HASH JOIN | |
3713 | 4M | 7 | +9 | 1 | 6357 | | | 5MB
| | |
| 6 | JOIN FILTER CREATE | :BF0001 |
3720 | 4M | 7 | +9 | 1 | 6357 | | | .
| | |
| 7 | TABLE ACCESS STORAGE FULL | TAB1 |
3720 | 4M | 15 | +1 | 1 | 6357 | 201K | 196GB | 7MB
| 100.00 | Cpu (1) |
| | | |
| | | | | | | | |
| cell smart table scan (13) |
| 8 | JOIN FILTER USE | :BF0001 |
2M | 3237 | 1 | +15 | 1 | 6577 | | | . |
| |
| 9 | TABLE ACCESS STORAGE FULL | TD |
2M | 3237 | 1 | +15 | 1 | 6577 | 176 | 174MB | 7MB |
| |
| 10 | JOIN FILTER USE | :BF0000 |
959K | 2596 | 1 | +15 | 1 | 1197 | | | .
| | |
| 11 | TABLE ACCESS STORAGE FULL | CMS |
959K | 2596 | 1 | +15 | 1 | 1197 | 144 | 143MB | 7MB
| | |
===============================================================================================================================================================================================
> Hello Lok,
>
> If you can replicate this, can you set at session level:
>
> alter session set "_serial_direct_read"=always;
>
> and see if it has any effect?
>
> Thanks.
>
> În lun., 28 feb. 2022 la 21:05, Lok P <loknath.73_at_gmail.com> a scris:
>
>> 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
>> ------------------------------
>> 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
>>
>> Global Stats
>>
>> ================================================================================================================================================
>> | 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:51:08 CET