ITPub博客

首页 > 数据库 > Oracle > sql语句执行缓慢分析

sql语句执行缓慢分析

Oracle 作者:shilei1 时间:2018-11-19 17:23:24 1 删除 编辑

20181119]sql语句执行缓慢分析.txt


--//上个星期在优化时遇到sql语句执行缓慢的问题,百思不知其解,做一个记录.

--//我们生产系统有一个表索引有点多,肯定一些索引不需要,我想删除一些不必要的索引(可以先invisiable).再观察情况.


1.环境:

zzzzzz> @ ver1

PORT_STRING                    VERSION        BANNER

------------------------------ -------------- --------------------------------------------------------------------------------

x86_64/Linux 2.4.xx            11.2.0.3.0     Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production


2.执行脚本如下:

$ cat a.txt

SELECT /*+ &&2 */ owner,

       index_name,

       --       index_type,

       table_NAME,

       COMPRESSION,

       UNIQUENESS,

       distinct_keys,

       AVG_LEAF_blocks_per_key,

       AVG_DATA_BLOCKS_PER_KEY,

       blevel,

       leaf_blocks,

       clustering_factor,

       status,

       num_rows,

       sample_size,

       last_analyzed

  FROM dba_indexes

 WHERE     owner LIKE 'XXXXXX_YYY'

       AND table_name = UPPER ('&&1')

       AND (owner, index_name) IN (SELECT owner, index_name

                                     FROM dba_indexes

                                    WHERE     owner LIKE 'XXXXXX_YYY'

                                          AND index_type <> 'LOB'

                                   MINUS

                                   (SELECT object_owner, object_name

                                      FROM v$sql_plan

                                     WHERE     object_type = 'INDEX'

                                           AND object_owner LIKE 'XXXXXX_YYY'

                                    UNION

                                    SELECT object_owner, object_name

                                      FROM dba_hist_sql_plan

                                     WHERE     object_type = 'INDEX'

                                           AND object_owner LIKE 'XXXXXX_YYY')

                                   MINUS

                                   (SELECT owner, constraint_name

                                      FROM dba_constraints

                                     WHERE     owner LIKE 'XXXXXX_YYY'

                                           AND constraint_type IN ('P',

                                                                   'U',

                                                                   'R')));

--//主要目的先排除一些现在使用的索引.


3.执行:

--//session 1:

zzzzzz> alter session set statistics_level=all;

Session altered.


zzzzzz> @ a.txt MS_CF01 aaa

...

--//慢.等。。。。


--//session 1,按ctrl+c中断执行,实际上没有执行完成:

zzzzzz> @ dpc '' ''

PLAN_TABLE_OUTPUT

-------------------------------------

SQL_ID  frzb5c8tjx9wz, child number 0

...

Plan hash value: 2331593202

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

| Id  | Operation                                         | Name                 | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

|   0 | SELECT STATEMENT                                  |                      |      1 |        |       |   485 (100)|          |      1 |00:01:42.24 |    2568K|     93 |       |       |          |

|   1 |  NESTED LOOPS OUTER                               |                      |      1 |      1 |   179 |   145   (0)| 00:00:02 |      1 |00:01:42.24 |    2568K|     93 |       |       |          |

|   2 |   NESTED LOOPS OUTER                              |                      |      1 |      1 |   168 |   144   (0)| 00:00:02 |      1 |00:01:42.24 |    2568K|     93 |       |       |          |

|   3 |    NESTED LOOPS OUTER                             |                      |      1 |      1 |   165 |   143   (0)| 00:00:02 |      1 |00:01:42.24 |    2568K|     93 |       |       |          |

... 太长...

|  38 |              SORT UNIQUE                          |                      |   3490 |      1 |   375 |   340  (97)| 00:00:05 |    126 |00:03:18.78 |    4909K|     15 |  2048 |  2048 |          |

|  39 |               UNION-ALL                           |                      |   3490 |        |       |            |          |   1461 |00:03:18.73 |    4909K|     15 |       |       |          |

|* 40 |                FIXED TABLE FULL                   | X$KQLFXPL            |   3490 |      1 |    22 |     3 (100)| 00:00:01 |    826 |00:02:58.63 |       0 |      0 |       |       |          |

|* 41 |                TABLE ACCESS FULL                  | WRH$_SQL_PLAN        |   3489 |      1 |    17 |   308   (1)| 00:00:04 |    635 |00:00:20.08 |    4909K|     15 |       |       |          |


--//很明显主要慢在ID=40,41,而实际上主要是循环次数3490导致执行缓慢.

--//很奇怪的是我在toad下很快完成.第1次执行需要实际长一点外,以后都很快.再次查看执行计划

--//注不能在toad下看,toad看仅仅看到child_number=0的执行计划.


zzzzzz> @ dpc frzb5c8tjx9wz ''

....

SQL_ID  frzb5c8tjx9wz, child number 1

-------------------------------------


Plan hash value: 1956464785


---------------------------------------------------------------------------------------------------------------------------------------------

| Id  | Operation                                | Name                 | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |  OMem |  1Mem | Used-Mem |

---------------------------------------------------------------------------------------------------------------------------------------------

|   0 | SELECT STATEMENT                         |                      |        |       |   570 (100)|          |       |       |          |

|*  1 |  FILTER                                  |                      |        |       |            |          |       |       |          |

|   2 |   NESTED LOOPS OUTER                     |                      |      1 |   179 |   230   (0)| 00:00:03 |       |       |          |

|   3 |    NESTED LOOPS OUTER                    |                      |      1 |   168 |   229   (0)| 00:00:03 |       |       |          |

|   4 |     NESTED LOOPS OUTER                   |                      |      1 |   164 |   228   (0)| 00:00:03 |       |       |          |

|   5 |      NESTED LOOPS                        |                      |      1 |   156 |   227   (0)| 00:00:03 |       |       |          |

....

|  50 |      UNION-ALL                           |                      |        |       |            |          |       |       |          |

|* 51 |       FIXED TABLE FULL                   | X$KQLFXPL            |      1 |    22 |     3 (100)| 00:00:01 |       |       |          |

|* 52 |       TABLE ACCESS FULL                  | WRH$_SQL_PLAN        |      1 |    17 |   308   (1)| 00:00:04 |       |       |          |

|  53 |    SORT UNIQUE NOSORT                    |                      |      1 |   211 |    15   (7)| 00:00:01 |       |       |          |


--//开始想是正常的,因为我在sqlplus下设置了alter session set statistics_level=all;.但是仔细看仔细计划对于的操作id不一样,而且Plan hash value也不同.

--//我也尝试在toad下加入alter session set statistics_level=all;按F9执行也会执行缓慢.


zzzzzz> @ share frzb5c8tjx9wz

SQL_TEXT                       = SELECT /*+ aaa */ owner,        index_name,        --     index_type,        table_NAME,        COMPRESSION,        UNIQUENESS,        distinct_keys,        AVG_LEAF_blocks_per_key,        AVG_DATA_BLOCKS_PER_KEY,

