Oracle Standard Edition One 11.2.0.1.0 on Oracle Linux 5
At this point I'm just looking for advice on how to
approach this issue.
Starting this last Monday, we observed several jobs that normally completed in one to five minutes begin taking over an hour. These are long-standing procedures. No code changed, no hardware changed, no db config changed. We fixed one yesterday with a minor mod to the code to improve the plan. We figure 'what changed' was an update to stats and a plan change by the optimizer.
Now another has risen to the top of the list, and is a much more complex situation, involving a view that selects across a db link.
Here's the overall structure of the query
insert into local_table
(select cola
, colb
, colc
from local_view
where some-conditions
)
and LOCAL_VIEW is structured like this
select a_column_list
from (select a.*,
b.item_num,
c.item_num
from remote_view@remote_db a
local_master_items b,
local_master_items c
where a.item_id = b.new_item_num
and a.kit_item_num = c.new_item_num(+)
),
local_master_items
where (item_id = new_item_num or
item_id = item_num
)
and status_code='A';
and REMOTE_VIEW is
really ugly. the printout runs 15 pages, full of nested CASE clauses, some individual CASE clauses running 3 pages each. Really, really ugly.
Not looking for detailed help, just some ideas on where to start. Does the overall structure suggest some built in ineffeciencies? If we need to attack tuning individual queries (views), would you start with the view definition at the remote link?
I ran a trace and tkprof on just that remote view. On the remote db, I traced a "SELCECT * FROM REMOTE_VIEW". Stats on that are as follows:
SQL ID: d0yxf44vvwuju
Plan Hash: 1017066403
select *
from
dw.for_roy_sales_extract_vw
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 99332 215.06 298.93 8228312 7654809 9930 1489966
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 99336 215.06 298.93 8228312 7654809 9930 1489966
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 5 (SYSTEM)
Rows Row Source Operation
------- ---------------------------------------------------
1489966 HASH JOIN RIGHT OUTER (cr=7654809 pr=8228312 pw=1221834 time=3508970 us cost=2450157 size=169759956882 card=657984329)
2913 TABLE ACCESS FULL ROYALTY_KIT (cr=38 pr=0 pw=0 time=506 us cost=12 size=168954 card=2913)
1489787 HASH JOIN RIGHT OUTER (cr=7654771 pr=8228312 pw=1221834 time=3201542 us cost=2448081 size=131596865800 card=657984329)
250 TABLE ACCESS FULL LK_COUNTRY (cr=4 pr=0 pw=0 time=0 us cost=3 size=2000 card=250)
1489787 HASH JOIN RIGHT OUTER (cr=7654767 pr=8228312 pw=1221834 time=2269242 us cost=2446014 size=126332991168 card=657984329)
155 TABLE ACCESS FULL RETURN_REASON (cr=3 pr=0 pw=0 time=0 us cost=3 size=1386 card=154)
1489787 HASH JOIN (cr=7654764 pr=8228312 pw=1221834 time=1206370 us cost=2443947 size=120411132207 card=657984329)
39044664 HASH JOIN (cr=4565349 pr=5137608 pw=572291 time=27036622 us cost=1347022 size=1558288236 card=15129012)
29568306 TABLE ACCESS FULL SALES_HEADER (cr=1883889 pr=1883877 pw=0 time=12938973 us cost=512113 size=236517560 card=29564695)
39044789 FILTER (cr=2681460 pr=2681439 pw=0 time=82806872 us)
71272240 HASH JOIN RIGHT OUTER (cr=2681460 pr=2681439 pw=0 time=69614256 us cost=730205 size=1437256140 card=15129012)
316 TABLE ACCESS FULL ORG_LOCATION (cr=7 pr=0 pw=0 time=105 us cost=4 size=5040 card=315)
71272240 TABLE ACCESS FULL SALES_DETAIL (cr=2681453 pr=2681439 pw=0 time=27887584 us cost=729978 size=5606996323 card=70974637)
42500473 TABLE ACCESS FULL INVENTORY_EOM (cr=3089415 pr=3089401 pw=0 time=77439856 us cost=829808 size=3359301920 card=41991274)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
1489966 HASH JOIN (RIGHT OUTER)
2913 TABLE ACCESS MODE: ANALYZED (FULL) OF 'ROYALTY_KIT' (TABLE)
1489787 HASH JOIN (RIGHT OUTER)
250 TABLE ACCESS MODE: ANALYZED (FULL) OF 'LK_COUNTRY' (TABLE)
1489787 HASH JOIN (RIGHT OUTER)
155 TABLE ACCESS MODE: ANALYZED (FULL) OF 'RETURN_REASON'
(TABLE)
1489787 HASH JOIN
39044664 HASH JOIN
29568306 TABLE ACCESS MODE: ANALYZED (FULL) OF 'SALES_HEADER'
(TABLE)
39044789 FILTER
71272240 HASH JOIN (RIGHT OUTER)
316 TABLE ACCESS MODE: ANALYZED (FULL) OF
'ORG_LOCATION' (TABLE)
71272240 TABLE ACCESS MODE: ANALYZED (FULL) OF
'SALES_DETAIL' (TABLE)
42500473 TABLE ACCESS MODE: ANALYZED (FULL) OF 'INVENTORY_EOM'
(TABLE)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 99333 0.00 0.06
Disk file operations I/O 14 0.00 0.00
kfk: async disk IO 79865 0.00 0.34
asynch descriptor resize 9 0.00 0.00
direct path read 27094 0.21 69.24
CSS initialization 1 0.00 0.00
CSS operation: query 6 0.00 0.00
CSS operation: action 1 0.00 0.00
direct path write temp 7183 0.01 6.21
local write wait 14895 0.01 7.05
os thread startup 1 0.01 0.01
KSV master wait 3 0.03 0.04
ASM file metadata operation 2 0.00 0.00
latch: cache buffers chains 11 0.00 0.00
db file sequential read 8 0.02 0.04
db file scattered read 2 0.00 0.00
direct path read temp 180 0.00 0.08
SQL*Net message from client 99333 7.62 113.36
SQL*Net break/reset to client 1 0.00 0.00
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 0
Fetch 99332 215.06 298.93 8228312 7654809 9930 1489966
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 99338 215.06 298.93 8228312 7654809 9930 1489966
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 99334 0.00 0.06
SQL*Net message from client 99334 7.62 113.36
Disk file operations I/O 14 0.00 0.00
kfk: async disk IO 79865 0.00 0.34
asynch descriptor resize 9 0.00 0.00
direct path read 27094 0.21 69.24
CSS initialization 1 0.00 0.00
CSS operation: query 6 0.00 0.00
CSS operation: action 1 0.00 0.00
direct path write temp 7183 0.01 6.21
local write wait 14895 0.01 7.05
os thread startup 1 0.01 0.01
KSV master wait 3 0.03 0.04
ASM file metadata operation 2 0.00 0.00
latch: cache buffers chains 11 0.00 0.00
db file sequential read 8 0.02 0.04
db file scattered read 2 0.00 0.00
direct path read temp 180 0.00 0.08
SQL*Net break/reset to client 1 0.00 0.00
log file sync 1 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 1 2 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 1 2 1
Misses in library cache during parse: 0
2 user SQL statements in session.
1 internal SQL statements in session.
3 SQL statements in session.
1 statement EXPLAINed in this session.
********************************************************************************
Trace file: dwstg_ora_15944_STEVENS.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
2 user SQL statements in trace file.
1 internal SQL statements in trace file.
3 SQL statements in trace file.
3 unique SQL statements in trace file.
1 SQL statements EXPLAINed using schema:
SYSTEM.prof$plan_table
Default table was used.
Table was created.
Table was dropped.
428267 lines in trace file.
416 elapsed seconds in trace file.
I killed the trace job after results started scolling on the screen, and am assuming that the 99k fetches matches to the 99k sqlnet waits as a result of the screen I/O (session was in a putty session, connected from my desktop to the server).