ITPub博客

首页 > Linux操作系统 > Linux操作系统 > [20131122]跟踪sql profile的操作.txt

[20131122]跟踪sql profile的操作.txt

原创 Linux操作系统 作者:lfree 时间:2013-11-22 10:50:43 0 删除 编辑
[20131122]跟踪sql profile的操作.txt

sql profile是11G的新特性,前几天我在给别人做优化时,偷懒直接使用toad,step by step分析使用sql profile,导致系统执行缓慢,不得不中断分析.今天有空跟踪sql profile的操作看看,了解一些过程.

SCOTT@test> @ver
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

1.建立测试环境:
create table t pctfree 99 as select rownum id,lpad('x',1000,'x')  name from dual connect by level<=1e3;
create index i_t_id on t(id) ;
alter table t modify(id NOT NULL);
exec dbms_stats.gather_table_stats(user, 'T',  no_invalidate => false);

2.建立测试例子:

SCOTT@test> select /*+ full(t) */ count(*) from t;
  COUNT(*)
----------
      1000

SCOTT@test> @dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  cdwnbcfy42f8b, child number 0
-------------------------------------
select /*+ full(t) */ count(*) from t
Plan hash value: 2966233522
---------------------------------------------------------
| Id  | Operation          | Name | E-Rows | Cost (%CPU)|
---------------------------------------------------------
|   0 | SELECT STATEMENT   |      |        |   279 (100)|
|   1 |  SORT AGGREGATE    |      |      1 |            |
|   2 |   TABLE ACCESS FULL| T    |   1000 |   279   (0)|
---------------------------------------------------------

--由于使用了提示执行计划选择全表扫描.现在使用sql profile来优化这条语句.

3.使用与跟踪sql profile:

@10046on 12

DECLARE
  ret_val VARCHAR2(4000);
BEGIN
  ret_val := DBMS_SQLTUNE.CREATE_TUNING_TASK(
                sql_id          => 'cdwnbcfy42f8b',
                plan_hash_value => NULL,
                scope       => 'COMPREHENSIVE',
                time_limit  => 1800,
                task_name   => 'TASK1',
                description => 'test');
  --:rv := ret_val;
END;
/

Begin
  Dbms_Sqltune.EXECUTE_TUNING_TASK('TASK1');
End;
/
@10046off

--select Dbms_Sqltune.REPORT_TUNING_TASK('TASK1', 'TEXT', 'TYPICAL') report from dual;
--execute dbms_sqltune.accept_sql_profile(task_name => 'TASK1', replace => TRUE);

4.分析跟踪文件:
--$ ./trimsql.sh  /u01/app/oracle11g/diag/rdbms/test/test/trace/test_ora_26538_127_0_0_1.trc > /tmp/task1.txt
$ tkprof  /u01/app/oracle11g/diag/rdbms/test/test/trace/test_ora_27568_127_0_0_1.trc
....
********************************************************************************

SQL ID: 4jh8pskb3zgu0 Plan Hash: 2966233522

select /*+ full(t) */ count(*)
from
 t


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute     10      0.00       0.00          0          0          0           0
Fetch       10      0.02       0.02          0      10040          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       21      0.02       0.02          0      10040          0          10

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84     (recursive depth: 1)
********************************************************************************

SQL ID: 4jh8pskb3zgu0 Plan Hash: 3548397654

select /*+ full(t) */ count(*)
from
 t


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute     10      0.00       0.00          0          0          0           0
Fetch       10      0.00       0.00          0         60          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       21      0.00       0.00          0         60          0          10

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84     (recursive depth: 1)
********************************************************************************

SQL ID: 4jh8pskb3zgu0 Plan Hash: 4021579484

select /*+ full(t) */ count(*)
from
 t


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute     10      0.00       0.00          0          0          0           0
Fetch       10      0.00       0.00          0         40          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       21      0.00       0.00          0         40          0          10

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84     (recursive depth: 1)
********************************************************************************

--从这里分析可以发现每种不同的执行计划,执行10次,如果存在很慢的执行方式,在生产系统执行,简直就是灾难!
--查询sql_id='4jh8pskb3zgu0' 看看执行计划:

SCOTT@test> @dpc 4jh8pskb3zgu0 ''
PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------
SQL_ID  4jh8pskb3zgu0, child number 0
-------------------------------------
/* SQL Analyze(68,0) */ select /*+ full(t) */ count(*) from t

Plan hash value: 2966233522

---------------------------------------------------------
| Id  | Operation          | Name | E-Rows | Cost (%CPU)|
---------------------------------------------------------
|   0 | SELECT STATEMENT   |      |        |   279 (100)|
|   1 |  SORT AGGREGATE    |      |      1 |            |
|   2 |   TABLE ACCESS FULL| T    |   1000 |   279   (0)|
---------------------------------------------------------

