hash join waits on cpu 100% time
- From: GG <grzegorzof@xxxxxxxxxx>
- To: oracle-l@xxxxxxxxxxxxx
- Date: Sat, 03 Jan 2015 19:33:18 +0100
Hi,
we are on 11.2.0.2
and observing strange issue with hash join , which waits on CPU all the
time .
SQL> @snapper all 10 1 557
Sampling SID 557 with interval 10 seconds, taking 1 snapshots...
-- Session Snapper v4.14 BETA - by Tanel Poder (
http://blog.tanelpoder.com ) - Enjoy the Most Advanced Oracle
Troubleshooting Script on the Planet! :)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SID, USERNAME , TYPE, STATISTIC , DELTA, HDELTA/SEC,
%TIME, GRAPH , NUM_WAITS, WAITS/SEC, AVERAGES
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
557, SYS , STAT, session logical
reads , 47425, 5k,
, , , , 47,5k total buffer visits
557, SYS , STAT, consistent
gets , 47426,
5k, , , , , ~ per execution
557, SYS , STAT, consistent gets from
cache , 47426, 5k,
, , , , ~ per execution
557, SYS , STAT, consistent gets from cache
(fastpath) , 47426, 5k,
, , , , ~ per execution
557, SYS , STAT, calls to
kcmgcs , 150,
15,8, , , , , ~ per execution
557, SYS , STAT, no work - consistent read
gets , 47276, 4,98k,
, , , , ~ per execution
557, SYS , STAT, Cached Commit SCN
referenced , 1, ,11,
, , , , ~ per execution
557, SYS , STAT, table scans (short
tables) , 75, 7,9,
, , , , ~ per execution
557, SYS , STAT, table scan rows
gotten , 14843948,
1,56M, , , , , ~ per
execution
557, SYS , STAT, table scan blocks
gotten , 47276, 4,98k,
, , , , ~ per execution
557, SYS , STAT, buffer is pinned
count , 73, 7,69,
, , , , ,15 % buffer gets avoided
thanks to buffer pin caching
557, SYS , TIME, DB
CPU , 9340000,
984,04ms, 98.4%, [@@@@@@@@@@], , ,
557, SYS , TIME, sql execute elapsed
time , 10018685, 1,06s, 105.6%,
[##########], , ,
557, SYS , TIME, DB
time , 10018685,
1,06s, 105.6%, [##########], , , -5,55 % unaccounted time
Plan is rather usual and estimated vs actual rows are close .
Any ideas ?
QL Text
------------------------------
merge /*+ optimizer_features_enable='10.2.0.4'*/ into
user1.tab_personal_add d using (with cm as (select /*+ no_parallel */
cm1.cust_id, cm1.cus_no, cm1.cunit_id, nvl(cpa.rec_checksum,0)
rec_checksum from user1.TAB_MASTER cm1 full outer join
user1.tab_personal_add cpa on cm1.cust_id = cpa.cust_id where
cm1.cunit_id = 2) select cm.cust_id, a.* from
cdwmain.V_sa_tab_personal_add a, cm where a.time =
to_date('20150102','yyyymmdd') and a.exported = '0' and a.cunit_id =
cm.cunit_id and a.cus_no =
cm.cus_no and a.rec_checksum <> cm.rec_checksum ) f on ( d.cust_id =
f.cust_id ) when matched then update set d.cunit_id = f.cunit_id,
d.title = f.title, d.gender = f.gender, d.birth_date = f.birth_date,
d.birth_place = f.birth_place, d.type_doc = f.type_doc, d.id_number =
f.id_number, d.nr_id = f.nr_id, d.nip = f.nip, d.fathers_name =
f.fathers_name, d.maiden_name = f.maiden_name, d.mother_maiden =
f.mother_maiden, d.marital_stat = f.marital_stat, d.spec_sign =
f.spec_sign, d.inst_death =
f.inst_death, d.add_info = f.add_info, d.b_dep_no = f.b_dep_no,
d.numochildren = f.numochildren, d.cur_no = f.curr_no, d.inputter =
f.inputter, d.authoriser = f.authoriser, d.auditor = f.auditor_code,
d.audit_time = f.audit_date_time, d.glob_rec_date = f.input_date_time,
d.glob_last_wday = f.Time, d.record_status = f.record_status, d.co_code
= f.co_code, d.dept_code = f.dept_code, d.load_last_action = 'U',
d.load_date = to_date('20150102','yyyymmdd'), d.load_time =
SYSTIMESTAMP, d.cont_pref =
f.cont_pref, d.cont_type = f.cont_type, d.work_place = f.work_place,
d.income = f.income, d.act_size = f.act_size, d.perm_no = f.perm_no,
d.perm_valid = f.perm_valid, d.profession = f.profession, d.rec_checksum
= f.rec_checksum when not matched then insert /* + append */ (
d.cust_id, d.cunit_id, d.title, d.gender, d.birth_date, d.birth_place,
d.type_doc, d.id_number, d.nr_id, d.nip, d.fathers_name, d.maiden_name,
d.mother_maiden, d.marital_stat, d.spec_sign, d.inst_death, d.add_info,
d.b_dep_no, d.numochildren, d.cur_no, d.inputter, d.authoriser,
d.auditor, d.audit_time, d.glob_rec_date, d.glob_last_wday,
d.record_status, d.co_code, d.dept_code, d.load_last_action,
d.load_date, d.load_time, d.cont_pref, d.cont_type, d.work_place,
d.income, d.act_size, d.perm_no, d.perm_valid, d.profession,
d.rec_checksum) values ( f.cust_id, f.cunit_id, f.title, f.gender,
f.birth_date, f.birth_place, f.type_doc, f.id_number, f.nr_id, f.nip,
f.fathers_name, f.maiden_name, f.mother_maiden,
f.marital_stat, f.spec_sign, f.inst_death, f.add_info, f.b_dep_no,
f.numochildren, f.curr_no, f.inputter, f.authoriser, f.auditor_code,
f.audit_date_time, f.input_date_time, f.Time, f.record_status,
f.co_code, f.dept_code, 'I', to_date('20150102','yyyymmdd'),
SYSTIMESTAMP, f.cont_pref, f.cont_type, f.work_place, f.income,
f.act_size, f.perm_no, f.perm_valid, f.profession, f.rec_checksum )
Global Information
------------------------------
Status : EXECUTING
Instance ID : 1
Session : SYS (557:4349)
SQL ID : f57f0s4zd9b58
SQL Execution ID : 16777216
Execution Started : 01/03/2015 18:50:54
First Refresh Time : 01/03/2015 18:51:02
Last Refresh Time : 01/03/2015 19:07:39
Duration : 1005s
Module/Action : sqlplus@prod (TNS V1-V3)/-
Service : SYS$USERS
Program : sqlplus@prod (TNS V1-V3)
Global Stats
=============================================================================================
| Elapsed | Cpu | IO | PL/SQL | Other | Buffer | Read |
Read | Write | Write |
| Time(s) | Time(s) | Waits(s) | Time(s) | Waits(s) | Gets | Reqs |
Bytes | Reqs | Bytes |
=============================================================================================
| 1005 | 895 | 0.18 | 0.00 | 110 | 5M | 20 |
5MB | 20 | 5MB |
=============================================================================================
SQL Plan Monitoring Details (Plan Hash Value=3437768513)
===========================================================================================================================================================================
| Id | Operation | Name |
Rows | Cost | Time | Start | Execs | Rows | Mem | Activity |
Activity Detail |
| | | | (Estim) | | Active(s) |
Active | | (Actual) | | (%) | (# samples) |
===========================================================================================================================================================================
| 0 | MERGE STATEMENT | | |
| | | 1 | | | | |
| 1 | MERGE |
tab_personal_ADD | | | 986 | +8 |
1 | 0 | | | |
| 2 | VIEW | | | |
986 | +8 | 1 | 92 | | | |
| -> 3 | HASH JOIN | | 189K | 7641
| 1004 | +2 | 1 | 92 | 73M | 0.20 | Cpu (2) |
| 4 | HASH JOIN OUTER | | 202K |
5093 | 8 | +1 | 1 | 202K | | 0.10 | Cpu
(1) |
| 5 | HASH JOIN OUTER | | 202K
| 1283 | 1 | +8 | 1 | 202K | |
| |
| 6 | PARTITION LIST SINGLE |
| 202K | 611 | 1 | +8 | 1 | 202K |
| | |
| 7 | TABLE ACCESS FULL |
TAB_MASTER | 202K | 611 | 1 | +8 |
1 | 202K | | | |
| 8 | INDEX FAST FULL SCAN |
I3_tab_personal_ADD | 1M | 360 | 1 | +8 |
1 | 1M | | | |
| 9 | TABLE ACCESS FULL |
tab_personal_ADD | 1M | 1457 | 1 | +8 |
1 | 1M | | | |
| -> 10 | VIEW |
V_SA_tab_personal_ADD | 189K | 321 | 998 | +8 |
1 | 7663 | | | |
| -> 11 | TEMP TABLE TRANSFORMATION |
| | | 998 | +8 | 1 | 7663 |
| | |
| 12 | LOAD AS SELECT | |
| | 1 | +8 | 1 | 1 | |
| |
| 13 | TABLE ACCESS FULL |
SA_CUS_CRM_PRIM_ADD | 198K | 162 | 1 | +8 |
1 | 198K | | | |
| -> 14 | VIEW | | 189K | 159
| 998 | +8 | 1 | 7663 | | | |
| -> 15 | UNION-ALL | |
| | 998 | +8 | 1 | 7663 | |
| |
| 16 | FILTER | | |
| | | 1 | | | | |
| 17 | TABLE ACCESS FULL |
SA_tab_personal_ADD | 668K | 660 | | |
| | | | |
| -> 18 | VIEW | | 198K | 26
| 1002 | +4 | 7664 | 7635 | | 84.56 | Cpu (849) |
| -> 19 | TABLE ACCESS FULL |
SYS_TEMP_0FD9EA7E0_1E010D37 | 198K | 26 | 998 | +8 | 7664
| 2G | | 4.58 | Cpu (46) |
| -> 20 | TABLE ACCESS FULL |
SA_tab_personal_ADD | 189K | 159 | 998 | +8 |
1 | 7663 | | | |
| 21 | VIEW | | 198K | 26
| | | | | | | |
| 22 | TABLE ACCESS FULL |
SYS_TEMP_0FD9EA7E0_1E010D37 | 198K | 26 | | |
| | | | |
| 23 | FILTER | | |
| | | | | | | |
| 24 | TABLE ACCESS BY INDEX ROWID |
SA_tab_personal_ADD | 1 | 4 | | |
| | | | |
| 25 | INDEX RANGE SCAN |
SA_tab_personal_ADD_PKEY | 1 | 3 | | |
| | | | |
| 26 | VIEW | | 198K | 26
| | | | | | | |
| 27 | TABLE ACCESS FULL |
SYS_TEMP_0FD9EA7E0_1E010D37 | 198K | 26 | | |
| | | | |
| 28 | FILTER | | |
| | | | | | | |
| 29 | TABLE ACCESS BY INDEX ROWID |
SA_tab_personal_ADD | 1 | | | |
| | | | |
| 30 | INDEX RANGE SCAN |
SA_tab_personal_ADD_PKEY | 1 | | | |
| | | | |
===========================================================================================================================================================================
--
//www.freelists.org/webpage/oracle-l
Other related posts:
