Create table as select (CTAS) takes forever, even its select query takes just 10 minutes

R4C_SuteeS · Dec 27, 2019 2:55AM

I have the attached CTAS query which takes forever to run (the most I have waited was 24 hours+).
But when I try run just only the select query alone, it takes only 10 minutes to complete (I also try to export data to excel via SQL developer, it only take 10 minutes as well).
I also have tried use PARALLEL at CTAS only, at select query only and both (as below) bu still have the issue).

So, I'm not sure why CTAS takes forever to complete. Any idea?

CREATE TABLE XX_XXX_XXXXX01 PARALLEL NOLOGGING AS

(SELECT

/*+ PARALLEL */

LEFT_CODE.SEQ,

LEFT_CODE.C1 AS C1,

LEFT_CODE.C2 AS C2,

LEFT_CODE.C3 AS C3,

LEFT_CODE.C4 AS C4,

LEFT_CODE.C5 AS C5,

LEFT_CODE.C6 AS C6,

LEFT_CODE.C7 AS C7,

LEFT_CODE.C8 AS C8,

LEFT_CODE.C9 AS C9,

LEFT_CODE.C10 AS C10,

LEFT_CODE.C11 AS C11,

LEFT_CODE.C12 AS C12,

LEFT_CODE.C13 AS C13,

LEFT_CODE.C14 AS C14,

LEFT_CODE.C15 AS C15,

LEFT_CODE.C16 AS C16,

LEFT_CODE.C17 AS C17,

LEFT_CODE.C18 AS C18,

LEFT_CODE.C19 AS C19,

LEFT_CODE.C20 AS C20,

LEFT_CODE.C21 AS C21,

RIGHT_CODE.C11 AS C22,

RIGHT_CODE.C12 AS C23,

RIGHT_CODE.C13 AS C24,

RIGHT_CODE.C14 AS C25,

RIGHT_CODE.C15 AS C26,

RIGHT_CODE.C11 AS C27,

RIGHT_CODE.C12 AS C28,

RIGHT_CODE.C13 AS C29,

RIGHT_CODE.C14 AS C30,

RIGHT_CODE.C15 AS C31,

RIGHT_CODE.C16 AS C32,

RIGHT_CODE.C17 AS C33,

RIGHT_CODE.C18 AS C34,

RIGHT_CODE.C19 AS C35,

RIGHT_CODE.C20 AS C36,

RIGHT_CODE.C21 AS C37,

RIGHT_CODE.C22 AS C38,

RIGHT_CODE.C23 AS C39,

RIGHT_CODE.C24 AS C40,

RIGHT_CODE.C25 AS C41,

RIGHT_CODE.C26 AS C42

FROM

(SELECT T1.*,

(SELECT COL2

FROM IMPORT_METADATA

WHERE SNAPSHOT_ID=2

AND TYPE ='USER'

AND COL1 =T1.XXX_LAST_UPDATED_BY

) AS LAST_UPDATED_BY_NAME,

(SELECT COL2

FROM IMPORT_METADATA

WHERE SNAPSHOT_ID=2

AND TYPE ='USER'

AND COL1 =T1.XXX_CREATED_BY

) AS CREATED_BY_NAME

FROM

(SELECT *

FROM XX_XXX_T3351

WHERE SNAPSHOT_ID =2

AND ( ( XXX_INV_ORG_ID IS NOT NULL

OR XXX_OU_ID IS NOT NULL

OR XXX_LEDGER_ID IS NOT NULL

OR XXX_BG_ID IS NOT NULL )

OR ( XXX_INV_ORG_ID IS NULL

AND XXX_OU_ID IS NULL

AND XXX_LEDGER_ID IS NULL

AND XXX_BG_ID IS NULL ) )

AND ( XXX_LAST_UPDATED_BY NOT IN ('-1','0','1','2','3','4','5','6','7','120','121','122','123','124','125','126','127','128','129' )

OR XXX_CREATED_BY NOT IN ('-1','0','1','2','3','4','5','6','7','120','121','122','123','124','125','126','127','128','129') )

) T1

ORDER BY SEQ

) LEFT_CODE

LEFT JOIN

(SELECT T1.*,

(SELECT COL2

FROM IMPORT_METADATA

WHERE SNAPSHOT_ID=2

AND TYPE ='USER'

AND COL1 =T1.XXX_LAST_UPDATED_BY

) AS LAST_UPDATED_BY_NAME,

(SELECT COL2

FROM IMPORT_METADATA

WHERE SNAPSHOT_ID=2

AND TYPE ='USER'

AND COL1 =T1.XXX_CREATED_BY

) AS CREATED_BY_NAME

FROM

(SELECT *

FROM XX_XXX_T3353

WHERE SNAPSHOT_ID =2

AND ( ( XXX_INV_ORG_ID IS NOT NULL

OR XXX_OU_ID IS NOT NULL

OR XXX_LEDGER_ID IS NOT NULL

OR XXX_BG_ID IS NOT NULL )

OR ( XXX_INV_ORG_ID IS NULL

AND XXX_OU_ID IS NULL

AND XXX_LEDGER_ID IS NULL

AND XXX_BG_ID IS NULL ) )

AND ( XXX_LAST_UPDATED_BY NOT IN ('-1','0','1','2','3','4','5','6','7','120','121','122','123','124','125','126','127','128','129' )

OR XXX_CREATED_BY NOT IN ('-1','0','1','2','3','4','5','6','7','120','121','122','123','124','125','126','127','128','129') )

) T1

ORDER BY SEQ

) RIGHT_CODE

ON 1 =1

AND NVL(LEFT_CODE.C8,'X') = NVL(RIGHT_CODE.C8,'X')

AND NVL(LEFT_CODE.C10,'X') = NVL(RIGHT_CODE.C10,'X')

AND NVL(LEFT_CODE.C1,'X') = NVL(RIGHT_CODE.C1,'X')

AND NVL(LEFT_CODE.C1,'X') = 'VALUE SET'

AND NVL(LEFT_CODE.C8,'X') IS NOT NULL

);