blevel,        leaf_blocks,        clustering_factor,        status,        num_rows,        sample_size,        last_analyzed   FROM dba_indexes  WHERE     owner LIKE :"SYS_B_00"        AND table_name = UPPER (:"SYS_B_01")        AND (owner,

index_name) IN (SELECT owner, index_name                                      FROM dba_indexes                                     WHERE     owner LIKE :"SYS_B_02"                                           AND index_type <> :"SYS_B_03"

MINUS                                    (SELECT object_owner, object_name                                       FROM v$sql_plan                                      WHERE     object_type = :"SYS_B_04"                                            AND

object_owner LIK

SQL_ID                         = frzb5c8tjx9wz

ADDRESS                        = 00000000AA459A38

CHILD_ADDRESS                  = 00000000AB1E7238

CHILD_NUMBER                   = 0

REASON                         = <ChildNode><ChildNumber>0</ChildNumber><ID>45</ID><reason>NLS

Settings(0)</reason><size>2x4</size><SessionLengthSemantics>0</SessionLengthSemantics><CursorLengthSemantics>0</CursorLengthSemantics></ChildNode><ChildNode><ChildNumber>0</ChildNumber><ID>3</ID><reason>Optimizer

mismatch(12)</reason><size>2x216</size><statistics_level> all                  typical             </statistics_level></ChildNode>

--------------------------------------------------

SQL_TEXT                       = SELECT /*+ aaa */ owner,        index_name,        --     index_type,        table_NAME,        COMPRESSION,        UNIQUENESS,        distinct_keys,        AVG_LEAF_blocks_per_key,        AVG_DATA_BLOCKS_PER_KEY,

blevel,        leaf_blocks,        clustering_factor,        status,        num_rows,        sample_size,        last_analyzed   FROM dba_indexes  WHERE     owner LIKE :"SYS_B_00"        AND table_name = UPPER (:"SYS_B_01")        AND (owner,

index_name) IN (SELECT owner, index_name                                      FROM dba_indexes                                     WHERE     owner LIKE :"SYS_B_02"                                           AND index_type <> :"SYS_B_03"

MINUS                                    (SELECT object_owner, object_name                                       FROM v$sql_plan                                      WHERE     object_type = :"SYS_B_04"                                            AND

object_owner LIK

SQL_ID                         = frzb5c8tjx9wz

ADDRESS                        = 00000000AA459A38

CHILD_ADDRESS                  = 00000000AB3775D8

CHILD_NUMBER                   = 1

OPTIMIZER_MISMATCH             = Y

REASON                         = <ChildNode><ChildNumber>1</ChildNumber><ID>3</ID><reason>Optimizer mismatch(12)</reason><size>2x216</size><statistics_level> typical              all                 </statistics_level></ChildNode>


--//我发现一个奇特的情况,sqlplus执行的语句和toad下执行的语句不能共享,提示LANGUAGE_MISMATCH= Y.


zzzzzz> select sql_id,child_number,PLAN_HASH_VALUE,buffer_gets,executions,ELAPSED_TIME from v$sql where sql_id='frzb5c8tjx9wz';

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE BUFFER_GETS EXECUTIONS ELAPSED_TIME

------------- ------------ --------------- ----------- ---------- ------------

frzb5c8tjx9wz            0      2331593202     4978087          1    201931031

frzb5c8tjx9wz            1      1956464785       30458          2      1486831


--//对比2者NLS*环境:

zzzzzz> select * from nls_session_parameters ;

PARAMETER                  VALUE

-------------------------- ----------------------------------

NLS_LANGUAGE               AMERICAN

NLS_TERRITORY              AMERICA

NLS_CURRENCY               $

NLS_ISO_CURRENCY           AMERICA

NLS_NUMERIC_CHARACTERS     .,

NLS_CALENDAR               GREGORIAN

NLS_DATE_FORMAT            YYYY-MM-DD HH24:MI:SS

NLS_DATE_LANGUAGE          AMERICAN

NLS_SORT                   BINARY

NLS_TIME_FORMAT            HH.MI.SSXFF AM

NLS_TIMESTAMP_FORMAT       YYYY-MM-DD HH24:MI:SS.FF

NLS_TIME_TZ_FORMAT         HH24.MI.SSXFF TZH:TZM

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

NLS_TIMESTAMP_TZ_FORMAT    YYYY-MM-DD HH24:MI:SS.FF TZH:TZM

NLS_DUAL_CURRENCY          $

NLS_COMP                   BINARY

NLS_LENGTH_SEMANTICS       BYTE

NLS_NCHAR_CONV_EXCP        FALSE

17 rows selected.


--//toad下执行:

select * from nls_session_parameters ;


PARAMETER,VALUE

NLS_LANGUAGE,AMERICAN

NLS_TERRITORY,AMERICA

NLS_CURRENCY,$

NLS_ISO_CURRENCY,AMERICA

NLS_NUMERIC_CHARACTERS,.,

NLS_CALENDAR,GREGORIAN

NLS_DATE_FORMAT,YYYY-MM-DD HH24:MI:SS

NLS_DATE_LANGUAGE,AMERICAN

NLS_SORT,BINARY

NLS_TIME_FORMAT,HH.MI.SSXFF AM

NLS_TIMESTAMP_FORMAT,YYYY-MM-DD HH24:MI:SS.FF

NLS_TIME_TZ_FORMAT,HH.MI.SSXFF AM TZR

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

NLS_TIMESTAMP_TZ_FORMAT,YYYY-MM-DD HH24:MI:SS.FF TZH:TZM

NLS_DUAL_CURRENCY,$

NLS_COMP,BINARY

NLS_LENGTH_SEMANTICS,BYTE

NLS_NCHAR_CONV_EXCP,FALSE


--//注意下划线,仅仅参数NLS_TIME_TZ_FORMAT不同.


$ export NLS_TIME_TZ_FORMAT='HH.MI.SSXFF AM TZR'


--//再次登录,问题消失.

alter session set statistics_level=all;

@ a.txt MS_CF01 aaa

--//很慢.登录后执行:

@ a.txt MS_CF01 aaa

--//可以发现很快,因为我在toad下已经执行过一次.

--//真心想不到这个参数,会导致这么奇怪的问题.

--//补充说明一下:

--//如果写成'HH24.MI.SSXFF AM TZR',调用sqlplus报错.

$ export NLS_TIME_TZ_FORMAT='HH24.MI.SSXFF AM TZR'

$ rlsql system/test12@192.168.31.8:1521/hrp430

ERROR:

ORA-01818: 'HH24' precludes use of meridian indicator

SP2-0152: ORACLE may not be functioning properly

ORA-24550: signal received: [si_signo=11] [si_errno=0] [si_code=1] [si_int=0] [si_ptr=(nil)] [si_addr=0x10]

kpedbg_dmp_stack()+362<-kpeDbgCrash()+192<-kpeDbgSignalHandler()+119<-skgesig_sigactionHandler()+218<-__sighandler()<-pthread_mutex_destroy()<-kpufhndl0()+5461<-kpufhndl()+11<-OCIHandleFree()+19<-afioci()+2372<-aficnthdf()+62<-aficexf()+185<-aficex()+370<-afidrv()+321<-frame_dummy()+123<-__libc_start_main()+244

rlwrap: warning: sqlplus crashed, killed by SIGSEGV.

rlwrap itself has not crashed, but for transparency,

it will now kill itself (without dumping core) with the same signal

warnings can be silenced by the --no-warnings (-n) option

Segmentation fault


--//多次尝试,确认实际上这个问题并不是参数NLS_TIME_TZ_FORMAT导致问题,而是执行计划不稳定.每次分析都有可能导致新的执行计划.

--//参数NLS_TIME_TZ_FORMAT不同,仅仅导致产生新的子光标,重新生成的执行计划.两者混合在一起导致问题非常怪异.

--//包括设置alter session set statistics_level=all;


--//如果我改写成如下,无论什么情况都是很快完成.

WITH a

     AS (SELECT /*+ MATERIALIZE */ object_owner, object_name

           FROM v$sql_plan

          WHERE object_type = 'INDEX' AND object_owner LIKE 'XXXXXX_YYY')

SELECT /*+ &&2 */ owner

      ,index_name

      ,--index_type,

       table_NAME

      ,COMPRESSION

      ,UNIQUENESS

      ,distinct_keys

      ,AVG_LEAF_blocks_per_key

      ,AVG_DATA_BLOCKS_PER_KEY

      ,blevel

      ,leaf_blocks

      ,clustering_factor

      ,status

      ,num_rows

      ,sample_size

      ,last_analyzed

  FROM dba_indexes

 WHERE     owner LIKE 'XXXXXX_YYY'

       AND table_name = UPPER ('&&1')

       AND (owner, index_name) IN (SELECT owner, index_name

                                     FROM dba_indexes

                                    WHERE     owner LIKE 'XXXXXX_YYY'

                                          AND index_type <> 'LOB'

                                   MINUS

                                   (SELECT object_owner, object_name FROM a

                                    UNION

                                    SELECT object_owner, object_name

                                      FROM dba_hist_sql_plan

                                     WHERE     object_type = 'INDEX'

                                           AND object_owner LIKE 'XXXXXX_YYY')

                                   MINUS

                                   (SELECT owner, constraint_name

                                      FROM dba_constraints

                                     WHERE     owner LIKE 'XXXXXX_YYY'

                                           AND constraint_type IN ('P'

                                                                  ,'U'

                                                                  ,'R')));



zzzzzz> @ aaa.txt MS_CF01 aaa

zzzzzz> select sql_id,child_number,PLAN_HASH_VALUE,buffer_gets,executions,ELAPSED_TIME from v$sql where sql_id='4zapbf2u32kx2';

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE BUFFER_GETS EXECUTIONS ELAPSED_TIME

------------- ------------ --------------- ----------- ---------- ------------

4zapbf2u32kx2            0      2384590172        9680          1       903877

4zapbf2u32kx2            1       115948183       11455          1       847278


zzzzzz> @ share 4zapbf2u32kx2

SQL_TEXT                       = with a as ( SELECT /*+ MATERIALIZE */ object_owner, object_name FROM v$sql_plan WHERE   object_type = :"SYS_B_00" AND object_owner LIKE :"SYS_B_01" ) SELECT /*+ aaa */ owner,        index_name,        --index_type,

table_NAME,        COMPRESSION,        UNIQUENESS,        distinct_keys,        AVG_LEAF_blocks_per_key,        AVG_DATA_BLOCKS_PER_KEY,        blevel,        leaf_blocks,        clustering_factor,        status,        num_rows,        sample_size,

last_analyzed   FROM dba_indexes  WHERE     owner LIKE :"SYS_B_02"        AND table_name = UPPER (:"SYS_B_03")        AND (owner, index_name) IN (SELECT owner, index_name                                      FROM dba_indexes

WHERE     owner LIKE :"SYS_B_04"                                           AND index_type <> :"SYS_B_05"                                    MINUS                                    (SELECT object_owner, object_name FROM a

UN

SQL_ID                         = 4zapbf2u32kx2

ADDRESS                        = 00000000A6303098

CHILD_ADDRESS                  = 00000000A68317F8

CHILD_NUMBER                   = 0

USE_FEEDBACK_STATS             = Y

REASON                         = <ChildNode><ChildNumber>0</ChildNumber><ID>3</ID><reason>Optimizer mismatch(13)</reason><size>3x4</size><kxscflg>32</kxscflg><kxscfl4>4194560</kxscfl4><dnum_kksfcxe>262144</dnum_kksfcxe></ChildNode>

--------------------------------------------------

SQL_TEXT                       = with a as ( SELECT /*+ MATERIALIZE */ object_owner, object_name FROM v$sql_plan WHERE   object_type = :"SYS_B_00" AND object_owner LIKE :"SYS_B_01" ) SELECT /*+ aaa */ owner,        index_name,        --index_type,

table_NAME,        COMPRESSION,        UNIQUENESS,        distinct_keys,        AVG_LEAF_blocks_per_key,        AVG_DATA_BLOCKS_PER_KEY,        blevel,        leaf_blocks,        clustering_factor,        status,        num_rows,        sample_size,

last_analyzed   FROM dba_indexes  WHERE     owner LIKE :"SYS_B_02"        AND table_name = UPPER (:"SYS_B_03")        AND (owner, index_name) IN (SELECT owner, index_name                                      FROM dba_indexes

WHERE     owner LIKE :"SYS_B_04"                                           AND index_type <> :"SYS_B_05"                                    MINUS                                    (SELECT object_owner, object_name FROM a

UN

SQL_ID                         = 4zapbf2u32kx2

ADDRESS                        = 00000000A6303098

CHILD_ADDRESS                  = 00000000A841E528

CHILD_NUMBER                   = 1

REASON                         =

--------------------------------------------------


PL/SQL procedure successfully completed.


--//不过不能共享的原因是是USE_FEEDBACK_STATS=Y.


总结:

1.环境变量,执行时参数不同导致产生新的子光标,出现一些怪异的情况,感觉toad下执行快,而sqlplus下执行慢.实际上反过来的情况也出

  现过.我估计cardinality FEEDBACK的影响.


2.对于复杂视图的执行计划先  MATERIALIZE也许能获得好的效果.


3.我发现一个奇怪的情况就是实际上打开alter session set statistics_level=all;就会选择慢的执行计划.

--//sqlplus开始第1次执行(硬分析)总是选择慢的执行计划.真心搞不懂....暂时放一下.


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

请登录后发表评论 登录
全部评论

注册时间:2018-10-10

  • 博文量
    548
  • 访问量
    41341