Oracle n NoSQL: Exadata Performance Issue/Problem: High time for Merge

Hi,
I recently faced a severe performance problem in Exadata Full Rack X2 where a Merge statement nearly took over 20+ hours. With Exadata in place customer expected fast performance
for all type of their queries. Customer surprised to see severe performance problem with Merge statement when they migrated their database from old legacy system typically non
oracle database.

Even for me its was a quite a surprise though, having Exadata in place how can a process take 20+ hrs. Following is the Merge Statement for your reference. This Merge statement
was running in production and processing high volume of data.

So to Diagnose and to simulate this i took same Merge statement but with less data this time(nearly 1/3 data) on quater Rack X2. It took 4+ hrs in this exadata but it also processed very less amount of data.

MERGE INTO XXX_UAT.XXX_BALANCE USING ( SELECT ACID, EOD_DATE, LKP_BAL_TYPE_ID, TRAN_DATE_BAL, TRAN_DATE_TOT_TRAN, VALUE_DATE_BAL, VALUE_DATE_TOT_TRAN, END_EOD_DATE, LCHG_TIME, RCRE_TIME FROM BOB_UAT_STG.STG_EOD_x_BAL_TABLE WHERE FLG_IUD IS NULL ) T ON (XXX_UAT.XXX_BALANCE.ACCT_ID = T.ACID AND XXX_UAT.XXX_BALANCE.ACCT_BAL_CALCULATED_DT = T.EOD_DATE AND XXX_UAT.XXX_BALANCE.BAL_TYPE_ID = T.LKP_BAL_TYPE_ID) WHEN MATCHED THEN UPDATE SET BAL_AMT=T.TRAN_DATE_BAL,
TRAN_DATE_TOT_TRAN=T.TRAN_DATE_TOT_TRAN, VALUE_DATE_BAL=T.VALUE_DATE_BAL, VALUE_DATE_TOT_TRAN=T.VALUE_DATE_TOT_TRAN, END_EOD_DATE=T.END_EOD_DATE, UPDATED_BY=1117146, UPDATED_ON=CURRENT_DATE, LCHG_TIME=T.LCHG_TIME, RCRE_TIME =T.RCRE_TIME WHEN NOT MATCHED THEN INSERT (ACCT_ID, ACCT_BAL_CALCULATED_DT, BAL_TYPE_ID, BAL_AMT, TRAN_DATE_TOT_TRAN, VALUE_DATE_BAL, VALUE_DATE_TOT_TRAN, END_EOD_DATE, INSERTED_BY, INSERTED_ON, LCHG_TIME, RCRE_TIME) VALUES( T.ACID, T.EOD_DATE, T.LKP_BAL_TYPE_ID,
T.TRAN_DATE_BAL, T.TRAN_DATE_TOT_TRAN, T.VALUE_DATE_BAL, T.VALUE_DATE_TOT_TRAN, T.END_EOD_DATE, 1117146, CURRENT_DATE, T.LCHG_TIME, T.RCRE_TIME )

Following is the some crucial contents of SQL monitoring reports:

Global Stats
====================================================================================================================================
| Elapsed | Cpu | IO | Application | Concurrency | Cluster | Other | Buffer | Read | Read | Write | Write | Cell |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes | Reqs | Bytes | Offload |
====================================================================================================================================
| 18138 | 2595 | 15502 | 0.00 | 0.74 | 21 | 19 | 21M | 4M | 35GB | 4707 | 552MB | -1.01% |
====================================================================================================================================