Note
-----
   - Warning: basic plan statistics not available. These are only collected when:
       * hint 'gather_plan_statistics' is used for the statement or
       * parameter 'statistics_level' is set to 'ALL', at session or system level

SQL_ID  4jh8pskb3zgu0, child number 1
-------------------------------------
/* SQL Analyze(68,0) */ select /*+ full(t) */ count(*) from t

Plan hash value: 3548397654

--------------------------------------------------------------
| Id  | Operation             | Name   | E-Rows | Cost (%CPU)|
--------------------------------------------------------------
|   0 | SELECT STATEMENT      |        |        |     3 (100)|
|   1 |  SORT AGGREGATE       |        |      1 |            |
|   2 |   INDEX FAST FULL SCAN| I_T_ID |   1000 |     3   (0)|
--------------------------------------------------------------

Note
-----
   - Warning: basic plan statistics not available. These are only collected when:
       * hint 'gather_plan_statistics' is used for the statement or
       * parameter 'statistics_level' is set to 'ALL', at session or system level

SQL_ID  4jh8pskb3zgu0, child number 2
-------------------------------------
/* SQL Analyze(68,0) */ select /*+ full(t) */ count(*) from t

Plan hash value: 4021579484

----------------------------------------------------
| Id  | Operation        | Name   | E-Rows | Cost  |
----------------------------------------------------
|   0 | SELECT STATEMENT |        |        |     4 |
|   1 |  SORT AGGREGATE  |        |      1 |       |
|   2 |   INDEX FULL SCAN| I_T_ID |   1000 |     4 |
----------------------------------------------------

Note
-----
   - cpu costing is off (consider enabling it)
   - Warning: basic plan statistics not available. These are only collected when:
       * hint 'gather_plan_statistics' is used for the statement or
       * parameter 'statistics_level' is set to 'ALL', at session or system level

61 rows selected.

--可以发现oracle选择3中方式:1.全表扫描 2.INDEX FAST FULL SCAN 3. INDEX FULL SCAN.
--实际上还要检查统计信息是否stale,还有stale还有分析表等情况,如果这些表很大,运行更慢,以后要在具体优化过程中注意.

5.查看分析报告:
SCOTT@test> select Dbms_Sqltune.REPORT_TUNING_TASK('TASK1', 'TEXT', 'TYPICAL') report from dual;
REPORT
-------------------------------------------------------------------------------
GENERAL INFORMATION SECTION
-------------------------------------------------------------------------------
Tuning Task Name   : TASK1
Tuning Task Owner  : SCOTT
Workload Type      : Single SQL Statement
Scope              : COMPREHENSIVE
Time Limit(seconds): 1800
Completion Status  : COMPLETED
Started at         : 11/22/2013 10:01:22
Completed at       : 11/22/2013 10:01:23

-------------------------------------------------------------------------------
Schema Name: SCOTT
SQL ID     : cdwnbcfy42f8b
SQL Text   : select /*+ full(t) */ count(*) from t

-------------------------------------------------------------------------------
FINDINGS SECTION (1 finding)
-------------------------------------------------------------------------------

1- SQL Profile Finding (see explain plans section below)
--------------------------------------------------------
  A potentially better execution plan was found for this statement.

  Recommendation (estimated benefit: 99.4%)
  -----------------------------------------
  - Consider accepting the recommended SQL profile.
    execute dbms_sqltune.accept_sql_profile(task_name => 'TASK1', task_owner
            => 'SCOTT', replace => TRUE);

  Validation results
  ------------------
  The SQL profile was tested by executing both its plan and the original plan
  and measuring their respective execution statistics. A plan may have been
  only partially executed if the other could be run to completion in less time.

                           Original Plan  With SQL Profile  % Improved
                           -------------  ----------------  ----------
  Completion Status:            COMPLETE          COMPLETE
  Elapsed Time (s):              .00276           .000155      94.38 %
  CPU Time (s):                 .002799             .0001      96.42 %
  User I/O Time (s):                  0                 0
  Buffer Gets:                     1004                 6       99.4 %
  Physical Read Requests:             0                 0
  Physical Write Requests:            0                 0
  Physical Read Bytes:                0                 0
  Physical Write Bytes:               0                 0
  Rows Processed:                     1                 1
  Fetches:                            1                 1
  Executions:                         1                 1

  Notes
  -----
  1. Statistics for the original plan were averaged over 10 executions.
  2. Statistics for the SQL profile plan were averaged over 10 executions.

