Re: CTAS running long

From: Jonathan Lewis <jlewisoracle_at_gmail.com>
Date: Mon, 9 May 2022 09:28:52 +0100
Message-ID: <CAGtsp8mJ_cBxpEtsdqy+D5eDs=SKm_jCCdqtFVQVdd+LTB9kzg_at_mail.gmail.com>



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 Mon May 09 2022 - 10:28:52 CEST

Original text of this message