Parallel Execution Details (DOP=20 , Servers Allocated=40)
=================================================================================================================================================================================================================
| Name | Type | Server# | Elapsed | Cpu | IO | Application | Concurrency | Cluster | Other | Buffer | Read | Read | Write | Write | Cell | Wait Events |
| | | | Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes | Reqs | Bytes | Offload | (sample #) |
=================================================================================================================================================================================================================
| PX Coordinator | QC | | 16213 | 689 | 15502 | 0.00 | 0.74 | 21 | | 21M | 4M | 35GB | | . | NaN% | gc cr multi block request (1) |
| | | | | | | | | | | | | | | | | gc current grant 2-way (19) |
| | | | | | | | | | | | | | | | | os thread startup (1) |
| | | | | | | | | | | | | | | | | gcs drm freeze in enter server mode (1) |
| | | | | | | | | | | | | | | | | cell multiblock physical read (3) |
| | | | | | | | | | | | | | | | | cell single block physical read (15469) |
| p000 | Set 1 | 1 | 96 | 95 | 0.00 | | | | 1.16 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p001 | Set 1 | 2 | 96 | 95 | 0.00 | | | | 1.24 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p002 | Set 1 | 3 | 96 | 95 | 0.00 | | | | 1.17 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p003 | Set 1 | 4 | 96 | 95 | 0.00 | | 0.00 | | 0.83 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p004 | Set 1 | 5 | 96 | 95 | 0.00 | | | | 0.77 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p005 | Set 1 | 6 | 96 | 95 | 0.00 | | | | 0.75 | | 234 | 27MB | 234 | 27MB | -49.25% | |
| p006 | Set 1 | 7 | 96 | 95 | 0.01 | | | | 0.66 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p007 | Set 1 | 8 | 97 | 95 | 0.00 | | | | 1.41 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p008 | Set 1 | 9 | 97 | 96 | 0.00 | | 0.00 | | 0.96 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p009 | Set 1 | 10 | 96 | 95 | 0.00 | | | | 0.86 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p010 | Set 1 | 11 | 96 | 96 | 0.00 | | 0.00 | | 0.73 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p011 | Set 1 | 12 | 96 | 95 | 0.00 | | | | 0.68 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p012 | Set 1 | 13 | 96 | 95 | 0.01 | | | | 0.81 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p013 | Set 1 | 14 | 96 | 95 | 0.00 | | | | 0.83 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p014 | Set 1 | 15 | 97 | 95 | 0.00 | | | | 1.29 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p015 | Set 1 | 16 | 96 | 96 | 0.00 | | | | 0.69 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p016 | Set 1 | 17 | 96 | 95 | 0.00 | | | | 0.76 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p017 | Set 1 | 18 | 96 | 95 | 0.00 | | | | 0.91 | | 236 | 28MB | 236 | 28MB | -49.25% | |
| p018 | Set 1 | 19 | 96 | 96 | 0.01 | | | | 0.73 | | 235 | 28MB | 235 | 28MB | -49.25% | |
| p019 | Set 1 | 20 | 97 | 95 | 0.01 | | | | 1.40 | | 236 | 28MB | 236 | 28MB | -49.25% | |
=================================================================================================================================================================================================================

SQL Plan Monitoring Details (Plan Hash Value=3727815683)
===================================================================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Write | Write | Mem | Temp | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | Reqs | Bytes | (Max) | (Max) | (%) | (# samples) |
===================================================================================================================================================================================================================================
| 0 | MERGE STATEMENT | | | | 16054 | +220 | 1 | 1 | | | | | | | 0.00 | Cpu (1) |
| 1 | MERGE | XXX_BALANCE | | | 16056 | +218 | 1 | 1 | 4M | 34GB | | | | | 78.73 | gc current grant 2-way (19) |
| | | | | | | | | | | | | | | | | Cpu (516) |
| | | | | | | | | | | | | | | | | gcs drm freeze in enter server mode (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (15469) |
| 2 | PX COORDINATOR | | | | 16274 | +0 | 21 | 8M | | | | | | | 0.09 | os thread startup (1) |
| | | | | | | | | | | | | | | | | Cpu (17) |
| 3 | PX SEND QC (RANDOM) | :TQ10002 | 8M | 708K | 16054 | +219 | 20 | 8M | | | | | | | 0.13 | Cpu (26) |
| 4 | VIEW | | | | 16054 | +219 | 20 | 8M | | | | | | | | |
| 5 | HASH JOIN OUTER BUFFERED | | 8M | 708K | 16261 | +12 | 20 | 8M | 4707 | 552MB | 4707 | 552MB | 1G | 629M | 5.15 | Cpu (1046) |
| 6 | BUFFER SORT | | | | 12 | +2 | 20 | 8M | | | | | 862M | | 0.04 | Cpu (9) |
| 7 | PX RECEIVE | | 8M | 28085 | 12 | +2 | 20 | 8M | | | | | | | 0.01 | Cpu (3) |
| 8 | PX SEND HASH | :TQ10000 | 8M | 28085 | 11 | +2 | 1 | 8M | | | | | | | 0.02 | Cpu (4) |
| 9 | TABLE ACCESS STORAGE FULL | STG_EOD_x_BAL_TABLE | 8M | 28085 | 12 | +1 | 1 | 8M | 869 | 802MB | | | | | 0.03 | gc cr multi block request (1) |
| | | | | | | | | | | | | | | | | Cpu (2) |
| | | | | | | | | | | | | | | | | cell multiblock physical read (3) |
| 10 | PX RECEIVE | | 2G | 680K | 207 | +13 | 20 | 2G | | | | | | | 3.67 | Cpu (746) |
| 11 | PX SEND HASH | :TQ10001 | 2G | 680K | 205 | +13 | | | | | | | | | 7.75 | Cpu (1575) |
| | | | | | | | | | | | | | | | | PX qref latch (1) |
| 12 | PX BLOCK ITERATOR | | 2G | 680K | 204 | +13 | | | | | | | | | 1.59 | Cpu (324) |
| 13 | TABLE ACCESS STORAGE FULL | XXX_BALANCE | 2G | 680K | 203 | +12 | | | | | | | | | 2.77 | Cpu (387) |
| | | | | | | | | | | | | | | | | cell smart table scan (177) |
=================================================================================================================================================================================

Some Observation Made here based on above SQL monitor report:

a) Cell smart Scan happened for XXX_BALANCE table (which is good though isn't it?)
b) Cell mutiblock read count for STG_EOD_XXX_BAL_TABLE , and this didn't offload.
c) XXX_BALANCE cell smart scan took nearly 3 minutes? (good)
d) 12 Seconds to get blocks of STG_EOD_x_BAL_TABLE table? (good)
e) 16261 seconds for HASH JOIN OUTER BUFFERED( Bad)
d) MERGE for 16052 seconds(Bad)
f) cell single block physical read (15469) for Merge at Step 1) of explain plan (This seems to be serious issue here),