AndrewSayer · Dec 27, 2019 3:23AM

Is the execution plan different between the CTAS and the select statement (other than the create table part)?

Adding parallelism is only going to make it difficult to compare, sometimes you’ll get the parallel slaves you want, sometimes you’ll get less and sometimes you’ll get none depending on the amount of other parallel work going on.

What is the session executing the CTAS waiting on? Check v$session_event to see where it’s spending most of its time.

Any chance youre referencing views/synonyms that point to remote tables?

Remember we don’t have your DDL.

GregV · Dec 27, 2019 3:48AM

Hi,

As Andrew suggested, start by checking what the session is waiting for. Since you're using SQL Developer check this from the "monitor sessions" screen.

When you say the query takes 10 min to complete, are you talking about retrieving all the rows? How many of them in total?

Using PARALLEL with a wrong execution plan only makes things worse because the wrong plan is multiplied to different sessions. Make sure the stats are up to date.

R4C_SuteeS · Dec 27, 2019 4:19AM

Andrew,

Thanks for quick response, and yes, the explain plain are differnt. I don't know why it does the INDEX RANGE SCAN when we do CTAS but it doesn't when we just select.

What wait event on all active sessions just CPU (resmgr:cpu quantum).

The SELECT statement only explain plan:

The complete CTAS explain plan:

R4C_SuteeS · Dec 27, 2019 4:28AM

Greg,

When you say the query takes 10 min to complete, are you talking about retrieving all the rows? How many of them in total?

Yes, either just run the select statement directly or retrieve all rows (by export that result to an excel file from SQL developer). It takes just ~10 minutes.

The excel sheet in return about 65K of rows. We have try the parallel cause the select statement get executing slowly (just 1 x vCPU on 4 x vCPU machine).

It just return in ~10 when we add the parallel hint. But however, once added to CTAS then it just take forever.

AndrewSayer · Dec 27, 2019 5:26AM

3339281 wrote:Andrew,Thanks for quick response, and yes, the explain plain are differnt. I don't know why it does the INDEX RANGE SCAN when we do CTAS but it doesn't when we just select.What wait event on all active sessions just CPU (resmgr:cpu quantum).The SELECT statement only explain plan:cid:d02facd8-106c-4b26-80ab-1a048a26200aThe complete CTAS explain plan:cid:0f0b7330-faa1-4901-8e16-edb49370caeb

I am not going to download files.

Please use sql*plus, grab the execution (not explain) plan from memory using dbms_xplan.display_cursor and copy and paste the plans using a fixed width font here.

resmgr:cpu quantum is NOT CPU, it's specifically a wait event to prevent you from using CPU. How is your resource manager configured? Is this wait event really the most significant - ie it's spent hours on it? Show us the results from v$session_event (remember to use a fresh session each time as this shows the aggregate usage for the lifetime of a session). How does that compare to the simple select statement?

GregV · Dec 27, 2019 6:16AM

I've noticed you're querying 4 times the IMPORT_METADATA table and you're using 2 ORDER BY clauses within in-line views, which gives unecessary pain to the optimizer. And worse, you're not even selecting columns from the IMPORT_METADATA table in your final SELECT list! So remove the scalar queries on IMPORT_METADATA and the ORDER BY clauses and see if it improves your query performance.

R4C_SuteeS · Dec 27, 2019 11:51AM

Andrew,

Explain plans are below, the output of "v$session_event" of all SIDs for the CTAS query. Please feel free to let me know if you need more information.

Select statement explain plan:

SQL> SELECT * FROM table(DBMS_XPLAN.DISPLAY_CURSOR('g7qxhcnvvwc3s',0));

SQL_ID g7qxhcnvvwc3s, child number 0

-------------------------------------

SELECT /*+ PARALLEL */ LEFT_CODE.SEQ, LEFT_CODE.C1 AS C1,

LEFT_CODE.C2 AS C2, LEFT_CODE.C3 AS C3, LEFT_CODE.C4

AS C4, LEFT_CODE.C5 AS C5, LEFT_CODE.C6 AS C6,

LEFT_CODE.C7 AS C7, LEFT_CODE.C8 AS C8, LEFT_CODE.C9

AS C9, LEFT_CODE.C10 AS C10, LEFT_CODE.C11 AS C11,

LEFT_CODE.C12 AS C12, LEFT_CODE.C13 AS C13, LEFT_CODE.C14

AS C14, LEFT_CODE.C15 AS C15, LEFT_CODE.C16 AS C16,

LEFT_CODE.C17 AS C17, LEFT_CODE.C18 AS C18,

LEFT_CODE.C19 AS C19, LEFT_CODE.C20 AS C20, LEFT_CODE.C21

AS C21, RIGHT_CODE.C11 AS C22, RIGHT_CODE.C12 AS C23,

RIGHT_CODE.C13 AS C24, RIGHT_CODE.C14 AS C25,

RIGHT_CODE.C15 AS C26, RIGHT_CODE.C11 AS C27,

RIGHT_CODE.C12 AS C28, RIGHT_CODE.C13 AS C29,

RIGHT_CODE.C14 AS C30, RIGHT_CODE.C15 AS C31,

RIGHT_CODE.C16 AS C32, RIGHT_CODE.C17 AS C33, RIGHT_CO

Plan hash value: 3171693698

-------------------------------------------------------------------------------------------------------------------------------

-------------------------------------------------------------------------------------------------------------------------------

| 0 | SELECT STATEMENT | | | | | 944K(100)| | | | |

| 1 | PX COORDINATOR | | | | | | | | | |

| 2 | PX SEND QC (ORDER) | :TQ10001 | 60208 | 4259M| | 944K (1)| 03:08:53 | Q1,01 | P->S | QC (ORDER) |

| 3 | SORT ORDER BY | | 60208 | 4259M| 470M| 944K (1)| 03:08:53 | Q1,01 | PCWP | |

| 4 | PX RECEIVE | | 60208 | 4259M| | 15167 (1)| 00:03:03 | Q1,01 | PCWP | |

