Re: CTAS running long

From: Jonathan Lewis <jlewisoracle_at_gmail.com>
Date: Wed, 11 May 2022 23:54:03 +0100
Message-ID: <CAGtsp8nC0OyOdTOygMoRn3-0ryKcHPWtU24x5ytaN4UR+rCG=Q_at_mail.gmail.com>



I'm sorry, I've just spent 40 minutes writing up some notes about what the monitor plan is showing - I'd misread two details when looking at the raw email - but google has just lost my mail by throwing a network error and jamming my browser, so a follow-up is going to have to wait another day.

Regards
Jonathan Lewis

On Tue, 10 May 2022 at 20:56, Lok P <loknath.73_at_gmail.com> wrote:

> Thank You Jonathan. The Oracle version is 19.9.0.0.0. And I checked the
> dba_lobs these two clobs are CACHE 'NO', LOGGING 'NO' and also SECUREFILE
> is NO. I will try to test the speed of CTAS on a lower environment on a
> sample table with CLOB columns and update on this. Mainly by altering the
> CACHE option to YES.
>
> Also, I checked the length of those two CLOB columns using
> dbms_lob.getlength. Out of total ~71million rows in that table one clob
> column has ~66million clobs having size <4KB and 944K clobs with size
> >600KB. Other column has ~70million clobs with size <4KB and 43K clobs
> with size >600KB. Can you explain a bit on the difference in data load
> strategy of having a large number of clobs with small size VS small number
> of clobs with large size?
>
>
> On Mon, May 9, 2022 at 1:59 PM Jonathan Lewis <jlewisoracle_at_gmail.com>
> wrote:
>
>>
>> You haven't said which version of Oracle you're using, not whether the
>> LOBs are basicfile or securefile (it would be too easy to assume
>> securefile, which could be wrong, and it might make a difference), and
>> whatever anyone tells you about configuring the logging or caching for the
>> table and/or its LOBs you should set up a small (couple of million rows) to
>> test since different versions may introduce different waits on different
>> events.
>>
>> You reported the log file sizes for the online logs - you need to review
>> the log file sizes of the archived logs because you may be losing a lot of
>> space in the online logs thanks to the effects or private redo (though,
>> since you're running RAC that might not apply - it didn't in older versions
>> of Oracle, I haven't checked the latest versions).
>>
>> Your largest amount of time is spent on direct path reads, not log file
>> switches, and it's not likely that you'll get rid of that, though maybe if
>> you cached the LOB it would make a difference. THe logging mechanism is
>> going to happen whether or not you specify nologging - that's the effect of
>> "force logging". However, and this may vary with version of Oracle and type
>> of LOB, it used to be the case that nocache LOBs would HAVE to log whole
>> Oracle blocks, even if you only half-filled then, while cache LOBs would
>> generate redo only for the actual data written to the LOB. This MIGHT make
>> a difference.
>>
>> The biggest timing, thing for you, though, is the basic volume -
>> according to operation 3 you have roughly 300GB of LOBs to read - which you
>> are doing one Oracle block at a time - this mean 300GB of LOBs to write,
>> 300GB of online redo (possibly duplexed) to write, and then you have to
>> read and write the online redo to archive it and maybe you have some other
>> processes reading the archive (or online) and pushing it across a network.
>>
>> As a minimum reversible change I would increase the number of redo log
>> groups to at least 20 (i.e. 10 GB), This might be enough to give Oracle
>> enough headroom to avoid the "checkpoint incomplete", but it might mean you
>> don't see that wait for the first minute and then see it continuously for
>> the next 30 minutes.
>>
>> I am a little puzzled by the fact that operation 3 records 545K writes to
>> write 314GB - which means an average of about 600KB per write. You can see
>> in operation 6, though, that you have recorded 225MB of writes with NO
>> write requests, so maybe there's an internal error in the accounting and
>> (for example) the number of write requests for direct path writes is lost
>> even though the volume is recorded). However, it's possible that you have a
>> relatively small number of large LOBs, and maybe most of your LOBs are "in
>> row", with only a small number "out of row". You should check on the
>> pattern of LOB sizes, because the best strategy for handling 40M LOBs of 4K
>> each might be different from the best strategy for handling 500K LOBs of
>> 600KB and 40M LOBs of 2K.
>>
>> Regards
>> Jonathan Lewis
>>
>>
>>
>>
>>
>>
>>
>>
>> On Sat, 7 May 2022 at 18:37, Lok P <loknath.73_at_gmail.com> wrote:
>>
>>> Resending as bounced back...
>>>
>>> Hi , We are trying to purge data from a non partition table, as part of
>>> which we are creating an interim table which would be partitioned and that
>>> will hold the required data and then we will exchange that partition with
>>> the main table to purge data from the main table.
>>>
>>> The issue is that the create interim partitioned table statement which
>>> is supposed to pick and purge ~60million records from the non partition
>>> table(TABLE1) is running long. The base/main table (Say TABLE1) is ~91GB in
>>> size and holds 71million rows and avg_row_len is showing as 1178. The sql
>>> monitor we captured is as below. It shows almost all time spent on "log
>>> file switch (checkpoint incomplete)". The interim table creation is running
>>> in Parallel-32.
>>>
>>> Btw we saw while performing CTAS for other tables with even more data we
>>> didn't see such an issue. And then one thing we noticed is, there exists
>>> two CLOB columns in this main table(table1 here) which were not there in
>>> other tables. And the CLOB columns were defined as below. So my question is
>>> , is this high "log file switch (checkpoint incomplete)" wait event
>>> happening because of the presence of these clob columns and how can we make
>>> this interim table creation faster in such a case?
>>>
>>> And we have our database in force logging mode and we have data guard
>>> configuration in place. If we create the interim table as nologging will it
>>> help here or cause any issue as we have our main non partitioned table is
>>> created as 'logging' mode?
>>>
>>> LOB (CLOB1) STORE AS (
>>>
>>> TABLESPACE TBS2
>>> ENABLE STORAGE IN ROW
>>> CHUNK 8192
>>> RETENTION
>>> NOCACHE
>>> NOLOGGING
>>> STORAGE (
>>> INITIAL 64K
>>> NEXT 1M
>>> MINEXTENTS 1
>>> MAXEXTENTS UNLIMITED
>>> PCTINCREASE 0
>>> BUFFER_POOL DEFAULT
>>> ))
>>> TABLESPACE TBS2
>>> PCTUSED 0
>>> PCTFREE 10
>>> INITRANS 1
>>> MAXTRANS 255
>>> STORAGE (
>>> INITIAL 64K
>>> NEXT 1M
>>> MAXSIZE UNLIMITED
>>> MINEXTENTS 1
>>> MAXEXTENTS UNLIMITED
>>> PCTINCREASE 0
>>> BUFFER_POOL DEFAULT
>>> )
>>> NOLOGGING
>>> NOCOMPRESS
>>> NOCACHE
>>> MONITORING;
>>>
>>>
>>> select group#, thread#, archived, status, BYTES/1024/1024 MB from v$log
>>>
>>> GROUP# THREAD# ARCHIVED STATUS MB
>>>
>>> 1 1 NO CURRENT 500
>>>
>>> 2 1 YES ACTIVE 500
>>>
>>> 3 1 YES ACTIVE 500
>>>
>>> 4 2 YES INACTIVE 500
>>>
>>> 5 2 NO CURRENT 500
>>>
>>> 6 2 YES ACTIVE 500
>>>
>>>
>>> CREATE TABLE TABLE_BKP (c1, c2, c3, c4.. c12) parallel 32 partition by
>>> range (C3) (partition p0 values less than (maxvalue) tablespace TBS1) as (
>>> select /*+ parallel(t, 32) */ * from TABLE1 t where cre_ts>Sysdate-700)
>>>
>>> Global Information
>>> ------------------------------
>>> Status : EXECUTING
>>> Instance ID : 1
>>> SQL ID : 3rfch2jrrciou
>>> SQL Execution ID : 16777216
>>> Execution Started : 05/07/2022 01:47:51
>>> First Refresh Time : 05/07/2022 01:47:52
>>> Last Refresh Time : 05/07/2022 02:24:12
>>> Duration : 2198s
>>> Module/Action : SQL*Plus/-
>>>
>>> Global Stats
>>>
>>> =======================================================================================================================================================================
>>> | Elapsed | Cpu | IO | Application | Concurrency | Cluster |
>>> Other | Buffer | Read | Read | Write | Write | Uncompressed | Offload
>>> | Offload |
>>> | Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) |
>>> Waits(s) | Gets | Reqs | Bytes | Reqs | Bytes | Bytes | Elig
>>> Bytes | Returned Bytes |
>>>
>>> =======================================================================================================================================================================
>>> | 70278 | 5941 | 42197 | 0.00 | 10 | 2.32 |
>>> 22128 | 378M | 40M | 314GB | 544K | 314GB | 6GB |
>>> 6GB | 632GB |
>>>
>>> =======================================================================================================================================================================
>>>
>>> SQL Plan Monitoring Details (Plan Hash Value=2463526707)
>>> ============================================================
>>> ============================================================
>>> ============================================================
>>> ============================================================
>>> | Id | Operation | Name |
>>> Rows | Cost | Time | Start | Execs | Rows | Read | Read |
>>> Write | Write | Mem | Activity | Activity Detail
>>> | Progress |
>>> | | | |
>>> (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes |
>>> Reqs | Bytes | | (%) | (# samples)
>>> | |
>>> ============================================================
>>> ============================================================
>>> ============================================================
>>> ============================================================
>>> | 0 | CREATE TABLE STATEMENT | |
>>> | | | | 33 | | | |
>>> | | . | |
>>> | |
>>> | 1 | PX COORDINATOR | |
>>> | | | | 33 | | | |
>>> | | . | |
>>> | |
>>> | 2 | PX SEND QC (RANDOM) | :TQ10000 |
>>> 44M | 58295 | | | 32 | | | |
>>> | | . | |
>>> | |
>>> | -> 3 | LOAD AS SELECT (HYBRID TSM/HWMB) | TABLE_BKP |
>>> | | 2201 | +3 | 32 | 0 | 40M | 308GB |
>>> 545K | 314GB | 65MB | 99.98 | gc cr grant 2-way (4)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | buffer busy waits (1)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | log buffer space (16)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | log file switch (checkpoint incomplete)
>>> (21981) | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | log file switch completion (30)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | Cpu (4405)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | enq: TX - contention (13)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | ASM IO for non-blocking poll (331)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | cell single block physical read (656)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | direct path read (42447)
>>> | |
>>> | | | |
>>> | | | | | | | |
>>> | | | | direct path write (2)
>>> | |
>>> | -> 4 | OPTIMIZER STATISTICS GATHERING | |
>>> 44M | 58295 | 2201 | +3 | 32 | 3M | | |
>>> | | 5MB | 0.01 | Cpu (4)
>>> | |
>>> | -> 5 | PX BLOCK ITERATOR | |
>>> 44M | 58295 | 2201 | +3 | 32 | 3M | | |
>>> | | . | |
>>> | |
>>> | -> 6 | TABLE ACCESS STORAGE FULL | TABLE1 |
>>> 44M | 58295 | 2201 | +3 | 62 | 3M | 10068 | 6GB |
>>> | | 225MB | 0.01 | Cpu (5)
>>> | 100% |
>>> | | | |
>>> | | | | | | | |
>>> | | | | cell smart table scan (2)
>>> | |
>>> ============================================================
>>> ============================================================
>>> ============================================================
>>> ============================================================
>>>
>>

--
http://www.freelists.org/webpage/oracle-l
Received on Thu May 12 2022 - 00:54:03 CEST

Original text of this message