It should be noted that this table XXX_BALANCE had primary key on two columns.Also table XXX_BALANCE table and STG_EOD_XXX_BAL_TABLE have Degree of 10, which means scan on these statements would be in parallel. Now here is Gotcha?
I noticed the Merge at step 1) of explain plan above, parallel didn't occur? Even we have defined Degree for the table?

So we have three issue here(primary key on table,high cell single block p read and no parallel for Merge at step1) discussed above for which i worked upon. Since the parallel operation(when actual merging i.e. inserting/updating data in table) didn't occur and so Hugh cell single block physical read operation to read the require set of data to get it updates/inserted.

It should be noted that Cell smart Scan for XXX_BALANCE table happened on cell storage so this obviously means that there would be no data inside the buffer cache of database server.Database will perform its operation very fast like updating/deleting data if data is already present in buffer cache if not then it has to read the required set of data back from disk, which is why we see(cell single block physical read).

So solution proposed
a) Try dropping primary key before Merge
b) Cell offload Disable(disable smart scan)
c) Use parallel DML or use hint parallel

Obviously dropping primary would be some relief but customer was not happy with this stretegy so i rollout this solution.
Now it was time to check performance when smart scan is disable and parallel hint.
Why i think smart scan disable will work? The reason is database will update/insert the required result set if the data is already present in database buffer cache and in case of smart Scan enabled data wont be.