-------------------------------------------------------------------------------
EXPLAIN PLANS SECTION
-------------------------------------------------------------------------------

1- Original With Adjusted Cost
------------------------------
Plan hash value: 2966233522

-------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Cost (%CPU)| Time     |
-------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |     1 |   279   (0)| 00:00:04 |
|   1 |  SORT AGGREGATE    |      |     1 |            |          |
|   2 |   TABLE ACCESS FULL| T    |  1000 |   279   (0)| 00:00:04 |
-------------------------------------------------------------------

2- Using SQL Profile
--------------------
Plan hash value: 3548397654

------------------------------------------------------------------------
| Id  | Operation             | Name   | Rows  | Cost (%CPU)| Time     |
------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |        |     1 |     3   (0)| 00:00:01 |
|   1 |  SORT AGGREGATE       |        |     1 |            |          |
|   2 |   INDEX FAST FULL SCAN| I_T_ID |  1000 |     3   (0)| 00:00:01 |
------------------------------------------------------------------------

--建议执行如下:
execute dbms_sqltune.accept_sql_profile(task_name => 'TASK1', task_owner=> 'SCOTT', replace => TRUE);

SCOTT@test> execute dbms_sqltune.accept_sql_profile(task_name => 'TASK1', task_owner=> 'SCOTT', replace => TRUE);
PL/SQL procedure successfully completed.

SCOTT@test> select /*+ full(t) */ count(*) from t;
  COUNT(*)
----------
      1000

SCOTT@test> @dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  cdwnbcfy42f8b, child number 0
-------------------------------------
select /*+ full(t) */ count(*) from t

Plan hash value: 3548397654

--------------------------------------------------------------
| Id  | Operation             | Name   | E-Rows | Cost (%CPU)|
--------------------------------------------------------------
|   0 | SELECT STATEMENT      |        |        |     3 (100)|
|   1 |  SORT AGGREGATE       |        |      1 |            |
|   2 |   INDEX FAST FULL SCAN| I_T_ID |   1000 |     3   (0)|
--------------------------------------------------------------

Note
-----
   - SQL profile SYS_SQLPROF_01427dac70410001 used for this statement
   - Warning: basic plan statistics not available. These are only collected when:
       * hint 'gather_plan_statistics' is used for the statement or
       * parameter 'statistics_level' is set to 'ALL', at session or system level


21 rows selected.

--可以发现下载执行计划使用INDEX FAST FULL SCAN.
--即使我改动第1个字母大写,依旧使用INDEX FAST FULL SCAN.
SCOTT@test> Select /*+ full(t) */ count(*) from t;
  COUNT(*)
----------
      1000

SCOTT@test> @dpc '' ''
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
SQL_ID  dxvbtb8hzfdr9, child number 0
-------------------------------------
Select /*+ full(t) */ count(*) from t

Plan hash value: 3548397654

--------------------------------------------------------------
| Id  | Operation             | Name   | E-Rows | Cost (%CPU)|
--------------------------------------------------------------
|   0 | SELECT STATEMENT      |        |        |     3 (100)|
|   1 |  SORT AGGREGATE       |        |      1 |            |
|   2 |   INDEX FAST FULL SCAN| I_T_ID |   1000 |     3   (0)|
--------------------------------------------------------------

Note
-----
   - SQL profile SYS_SQLPROF_01427dac70410001 used for this statement
   - Warning: basic plan statistics not available. These are only collected when:
       * hint 'gather_plan_statistics' is used for the statement or
       * parameter 'statistics_level' is set to 'ALL', at session or system level
21 rows selected.

--补充1点,如果优化语句带文字变量,想优化大量相似语句,可以在执行dbms_sqltune.accept_sql_profile
--加入:force_match=>true
--         force_match  - If TRUE this causes SQL Profiles
--                        to target all SQL statements which have the same
--                        text after normalizing all literal values into
--                        bind variables. (Note that if a combination of
--                        literal values and bind values is used in a
--                        SQL statement, no bind transformation occurs.)
--                        This is analogous to the matching algorithm
--                        used by the "FORCE" option of the
--                        CURSOR_SHARING parameter.  If FALSE, literals are
--                        not transformed.  This is analogous to the
--                        matching algorithm used by the "EXACT" option of
--                        the CURSOR_SHARING parameter.

总结:
sql profile是好东西,在生产系统使用,特别在优化很慢的语句时,要注意这些相关问题.


来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/267265/viewspace-777298/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
熟悉oracle相关技术,擅长sql优化,rman备份与恢复,熟悉linux shell编程。

注册时间:2008-01-03

  • 博文量
    2634
  • 访问量
    6394722