| 5 | PX SEND RANGE | :TQ10000 | 60208 | 4259M| | 15167 (1)| 00:03:03 | Q1,00 | P->P | RANGE |

| 6 | NESTED LOOPS OUTER | | 60208 | 4259M| | 15167 (1)| 00:03:03 | Q1,00 | PCWP | |

| 7 | PX BLOCK ITERATOR | | | | | | | Q1,00 | PCWC | |

|* 8 | TABLE ACCESS FULL | XX_XXX_T3351 | 60208 | 2419M| | 58 (2)| 00:00:01 | Q1,00 | PCWP | |

| 9 | VIEW | | 1 | 32032 | | | | Q1,00 | PCWP | |

|* 10 | FILTER | | | | | | | Q1,00 | PCWP | |

|* 11 | TABLE ACCESS FULL| XX_XXX_T3353 | 1 | 38129 | | 24 (0)| 00:00:01 | Q1,00 | PCWP | |

-------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):

---------------------------------------------------

8 - access(:Z>=:Z AND :Z<=:Z)

filter(("SNAPSHOT_ID"=2 AND (("XXX_LAST_UPDATED_BY"<>(-1) AND "XXX_LAST_UPDATED_BY"<>0 AND

"XXX_LAST_UPDATED_BY"<>1 AND "XXX_LAST_UPDATED_BY"<>2 AND "XXX_LAST_UPDATED_BY"<>3 AND "XXX_LAST_UPDATED_BY"<>4 AND

"XXX_LAST_UPDATED_BY"<>5 AND "XXX_LAST_UPDATED_BY"<>6 AND "XXX_LAST_UPDATED_BY"<>7 AND "XXX_LAST_UPDATED_BY"<>120 AND

"XXX_LAST_UPDATED_BY"<>121 AND "XXX_LAST_UPDATED_BY"<>122 AND "XXX_LAST_UPDATED_BY"<>123 AND

"XXX_LAST_UPDATED_BY"<>124 AND "XXX_LAST_UPDATED_BY"<>125 AND "XXX_LAST_UPDATED_BY"<>126 AND

"XXX_LAST_UPDATED_BY"<>127 AND "XXX_LAST_UPDATED_BY"<>128 AND "XXX_LAST_UPDATED_BY"<>129) OR ("XXX_CREATED_BY"<>(-1)

AND "XXX_CREATED_BY"<>0 AND "XXX_CREATED_BY"<>1 AND "XXX_CREATED_BY"<>2 AND "XXX_CREATED_BY"<>3 AND

"XXX_CREATED_BY"<>4 AND "XXX_CREATED_BY"<>5 AND "XXX_CREATED_BY"<>6 AND "XXX_CREATED_BY"<>7 AND "XXX_CREATED_BY"<>120

AND "XXX_CREATED_BY"<>121 AND "XXX_CREATED_BY"<>122 AND "XXX_CREATED_BY"<>123 AND "XXX_CREATED_BY"<>124 AND

"XXX_CREATED_BY"<>125 AND "XXX_CREATED_BY"<>126 AND "XXX_CREATED_BY"<>127 AND "XXX_CREATED_BY"<>128 AND

"XXX_CREATED_BY"<>129)) AND ("XXX_INV_ORG_ID" IS NOT NULL OR "XXX_OU_ID" IS NOT NULL OR "XXX_LEDGER_ID" IS NOT NULL OR

"XXX_BG_ID" IS NOT NULL OR ("XXX_INV_ORG_ID" IS NULL AND "XXX_OU_ID" IS NULL AND "XXX_LEDGER_ID" IS NULL AND

"XXX_BG_ID" IS NULL))))

10 - filter((NVL("XX_XXX_T3351"."C8",'X') IS NOT NULL AND NVL("XX_XXX_T3351"."C1",'X')='Value Set'))

11 - filter(("SNAPSHOT_ID"=2 AND (("XXX_LAST_UPDATED_BY"<>(-1) AND "XXX_LAST_UPDATED_BY"<>0 AND