一生产库，cpu利用率达到95%以上，通过分析发现是由一条sql语句影响，通过设置参数 _optimizer_rownum_pred_based_fkr来解决
------采样时间看数据库负载很高
-------sharepool 占用了大量的内存（说明数据里存在的硬解析较高，存大大量的字面值）
--------top5事件发现PX DEQ CREDIT SEND BLKD很高
Note:
等待事件"PX Deq Credit: need buffer" 和 "PX Deq Credit: send blkd"的发生，是在部分查询时，数据或信息通过另外的进程被改变了。至少有3个不同的主要问题可以导致这种等待事件。第一：当有大量的数据和信息在并发线程中被改变，我们可以看到很高的等待事件。导致这个原因可能是由于执行计划不对或者并发设置不对。第二：CPU资源或者接口上有问题。例如，一个CPU资源达到100%，进程就被CPU控制而不能快速传递数据。第三：并发查询被hang住了，因为一个进程出现PX Deq Credit: need buffer等待事件
---------从如下整体的统计信息来看，数据库的大部分时间都化在sql execute elapsed time上。
|
Statistic Name |
Time (s) |
% of DB Time |
|
sql execute elapsed time |
143,382.44 |
91.49 |
|
DB CPU |
82,112.02 |
52.39 |
|
parse time elapsed |
3,620.27 |
2.31 |
|
hard parse elapsed time |
1,429.93 |
0.91 |
|
connection management call elapsed time |
20.06 |
0.01 |
|
PL/SQL execution elapsed time |
16.67 |
0.01 |
|
repeated bind elapsed time |
3.19 |
0.00 |
|
sequence load elapsed time |
2.27 |
0.00 |
|
hard parse (sharing criteria) elapsed time |
1.03 |
0.00 |
|
PL/SQL compilation elapsed time |
0.86 |
0.00 |
|
failed parse elapsed time |
0.51 |
0.00 |
|
hard parse (bind mismatch) elapsed time |
0.04 |
0.00 |
|
DB time |
156,726.52 |
|
|
background elapsed time |
3,882.40 |
|
|
background cpu time |
356.82 |
|
---------从wait class上看时间都化在cpu的时间上。
Wait Class
· s - second
· cs - centisecond - 100th of a second
· ms - millisecond - 1000th of a second
· us - microsecond - 1000000th of a second
· ordered by wait time desc, waits desc
· %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0
|
Wait Class |
Waits |
%Time -outs |
Total Wait Time (s) |
Avg wait (ms) |
%Total Call Time |
|
CPU time |
|
|
82,112 |
|
52.39 |
|
User I/O |
3,296,101 |
0 |
32,057 |
10 |
20.45 |
|
Other |
2,357,592 |
5 |
18,260 |
8 |
11.65 |
|
Network |
18,175,262 |
|
7,402 |
0 |
4.72 |
|
Commit |
1,199,873 |
1 |
7,372 |
6 |
4.70 |
|
System I/O |
1,754,920 |
|
4,076 |
2 |
2.60 |
|
Application |
2,017,828 |
|
1,317 |
1 |
0.84 |
|
Concurrency |
102,800 |
0 |
726 |
7 |
0.46 |
|
Configuration |
202 |
4 |
7 |
34 |
0.00 |
-------查看当时的等待事件
-------查看事latch: cache buffers chains对应的sql语句大部分都类似的语句
0wnbhwrfvgktk
SELECT BILLFLOW_ID, PACKAGE_ID, FILE_CNT, BILLING_CYCLE_ID FROM (select * from B_FILE_PACKAGE ORDER BY CREATED_DATE) a where not exists (select * from B_PACKAGE_STATE_TRANS b where b.package_id = a.package_id and b.process_id =850) and A.STATE = 'RDY' AND BILLFLOW_ID in (1) and rownum <:RUWNUM
1qwx3mq126jn8
SELECT BILLFLOW_ID, PACKAGE_ID, FILE_CNT, BILLING_CYCLE_ID FROM (select * from B_FILE_PACKAGE ORDER BY CREATED_DATE) a where not exists (select * from B_PACKAGE_STATE_TRANS b where b.package_id = a.package_id and b.process_id =867) and A.STATE = 'RDY' AND BILLFLOW_ID in (21) and rownum <:RUWNUM
0cwbfbvucu2hs
SELECT BILLFLOW_ID, PACKAGE_ID, FILE_CNT, BILLING_CYCLE_ID FROM (select * from B_FILE_PACKAGE ORDER BY CREATED_DATE) a where not exists (select * from B_PACKAGE_STATE_TRANS b where b.package_id = a.package_id and b.process_id =866) and A.STATE = 'RDY' AND BILLFLOW_ID in (21) and rownum <:RUWNUM
--------类似的语句很多，基本相同，在此挑出一条重点分析（0wnbhwrfvgktk）
/oraclelog/tjbill/udump/tjbill_ora_15118.log
Note:
从上述得知，此语句时间大部分都花提取数据阶段。
----------此条语句的执行计划
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 0wnbhwrfvgktk, child number 1
-------------------------------------
SELECT BILLFLOW_ID, PACKAGE_ID, FILE_CNT, BILLING_CYCLE_ID FROM (select * from
B_FILE_PACKAGE ORDER BY CREATED_DATE) a where not exists
(select * from B_PACKAGE_STATE_TRANS b where b.package_id = a.package_id and b.process_id =850)
and A.STATE = 'RDY' AND BILLFLOW_ID in (1) and rownum <:RUWNUM
Plan hash value: 2172617882
---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | | 5490 (100)| |
|* 1 | COUNT STOPKEY | | | | | | |
| 2 | NESTED LOOPS ANTI | | 999 | 54945 | | 5490 (1)| 00:01:06 |
| 3 | VIEW | | 10654 | 468K| | 159 (2)| 00:00:02 |
| 4 | SORT ORDER BY | | 5790K| 242M| 400M| 86113 (2)| 00:17:14 |
|* 5 | TABLE ACCESS FULL | B_FILE_PACKAGE | 5790K| 242M| | 21064 (3)| 00:04:13 |
|* 6 | TABLE ACCESS BY INDEX ROWID| B_PACKAGE_STATE_TRANS | 5185K| 49M| | 1 (0)| 00:00:01 |
|* 7 | INDEX RANGE SCAN | IDX_B_PAG_STAT_TRANS | 2 | | | 1 (0)| 00:00:01 |
---------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------
1 - filter(ROWNUM<:RUWNUM)
5 - filter(("B_FILE_PACKAGE"."BILLFLOW_ID"=1 AND "B_FILE_PACKAGE"."STATE"='RDY'))
6 - filter("B"."PROCESS_ID"=850)
7 - access("B"."PACKAGE_ID"="A"."PACKAGE_ID")
Column Projection Information (identified by operation id):
-----------------------------------------------------------
1 - "PACKAGE_ID"[NUMBER,22], "FILE_CNT"[NUMBER,22], "BILLFLOW_ID"[NUMBER,22],
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
"BILLING_CYCLE_ID"[NUMBER,22]
2 - "PACKAGE_ID"[NUMBER,22], "FILE_CNT"[NUMBER,22], "BILLFLOW_ID"[NUMBER,22],
"BILLING_CYCLE_ID"[NUMBER,22]
3 - "PACKAGE_ID"[NUMBER,22], "FILE_CNT"[NUMBER,22], "BILLFLOW_ID"[NUMBER,22],
"BILLING_CYCLE_ID"[NUMBER,22]
4 - (#keys=1) "B_FILE_PACKAGE"."CREATED_DATE"[DATE,7], "B_FILE_PACKAGE"."PACKAGE_ID"[NUMBER,22],
"B_FILE_PACKAGE"."FILE_CNT"[NUMBER,22], "B_FILE_PACKAGE"."BILLFLOW_ID"[NUMBER,22],
"B_FILE_PACKAGE"."BILLING_CYCLE_ID"[NUMBER,22]
5 - "B_FILE_PACKAGE"."PACKAGE_ID"[NUMBER,22], "B_FILE_PACKAGE"."FILE_CNT"[NUMBER,22],
"B_FILE_PACKAGE"."BILLFLOW_ID"[NUMBER,22], "B_FILE_PACKAGE"."BILLING_CYCLE_ID"[NUMBER,22],
"B_FILE_PACKAGE"."CREATED_DATE"[DATE,7]
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
7 - "B".ROWID[ROWID,10]
----------查看BILL.B_FILE_PACKAGE表的列的索引情况
select index_owner,index_name,table_name,column_name,column_position,descend from dba_ind_columns where table_name='B_FILE_PACKAGE' and INDEX_OWNER='BILL';
INDEX_OWNER INDEX_NAME TABLE_NAME COLUMN_NAME COLUMN_POSITION DESC
--------------- ------------------------------ ------------------------------ ------------------------- --------------- ----
BILL IDX_FLOW_FLAG_PACKAGE B_FILE_PACKAGE BILLFLOW_ID 1 ASC
BILL IDX_FLOW_FLAG_PACKAGE B_FILE_PACKAGE BILLDB_FLAG 2 ASC
BILL IDX_FLOW_FLAG_PACKAGE B_FILE_PACKAGE PACKAGE_ID 3 ASC
BILL IDX_FLOWID_STATE B_FILE_PACKAGE BILLFLOW_ID 1 ASC
BILL IDX_FLOWID_STATE_DATE B_FILE_PACKAGE BILLFLOW_ID 1 ASC
BILL IDX_FLOWID_STATE_DATE B_FILE_PACKAGE STATE 2 ASC
BILL IDX_FLOWID_STATE_DATE B_FILE_PACKAGE CREATED_DATE 3 ASC
BILL IDX_FILE_PAK_ID B_FILE_PACKAGE PACKAGE_ID 1 ASC
BILL IDX_FLOWID_STATE B_FILE_PACKAGE STATE 2 ASC
--------------10046--------------------
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> oradebug setmypid;
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12;
Statement processed.
SQL> set timing on
SQL> SELECT BILLFLOW_ID, PACKAGE_ID, FILE_CNT, BILLING_CYCLE_ID
2 FROM
3 (select * from bill.B_FILE_PACKAGE ORDER BY CREATED_DATE) a
4 where not exists (select * from bill.B_PACKAGE_STATE_TRANS
5 b where b.package_id = a.package_id and b.process_id =850)
6 and A.STATE = 'RDY' AND BILLFLOW_ID in (1) and
7 rownum <1000;
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81669818 369 11309
1 81669819 6 11309
1 81669820 18 0
1 81669821 30 11309
1 81669822 15 11309
1 81669823 1 0
1 81669824 2 11309
1 81669825 1 0
1 81669826 1 0
1 81669827 1 0
1 81669828 2 11309
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81669829 1 0
1 81669830 1 0
1 81669831 2 0
1 81669832 1 0
1 81669833 1 0
1 81669834 1 0
1 81669836 1 0
1 81669835 2 11309
1 81669837 1 0
1 81669838 1 0
1 81669839 1 0
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81669840 1 0
1 81669841 1 0
1 81669842 1 0
1 81669843 1 0
1 81669844 1 0
1 81669845 1 0
1 81669846 1 0
1 81669847 1 0
1 81669848 1 0
1 81669849 42 11309
1 81669850 8 11309
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81669851 1 11309
1 81669852 312 11309
1 81669853 7 11309
1 81669854 1 11309
1 81669855 5 11309
1 81669857 6 11309
1 81669856 173 11309
40 rows selected.
Elapsed: 00:02:51.82 ======》现在的消耗时间
Note:
没关闭_ optimizer_rownum_pred_based_fkr之前执行计划走的是nested loops ，主要时间都消耗在nested loops上time=167s左右。
===================================================================================================================
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> alter session set "_optimizer_rownum_pred_based_fkr"=false;
Session altered.
SQL> set timing on
SQL> oradebug setmypid;
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12;
Statement processed.
SQL> SELECT BILLFLOW_ID, PACKAGE_ID, FILE_CNT, BILLING_CYCLE_ID
FROM
(select * from bill.B_FILE_PACKAGE ORDER BY CREATED_DATE) a
where not exists (select * from bill.B_PACKAGE_STATE_TRANS
b where b.package_id = a.package_id and b.process_id =850)
2 3 4 5 6 and A.STATE = 'RDY' AND BILLFLOW_ID in (1) and
7 rownum <1000;
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81668860 9 11309
1 81668859 332 11309
1 81668861 305 11309
1 81668862 5 11309
1 81668863 1 11309
1 81668864 78 11309
1 81668865 7 11309
1 81668866 3 11309
1 81668867 22 11309
1 81668868 22 11309
1 81668869 4 0
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81668870 18 0
1 81668871 33 11309
1 81668872 1 0
1 81668873 2 11309
1 81668874 1 0
1 81668875 2 11309
1 81668876 1 0
1 81668878 1 0
1 81668877 2 11309
1 81668879 1 0
1 81668880 1 0
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81668881 1 0
1 81668882 1 0
1 81668884 1 0
1 81668883 2 11309
1 81668885 1 0
1 81668886 3 0
1 81668888 1 0
1 81668887 1 0
1 81668889 2 11309
1 81668890 1 0
1 81668891 2 11309
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81668892 1 0
1 81668893 3 0
1 81668894 3 11309
1 81668895 1 0
1 81668896 4 11309
1 81668897 6 11309
1 81668898 3 11309
1 81668899 3 11309
1 81669100 1 0
1 81669101 2 11309
1 81669102 5 11309
BILLFLOW_ID PACKAGE_ID FILE_CNT BILLING_CYCLE_ID
----------- ---------- ---------- ----------------
1 81669103 3 11309
1 81669105 3 11309
1 81669104 2 11309
1 81669106 2 0
1 81669107 3 0
1 81669108 8 11309
1 81669109 49 11309
1 81669110 1 11309
1 81669111 1 11309
1 81669112 30 11309
1 81669113 3 11309
55 rows selected.
Elapsed: 00:00:40.30 ====》执行alter session set "_optimizer_rownum_pred_based_fkr"=false;后的消耗时间
SQL> oradebug event 10046 trace name oradebug event 10046 trace name context off;
SQL>
SQL> oradebug event 10046 trace name context off;
Statement processed.
SQL>
SQL>
SQL> oradebug tracefile_name
/oraclelog/tjbill/udump/tjbill_ora_10904.trc
SQL>
Note：
关闭_optimizer_rownum_pred_based_fkr之后执行计划走的是hash join （最佳的）消耗时间39s 左右。消耗时间降低了167s/39s=4.2倍左右。
+ buffer gets reduced from 18455275 to 247494
+ elapsed time reduced from 167 to 39 seconds.
临时解决方法
alter system set "_optimizer_rownum_pred_based_fkr"=false;
SQLT (SQLTXPLAIN) - Tool that helps to diagnose a SQL statement performing poorly or one that produces wrong results (Doc ID 215187.1)
创建的密码为oracle
Cd /oracle/multnovo/hurp/sqlt/run
Sqlplus / as sysdba
SQL> start sqltxtract.sql 0wnbhwrfvgktk