I set following session level parameter for this:

alter session set cell_offload_processing=false;
alter session enable parallel dml;

The result i got was a surprise. The Merge statement got over in 15 mins. :)

Below is the final result and report of SQL monitoring:

MERGE INTO /*+ parallel(XXX_BALANCE 16) */ XXX_UAT.XXX_BALANCE USING ( SELECT ACID, EOD_DATE, LKP_BAL_TYPE_ID, TRAN_DATE_BAL, TRAN_DATE_TOT_TRAN, VALUE_DATE_BAL, VALUE_DATE_TOT_TRAN, END_EOD_DATE, LCHG_TIME, RCRE_TIME FROM BOB_UAT_STG.STG_EOD_x_BAL_TABLE WHERE FLG_IUD IS NULL ) T ON (XXX_UAT.XXX_BALANCE.ACCT_ID = T.ACID AND XXX_UAT.XXX_BALANCE.ACCT_BAL_CALCULATED_DT = T.EOD_DATE AND XXX_UAT.XXX_BALANCE.BAL_TYPE_ID = T.LKP_BAL_TYPE_ID) WHEN MATCHED THEN UPDATE SET
BAL_AMT=T.TRAN_DATE_BAL, TRAN_DATE_TOT_TRAN=T.TRAN_DATE_TOT_TRAN, VALUE_DATE_BAL=T.VALUE_DATE_BAL, VALUE_DATE_TOT_TRAN=T.VALUE_DATE_TOT_TRAN, END_EOD_DATE=T.END_EOD_DATE, UPDATED_BY=1117146, UPDATED_ON=CURRENT_DATE, LCHG_TIME=T.LCHG_TIME, RCRE_TIME =T.RCRE_TIME WHEN NOT MATCHED THEN INSERT (ACCT_ID, ACCT_BAL_CALCULATED_DT, BAL_TYPE_ID, BAL_AMT, TRAN_DATE_TOT_TRAN, VALUE_DATE_BAL, VALUE_DATE_TOT_TRAN, END_EOD_DATE, INSERTED_BY, INSERTED_ON, LCHG_TIME, RCRE_TIME) VALUES( T.ACID, T.EOD_DATE,
T.LKP_BAL_TYPE_ID, T.TRAN_DATE_BAL, T.TRAN_DATE_TOT_TRAN, T.VALUE_DATE_BAL, T.VALUE_DATE_TOT_TRAN, T.END_EOD_DATE, 1117146, CURRENT_DATE, T.LCHG_TIME, T.RCRE_TIME )

Global Stats
============================================================================================================================================
| Elapsed | Cpu | IO | Application | Concurrency | Cluster | Other | Fetch | Buffer | Read | Read | Write | Write | Cell |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes | Reqs | Bytes | Offload |
============================================================================================================================================
| 14485 | 4548 | 2882 | 0.00 | 4.87 | 0.10 | 7050 | 1 | 57M | 3M | 365GB | 7465 | 1GB | |
============================================================================================================================================
Parallel Execution Details (DOP=16 , Servers Allocated=32)
===================================================================================================================================================================================================================
| Name | Type | Server# | Elapsed | Cpu | IO | Application | Concurrency | Cluster | Other | Buffer | Read | Read | Write | Write | Cell | Wait Events |
| | | | Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes | Reqs | Bytes | Offload | (sample #) |
===================================================================================================================================================================================================================
| PX Coordinator | QC | | 46 | 0.55 | 3.95 | 0.00 | 3.36 | 0.01 | 39 | 10791 | 189 | 20MB | 101 | 20MB | -49.25% | os thread startup (3) |
| | | | | | | | | | | | | | | | | enq: CR - block range reuse ckpt (37) |
| | | | | | | | | | | | | | | | | name-service call wait (1) |
| | | | | | | | | | | | | | | | | direct path read temp (3) |
| | | | | | | | | | | | | | | | | direct path write temp (1) |
| p020 | Set 1 | 1 | 538 | 126 | 114 | | 0.00 | 0.00 | 298 | 450K | 68330 | 566MB | 295 | 35MB | -5.26% | free buffer waits (294) |
| | | | | | | | | | | | | | | | | cell single block physical read (116) |
| p021 | Set 1 | 2 | 485 | 126 | 89 | | | 0.00 | 270 | 399K | 57939 | 485MB | 294 | 34MB | -6.38% | free buffer waits (264) |
| | | | | | | | | | | | | | | | | cell single block physical read (89) |
| p022 | Set 1 | 3 | 513 | 126 | 97 | | 0.00 | | 290 | 439K | 65610 | 545MB | 295 | 35MB | -6.38% | free buffer waits (303) |
| | | | | | | | | | | | | | | | | cell single block physical read (88) |
| p023 | Set 1 | 4 | 489 | 125 | 99 | | 0.00 | | 265 | 383K | 56399 | 473MB | 294 | 34MB | -6.38% | free buffer waits (256) |
| | | | | | | | | | | | | | | | | cell single block physical read (108) |
| p024 | Set 1 | 5 | 505 | 126 | 101 | | 0.00 | | 278 | 420K | 62969 | 524MB | 294 | 34MB | -6.38% | free buffer waits (275) |
| | | | | | | | | | | | | | | | | cell single block physical read (103) |
| p025 | Set 1 | 6 | 533 | 128 | 91 | | 0.00 | 0.00 | 314 | 489K | 75381 | 621MB | 295 | 35MB | -5.26% | free buffer waits (309) |
| | | | | | | | | | | | | | | | | cell single block physical read (90) |
| p026 | Set 1 | 7 | 537 | 128 | 97 | | 0.00 | 0.00 | 312 | 489K | 75614 | 623MB | 294 | 34MB | -5.26% | free buffer waits (310) |
| | | | | | | | | | | | | | | | | cell single block physical read (100) |
| p027 | Set 1 | 8 | 581 | 130 | 104 | | 0.39 | | 347 | 558K | 92066 | 752MB | 295 | 35MB | -4.17% | free buffer waits (361) |
| | | | | | | | | | | | | | | | | cell single block physical read (93) |
| p028 | Set 1 | 9 | 549 | 128 | 88 | | 0.00 | | 333 | 494K | 77849 | 640MB | 295 | 35MB | -5.26% | free buffer waits (327) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | cell single block physical read (94) |
| p029 | Set 1 | 10 | 550 | 127 | 92 | | 0.00 | | 331 | 506K | 79705 | 655MB | 294 | 34MB | -5.26% | free buffer waits (345) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Normal (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (75) |
| p030 | Set 1 | 11 | 527 | 126 | 99 | | | | 302 | 449K | 68054 | 564MB | 294 | 34MB | -5.26% | free buffer waits (307) |
| | | | | | | | | | | | | | | | | cell single block physical read (91) |
| p031 | Set 1 | 12 | 518 | 126 | 100 | | 0.00 | | 292 | 434K | 65787 | 546MB | 293 | 34MB | -6.38% | free buffer waits (294) |
| | | | | | | | | | | | | | | | | cell single block physical read (94) |
| p032 | Set 1 | 13 | 540 | 126 | 106 | | | | 308 | 444K | 68120 | 564MB | 295 | 35MB | -5.26% | free buffer waits (304) |
| | | | | | | | | | | | | | | | | cell single block physical read (105) |
| p033 | Set 1 | 14 | 495 | 125 | 88 | | 0.97 | | 281 | 400K | 59531 | 497MB | 293 | 34MB | -6.38% | buffer busy waits (1) |
| | | | | | | | | | | | | | | | | free buffer waits (284) |
| | | | | | | | | | | | | | | | | cell single block physical read (83) |
| p034 | Set 1 | 15 | 535 | 127 | 94 | | | 0.00 | 314 | 463K | 69970 | 579MB | 294 | 34MB | -5.26% | free buffer waits (321) |
| | | | | | | | | | | | | | | | | cell single block physical read (90) |
| p035 | Set 1 | 16 | 494 | 125 | 93 | | 0.00 | | 276 | 395K | 58848 | 492MB | 294 | 34MB | -6.38% | free buffer waits (283) |
| | | | | | | | | | | | | | | | | cell single block physical read (84) |
| p036 | Set 2 | 1 | 384 | 159 | 86 | | 0.00 | 0.00 | 139 | 3M | 122K | 23GB | 166 | 41MB | | free buffer waits (127) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | write complete waits (2) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (73) |
| | | | | | | | | | | | | | | | | direct path read (8) |
| | | | | | | | | | | | | | | | | direct path write (9) |
| p037 | Set 2 | 2 | 378 | 158 | 83 | | 0.01 | 0.05 | 136 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (124) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | write complete waits (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | reliable message (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (70) |
| | | | | | | | | | | | | | | | | direct path read (5) |
| | | | | | | | | | | | | | | | | direct path write (5) |
| p038 | Set 2 | 3 | 376 | 156 | 84 | | 0.03 | | 136 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (122) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | cell single block physical read (78) |
| | | | | | | | | | | | | | | | | direct path read (5) |
| | | | | | | | | | | | | | | | | direct path write (9) |
| p039 | Set 2 | 4 | 387 | 159 | 85 | | 0.00 | 0.00 | 143 | 3M | 123K | 23GB | 166 | 41MB | | free buffer waits (132) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | cell single block physical read (68) |
| | | | | | | | | | | | | | | | | direct path read (4) |
| | | | | | | | | | | | | | | | | direct path write (9) |
| p040 | Set 2 | 5 | 374 | 159 | 81 | | 0.00 | 0.00 | 134 | 3M | 122K | 23GB | 166 | 41MB | | free buffer waits (121) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | cell single block physical read (79) |
| | | | | | | | | | | | | | | | | direct path read (6) |
| | | | | | | | | | | | | | | | | direct path write (7) |
| p041 | Set 2 | 6 | 374 | 159 | 81 | | 0.00 | 0.00 | 134 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (129) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | reliable message (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (68) |
| | | | | | | | | | | | | | | | | direct path read (6) |
| | | | | | | | | | | | | | | | | direct path write (6) |
| p042 | Set 2 | 7 | 379 | 158 | 81 | | 0.00 | 0.00 | 140 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (132) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (74) |
| | | | | | | | | | | | | | | | | direct path read (7) |
| | | | | | | | | | | | | | | | | direct path write (6) |
| p043 | Set 2 | 8 | 371 | 155 | 82 | | 0.00 | 0.00 | 134 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (124) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | reliable message (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (74) |
| | | | | | | | | | | | | | | | | direct path read (9) |
| | | | | | | | | | | | | | | | | direct path write (5) |
| p044 | Set 2 | 9 | 377 | 154 | 84 | | 0.00 | 0.01 | 139 | 3M | 121K | 22GB | 166 | 41MB | | free buffer waits (126) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (73) |
| | | | | | | | | | | | | | | | | direct path read (4) |
| | | | | | | | | | | | | | | | | direct path write (8) |
| p045 | Set 2 | 10 | 385 | 158 | 83 | | 0.00 | 0.00 | 144 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (131) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (71) |
| | | | | | | | | | | | | | | | | direct path read (10) |
| | | | | | | | | | | | | | | | | direct path write (5) |
| p046 | Set 2 | 11 | 380 | 157 | 85 | | 0.00 | 0.00 | 137 | 3M | 123K | 22GB | 166 | 41MB | | free buffer waits (123) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (74) |
| | | | | | | | | | | | | | | | | direct path read (10) |
| | | | | | | | | | | | | | | | | direct path write (10) |
| p047 | Set 2 | 12 | 385 | 159 | 83 | | 0.00 | 0.01 | 142 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (133) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (74) |
| | | | | | | | | | | | | | | | | direct path read (5) |
| | | | | | | | | | | | | | | | | direct path write (7) |
| p048 | Set 2 | 13 | 379 | 158 | 84 | | 0.00 | 0.00 | 137 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (126) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | reliable message (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (77) |
| | | | | | | | | | | | | | | | | direct path read (8) |
| | | | | | | | | | | | | | | | | direct path write (7) |
| p049 | Set 2 | 14 | 368 | 157 | 81 | | 0.00 | 0.01 | 131 | 3M | 121K | 22GB | 166 | 41MB | | free buffer waits (118) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | write complete waits (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (1) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (71) |
| | | | | | | | | | | | | | | | | direct path read (3) |
| | | | | | | | | | | | | | | | | direct path write (8) |
| p050 | Set 2 | 15 | 378 | 158 | 86 | | 0.00 | 0.00 | 134 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (128) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | cell single block physical read (64) |
| | | | | | | | | | | | | | | | | direct path read (7) |
| | | | | | | | | | | | | | | | | direct path write (7) |
| p051 | Set 2 | 16 | 376 | 156 | 80 | | 0.08 | 0.00 | 141 | 3M | 122K | 22GB | 166 | 41MB | | free buffer waits (123) |
| | | | | | | | | | | | | | | | | log file switch completion (1) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (3) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | | | | reliable message (1) |
| | | | | | | | | | | | | | | | | cell single block physical read (82) |
| | | | | | | | | | | | | | | | | direct path read (4) |
| | | | | | | | | | | | | | | | | direct path write (7) |
===================================================================================================================================================================================================================
SQL Plan Monitoring Details (Plan Hash Value=3023935004)
========================================================================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Write | Write | Mem | Temp | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | Reqs | Bytes | (Max) | (Max) | (%) | (# samples) |
========================================================================================================================================================================================================================================
| 0 | MERGE STATEMENT | | | | 512 | +421 | 33 | 32 | | | | | | | 0.35 | free buffer waits (6) |
| | | | | | | | | | | | | | | | | Cpu (1) |
| | | | | | | | | | | | | | | | | enq: CR - block range reuse ckpt (37) |
| | | | | | | | | | | | | | | | | reliable message (5) |
| 1 | PX COORDINATOR | | | | 932 | +0 | 33 | 32 | 112 | 20MB | 101 | 20MB | | | 0.06 | os thread startup (3) |
| | | | | | | | | | | | | | | | | name-service call wait (1) |
| | | | | | | | | | | | | | | | | direct path read temp (3) |
| | | | | | | | | | | | | | | | | direct path write temp (1) |
| 2 | PX SEND QC (RANDOM) | :TQ10004 | 8M | 852K | 96 | +833 | 16 | 32 | | | | | | | | |
| 3 | INDEX MAINTENANCE | XXX_BALANCE | | | 464 | +466 | 16 | 32 | 1M | 8GB | | | | | 45.62 | buffer busy waits (1) |
| | | | | | | | | | | | | | | | | free buffer waits (4837) |
| | | | | | | | | | | | | | | | | Cpu (123) |
| | | | | | | | | | | | | | | | | buffer exterminate (2) |
| | | | | | | | | | | | | | | | | cell single block physical read (1503) |
| 4 | PX RECEIVE | | 8M | 852K | 3 | +467 | 16 | 4M | | | | | | | | |
| 5 | PX SEND RANGE | :TQ10003 | 8M | 852K | 5 | +464 | 16 | 4M | | | | | | | | |
| 6 | MERGE | XXX_BALANCE | | | 254 | +215 | 16 | 0 | 2M | 12GB | 2656 | 651MB | 9M | | 25.75 | free buffer waits (2011) |
| | | | | | | | | | | | | | | | | log file switch completion (16) |
| | | | | | | | | | | | | | | | | write complete waits (4) |
| | | | | | | | | | | | | | | | | Cpu (261) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Get Keys (48) |
| | | | | | | | | | | | | | | | | buffer exterminate (15) |
| | | | | | | | | | | | | | | | | latch: object queue header operation (9) |
| | | | | | | | | | | | | | | | | cell single block physical read (1170) |
| | | | | | | | | | | | | | | | | direct path write (115) |
| 7 | PX RECEIVE | | 8M | 852K | 247 | +215 | 16 | 8M | | | | | | | 0.07 | Cpu (10) |
| 8 | PX SEND HYBRID (ROWID PKEY) | :TQ10002 | 8M | 852K | 252 | +215 | 16 | 8M | | | | | | | 0.19 | Cpu (27) |
| 9 | VIEW | | | | 252 | +215 | 16 | 8M | | | | | | | 0.01 | Cpu (1) |
| 10 | HASH JOIN OUTER BUFFERED | | 8M | 852K | 462 | +5 | 16 | 8M | 4708 | 552MB | 4708 | 552MB | 1G | 621M | 7.51 | Cpu (1065) |
| 11 | PX RECEIVE | | 8M | 1948 | 1 | +5 | 16 | 8M | | | | | | | | |
| 12 | PX SEND HASH | :TQ10000 | 8M | 1948 | 2 | +4 | 16 | 8M | | | | | | | 0.01 | Cpu (1) |
| 13 | PX BLOCK ITERATOR | | 8M | 1948 | 2 | +4 | 16 | 8M | | | | | | | 0.01 | Cpu (1) |
| 14 | TABLE ACCESS STORAGE FULL | STG_EOD_x_BAL_TABLE | 8M | 1948 | 1 | +5 | 343 | 8M | 991 | 802MB | | | | | | |
| 15 | PX RECEIVE | | 2G | 849K | 211 | +5 | 16 | 2G | | | | | | | 5.26 | Cpu (744) |
| | | | | | | | | | | | | | | | | PX Deq: Table Q Normal (1) |
| 16 | PX SEND HASH | :TQ10001 | 2G | 849K | 211 | +5 | 16 | 2G | | | | | | | 9.99 | Cpu (1416) |
| 17 | PX BLOCK ITERATOR | | 2G | 849K | 211 | +5 | 16 | 2G | | | | | | | 2.34 | Cpu (332) |
| 18 | TABLE ACCESS STORAGE FULL | XXX_BALANCE | 2G | 849K | 211 | +5 | 343 | 2G | 352K | 343GB | | | | | 2.82 | Cpu (299) |
| | | | | | | | | | | | | | | | | direct path read (101) |
========================================================================================================================================================================================================================================

Some observation here:
1) Merge at step 0) is now actually happening in parallel
2) No smart scan for XXX_BALANCE table this time
3) Direct path read operation for both tables but with smart scan off
4) Very less cell single block physical read operation
5) new event occur this time its "free buffer wait"
6) Table xxx_BALANCE done in 211 seconds
7) Table STG_EOD_XXX_BAL_TABLE done in 1 seconds(probably data was already present in buffer cache)
8) New event INDEX MAINTENANCE appeared why? Because we of direct path read.

So the performance has been increased with smart scan off and parallel hint in merge statement. Now database is able to process faster when data is already on database server machine (though in pga). And There is some extra cost involved for maintaining the index that why we see INDEX MAINTENANCE operation in xplain plan.

Conclusion -> some times smart scan wont help in gaining performance when data find itself that i can process faster enough when data is available in database server. There is some speculation about Merge statement as we seen it didn't occur in parallel

PS-You are welcome to comment anything if you feel my interpretation is wrong somewhere. My purpose for blogging would be solved btw :D

Oracle n NoSQL

Saturday, May 19, 2012

Exadata Performance Issue/Problem: High time for Merge

1 comment: