xiaocen 2016-11-17
What reasons will be happening sql hard parse and generating new child cursors
在一个繁忙的系统中,发现一个复杂且非常长的查询,产生40多个子游标和大量的硬解析,占用很多的内存、CPU资源;
SQL> @sql 3168229204 Show SQL text, child cursors and execution stats for SQL hash value 3168229204 child GGT report HASH_VALUE CH# PLAN_HASH FIRST_LOAD_TIME LAST_LOAD_TIME SQL_PROFIL ---------- ----- ---------- -------------------- -------------------- ---------- 3168229204 0 1144031096 2016-09-21/15:52:45 2016-11-03/16:43:40 3168229204 1 1144031096 2016-09-21/15:52:45 2016-11-03/17:39:50 3168229204 2 1144031096 2016-09-21/15:52:45 2016-11-03/18:52:26 3168229204 3 1144031096 2016-09-21/15:52:45 2016-11-04/08:41:15 3168229204 4 1144031096 2016-09-21/15:52:45 2016-11-05/08:12:52 3168229204 5 1144031096 2016-09-21/15:52:45 2016-11-07/08:00:49 3168229204 6 1144031096 2016-09-21/15:52:45 2016-11-07/13:15:24 3168229204 7 1144031096 2016-09-21/15:52:45 2016-11-08/08:07:12 3168229204 8 1144031096 2016-09-21/15:52:45 2016-11-09/08:11:57 3168229204 9 1144031096 2016-09-21/15:52:45 2016-11-09/08:31:15 3168229204 10 1144031096 2016-09-21/15:52:45 2016-11-09/08:46:13 3168229204 11 532057913 2016-09-21/15:52:45 2016-11-09/09:01:21 3168229204 12 1144031096 2016-09-21/15:52:45 2016-10-26/08:10:30 3168229204 13 1144031096 2016-09-21/15:52:45 2016-10-27/08:06:34 3168229204 14 1144031096 2016-09-21/15:52:45 2016-10-27/10:30:49 3168229204 15 1144031096 2016-09-21/15:52:45 2016-10-28/08:06:48 3168229204 16 1144031096 2016-09-21/15:52:45 2016-10-31/08:00:14 3168229204 17 1144031096 2016-09-21/15:52:45 2016-10-29/11:15:32 3168229204 18 1144031096 2016-09-21/15:52:45 2016-11-01/08:02:00 3168229204 19 1144031096 2016-09-21/15:52:45 2016-11-01/08:16:02 3168229204 44 532057913 2016-09-21/15:52:45 2016-10-25/08:36:46 21 rows selected. CH# PARENT_HANDLE OBJECT_HANDLE PARSES H_PARSES EXECUTIONS FETCHES ROWS_PROCESSED LIOS PIOS SORTS CPU_MS ELA_MS USERS_EXECUTING ----- ---------------- ---------------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- --------------- 0 000000099DC30528 000000099DC62120 1 117 1 11 20619 563097 16037 0 6707.98 1777858.92 0 1 000000099DC30528 000000099EC8B478 1 114 1 11 20795 539435 1030 0 3436.478 59351.813 0 2 000000099DC30528 000000099DE9FE00 3 109 3 33 62385 6765790 6028872 0 87585.686 927030.91 0 3 000000099DC30528 000000099FC011E8 8 105 8 82 155431 22164287 21124804 0 295961.008 6440049.63 0 4 000000099DC30528 000000099F5D9880 44 103 44 315 572091 134332996 129689322 0 1627595.57 26658408 0 5 000000099DC30528 000000099EC73B98 104 100 104 565 1007037 318502972 310719053 0 3833473.23 32819296.8 0 6 000000099DC30528 000000099F426050 21 95 21 30 25387 1980211 9151 0 11131.307 691583.17 0 7 000000099DC30528 000000099E1C8A58 31 91 31 81 134024 82881335 75710067 0 830793.701 12330642 0 8 000000099DC30528 000000099FAC91F8 51 86 51 221 399552 156405150 151167773 0 1859173.36 34943618.3 0 9 000000099DC30528 000000099F6D67B8 1 84 1 5 9331 545117 19 0 1828.722 2107.133 0 10 000000099DC30528 000000099FCF3EE8 1 78 1 5 9386 547695 188 0 2588.606 10211.348 0 11 000000099DC30528 000000099F50D9C8 32 76 32 203 372484 98467223 94342488 0 1153776.61 19565473.3 1 12 000000099DC30528 000000099FA1ED18 1 72 1 862 8610 626229 35266 0 8491.715 736156.11 0 13 000000099DC30528 000000099F0DA4C0 51 69 51 54046 540160 156744017 150198327 0 1901325.93 31480771.6 0 14 000000099DC30528 000000099E680C90 10 65 10 6566 65606 25179760 22590318 0 251589.755 3495357.72 0 15 000000099DC30528 000000099EF0DF50 42 57 42 36991 369806 115460484 102958163 0 1152703.76 15607683.6 0 16 000000099DC30528 000000099F5ACBC8 63 53 63 60623 606007 167981225 155721272 0 1724758.8 21204621.2 0 17 000000099DC30528 000000099FA0A6A0 1 53 1 888 8879 193856 1047 0 1283.808 2972.2 0 18 000000099DC30528 000000099E7B52D8 142 51 142 81062 810103 239175636 226077041 0 2483807.37 18198010.6 0 19 000000099DC30528 000000099DA92AA0 15 46 15 12766 127575 1847753 5046 0 15149.692 457626.043 0 44 000000099DC30528 000000099E6EBA18 48 1 48 37672 376331 149384376 144111692 0 1825119.51 31195023.6 0
而且由于某些原因优化器不能够做出正确的评估,导致执行计划不一样,产生了大量的物理读等待事件;所以作为开发人员我们要了解清楚硬解析和产生子游标的原因,做出必要的调整和优化,使优化器能够正确做出评估,巩固和保护执行计划,竭力避免重复硬解析和使用不正确的执行计划。
Oracle中有很多的原因导致硬解析和产生子游标,比如有两个用户USERA和USERB,它们都有相同的表TAB01,两个用户都执行了如下的查询操作;
select * from tab01;
这样就会在v$sqlarea,v$sql,v$sql_shared_cursor产生如下的记录;
SQL> select sql_text,hash_value,sharable_mem,buffer_gets,loads,fetches,executions,optimizer_mode,PARSING_SCHEMA_NAME from v$sqlarea where sql_id='5b42g2fkrrzss'; SQL_TEXT HASH_VALUE SHARABLE_MEM BUFFER_GETS LOADS FETCHES EXECUTIONS OPTIMIZER_MODE PARSING_SCHEMA_NAME -------------------- ---------- ------------ ----------- ---------- ---------- ---------- -------------------- ------------------------------------------------------------ select * from tab01 2776366872 85836 220 2 2 2 ALL_ROWS USERB SQL> select t.CHILD_NUMBER,sql_text,hash_value,sharable_mem,buffer_gets,loads,fetches,executions,optimizer_mode,t.PARSING_SCHEMA_NAME from v$sql t where sql_id='5b42g2fkrrzss'; CHILD_NUMBER SQL_TEXT HASH_VALUE SHARABLE_MEM BUFFER_GETS LOADS FETCHES EXECUTIONS OPTIMIZER_MODE PARSING_SCHEMA_NAME ------------ -------------------- ---------- ------------ ----------- ---------- ---------- ---------- -------------------- ------------------------------------------------------------ 0 select * from tab01 2776366872 44868 110 1 1 1 ALL_ROWS USERA 1 select * from tab01 2776366872 44868 110 1 1 1 ALL_ROWS USERB SQL> select child_number,t.AUTH_CHECK_MISMATCH,t.TRANSLATION_MISMATCH from v$sql_shared_cursor t where sql_id='5b42g2fkrrzss'; CHILD_NUMBER AU TR ------------ -- -- 0 N N 1 Y Y
其它还有非常多的原因导致硬解析和产生子游标,接下来会讨论一些日常开发中容易导致的原因;
create table tparse( x number primary key, y varchar2(30) ); begin dbms_stats.set_table_stats ( user,'tparse', numrows=>10000000, numblks=>100000 ); end; / begin dbms_stats.set_index_stats ( user,'SYS_C0013113', numrows=>10000000 ); end; /
这里创建了tparse表,然后虚拟设置了表和索引的统计信息;接着在pl/sql里用不同的优化器环境和不同的条件下执行SQL;
declare l_num_x number; l_var_x varchar2(30); l_var_x1 varchar2(300); begin execute immediate 'alter session set optimizer_mode=all_rows'; for i in (select * from tparse where x>l_num_x)loop null; end loop; for i in (select * from tparse where x>l_var_x)loop null; end loop; execute immediate 'alter session set optimizer_mode=first_rows_10'; for i in (select * from tparse where x>l_num_x)loop null; end loop; for i in (select * from tparse where x>l_var_x)loop null; end loop; for i in (select * from tparse where x>l_var_x1)loop null; end loop; end; /
成功执行pl/sql后,检查v$sql表;
col SQL_TEXT for a50 select sql_id,CHILD_NUMBER,hash_value,SQL_TEXT , buffer_gets LIOS, disk_reads PIOS, sorts, cpu_time/1000 cpu_ms, elapsed_time/1000 ela_ms from v$sql where sql_text like 'SELECT %TPARSE WHERE X%' order by CHILD_NUMBER ; SQL_ID CHILD_NUMBER HASH_VALUE SQL_TEXT LIOS PIOS SORTS CPU_MS ELA_MS -------------------------- ------------ ---------- -------------------------------------------------- ---------- ---------- ---------- ---------- ---------- 1dmmz4yh0hrzx 0 2684903421 SELECT * FROM TPARSE WHERE X>:B1 26 3 0 2 1.733 1dmmz4yh0hrzx 1 2684903421 SELECT * FROM TPARSE WHERE X>:B1 4 0 0 1.998 1.331 1dmmz4yh0hrzx 2 2684903421 SELECT * FROM TPARSE WHERE X>:B1 4 0 0 2 1.673 1dmmz4yh0hrzx 3 2684903421 SELECT * FROM TPARSE WHERE X>:B1 2 0 0 2.999 3.286 1dmmz4yh0hrzx 4 2684903421 SELECT * FROM TPARSE WHERE X>:B1 2 0 0 1 .783
这里产生了5条记录,sql_id,hash_value都相同,但是它们有不同之处;
这些原因都可以在v$sql_shared_cursor视图中找到原因;
select t.ADDRESS,t.CHILD_ADDRESS,child_number,t.BIND_MISMATCH,t.OPTIMIZER_MODE_MISMATCH,t.BIND_LENGTH_UPGRADEABLE from v$sql_shared_cursor t where sql_id='1dmmz4yh0hrzx'; ADDRESS CHILD_ADDRESS CHILD_NUMBER BI OP BI ---------------- ---------------- ------------ -- -- -- 0000000069AC2D28 0000000062F19D70 0 N N N 0000000069AC2D28 00000000696F7E48 1 Y N N 0000000069AC2D28 000000006A3E05A8 2 N Y N 0000000069AC2D28 000000006636C6D8 3 Y Y N 0000000069AC2D28 0000000065AE2338 4 Y Y Y
对于第一次解析,由于共享池中不存在已经解析的游标,oracle必须硬解析SQL,然后共享,所以v$sql_shared_cursor视图中的mismatch值为N;
当第二次解析时, 由于共享池中已经存在解析的游标,但由于变量类型与主键类型不同,对比第一次解析时发生BIND_MISMATCH,oracle再次硬解析;
第三次解析时,由于绑定值与主键值类型相同,但优化器的设置不同,对比第一次解析时发生OPTIMIZER_MODE_MISMATCH,oracle再次硬解析;
第四次解析时,由于绑定值与主键值类型不同,并且优化器的设置也不同,对比第一次解析发生BIND_MISMATCH和OPTIMIZER_MODE_MISMATCH,oracle再次硬解析;
;
第五次解析时,由于绑定值与主键值类型不同,优化器的设置不同,并且绑定值长度较之前发生了变化,对比第一次解析时发生BIND_MISMATCH、OPTIMIZER_MODE_MISMATCH和BIND_LENGTH_UPGRADEABLE,oracle再次硬解析;
到现在我们了解了产生硬解析和子游标的原因,我们看看优化器在生成执行计划时的不同; 首先看第一次的执行计划;
SQL> SELECT * FROM table (DBMS_XPLAN.DISPLAY_CURSOR('1dmmz4yh0hrzx',0)); PLAN_TABLE_OUTPUT ------------------------------------------------------------------------------------------------------------------------ SQL_ID 1dmmz4yh0hrzx, child number 0 ------------------------------------- SELECT * FROM TPARSE WHERE X>:B1 Plan hash value: 3289637765 -------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | -------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 13 (100)| | | 1 | TABLE ACCESS BY INDEX ROWID| TPARSE | 500K| 14M| 13 (24)| 00:00:01 | |* 2 | INDEX RANGE SCAN | SYS_C0013113 | 90000 | | 4 (50)| 00:00:01 | -------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 2 - access("X">:B1)
优化器使用了索引,谓语条件没有任何转换;
第二次
SQL> SELECT * FROM table (DBMS_XPLAN.DISPLAY_CURSOR('1dmmz4yh0hrzx',1)); PLAN_TABLE_OUTPUT -------------------------------------------------------------------------------------------------------------------- SQL_ID 1dmmz4yh0hrzx, child number 1 ------------------------------------- SELECT * FROM TPARSE WHERE X>:B1 Plan hash value: 3289637765 -------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | -------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 13 (100)| | | 1 | TABLE ACCESS BY INDEX ROWID| TPARSE | 500K| 14M| 13 (24)| 00:00:01 | |* 2 | INDEX RANGE SCAN | SYS_C0013113 | 90000 | | 4 (50)| 00:00:01 | -------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 2 - access("X">TO_NUMBER(:B1))
优化器同样使用了索引,谓语条件中值类型发生隐形转换;
第三次解析
SQL> SELECT * FROM table (DBMS_XPLAN.DISPLAY_CURSOR('1dmmz4yh0hrzx',2,'outline')); PLAN_TABLE_OUTPUT -------------------------------------------------------------------------------------------------------- SQL_ID 1dmmz4yh0hrzx, child number 2 ------------------------------------- SELECT * FROM TPARSE WHERE X>:B1 Plan hash value: 3289637765 -------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | -------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 3 (100)| | | 1 | TABLE ACCESS BY INDEX ROWID| TPARSE | 10 | 300 | 3 (0)| 00:00:01 | |* 2 | INDEX RANGE SCAN | SYS_C0013113 | 90000 | | 2 (0)| 00:00:01 | -------------------------------------------------------------------------------------------- Outline Data ------------- /*+ BEGIN_OUTLINE_DATA IGNORE_OPTIM_EMBEDDED_HINTS OPTIMIZER_FEATURES_ENABLE('11.2.0.4') DB_VERSION('11.2.0.4') FIRST_ROWS(10) OUTLINE_LEAF(@"SEL$1") INDEX_RS_ASC(@"SEL$1" "TPARSE"@"SEL$1" ("TPARSE"."X")) END_OUTLINE_DATA */ Predicate Information (identified by operation id): --------------------------------------------------- 2 - access("X">:B1)
优化器设置改变了,评估的基数因优化器设置而变低。
通过上面的例子可以看出,使用最频繁的情况(变量类型改变,变量长度改变,优化器设置改变等)均会导致重复的解析和新游标产生,但复杂且非常长的SQL在系统中是司空见惯的,如果才能避免或减少重复硬解析和资源的使用,又在一定程度上保护执行计划呢?
10g以前有outline,但使用受限;10g及以后有sql profile;让我们以第一次解析来创建SQL profile,看会发生什么;
SQL> @sqlprofile/create_sql_profile.sql '1dmmz4yh0hrzx' 0 Enter value for sql_id: 1dmmz4yh0hrzx Enter value for child_no (0): Enter value for profile_name (PROF_sqlid_planhash): Enter value for category (DEFAULT): Enter value for force_matching (FALSE): SQL> alter system flush shared_pool;
创建好SQL profile后清空共享池,然后再重新运行上面的PL/SQL;再观察v$sql;
col SQL_TEXT for a50 select sql_id,CHILD_NUMBER,hash_value,SQL_TEXT , buffer_gets LIOS, disk_reads PIOS, sorts, cpu_time/1000 cpu_ms, elapsed_time/1000 ela_ms from v$sql where sql_text like 'SELECT %TPARSE WHERE X%' order by CHILD_NUMBER ; SQL_ID CHILD_NUMBER HASH_VALUE SQL_TEXT LIOS PIOS SORTS CPU_MS ELA_MS -------------------------- ------------ ---------- -------------------------------------------------- ---------- ---------- ---------- ---------- ---------- 1dmmz4yh0hrzx 0 2684903421 SELECT * FROM TPARSE WHERE X>:B1 1010 22 0 20.996 24.27 1dmmz4yh0hrzx 1 2684903421 SELECT * FROM TPARSE WHERE X>:B1 2 0 0 3 2.783 1dmmz4yh0hrzx 2 2684903421 SELECT * FROM TPARSE WHERE X>:B1 4 0 0 2 2.473 select t.ADDRESS,t.CHILD_ADDRESS,child_number,t.BIND_MISMATCH,t.OPTIMIZER_MODE_MISMATCH,t.BIND_LENGTH_UPGRADEABLE from v$sql_shared_cursor t where sql_id='1dmmz4yh0hrzx'; ADDRESS CHILD_ADDRESS CHILD_NUMBER BI OP BI ---------------- ---------------- ------------ -- -- -- 0000000069AC2D28 0000000062F19D70 0 N N N 0000000069AC2D28 00000000696F7E48 1 Y N N 0000000069AC2D28 000000006A3E05A8 2 Y N Y
仅产生2个子游标,一次因为变量类型改变了,一次为变量类型和变量值长度改变了;优化器环境改变并没有影响到优化器;再继续查询优化器的行为;
SQL> @sql 2684903421 Show SQL text, child cursors and execution stats for SQL hash value 2684903421 child 0 HASH_VALUE CH# PLAN_HASH SQL_TEXT FIRST_LOAD_TIME LAST_LOAD_TIME SQL_PROFILE ---------- ----- ---------- -------------------------------------------------------------------------------------------------------------- -------------------- -------------------- ------------------------------ 2684903421 0 3289637765 SELECT * FROM TPARSE WHERE X>:B1 2016-11-15/20:09:37 2016-11-15/21:57:33 PROF_1dmmz4yh0hrzx_3289637765 2684903421 1 3289637765 SELECT * FROM TPARSE WHERE X>:B1 2016-11-15/20:09:37 2016-11-15/21:57:33 PROF_1dmmz4yh0hrzx_3289637765 2684903421 2 3289637765 SELECT * FROM TPARSE WHERE X>:B1 2016-11-15/20:09:37 2016-11-15/21:57:33 PROF_1dmmz4yh0hrzx_3289637765 3 rows selected. CH# PARENT_HANDLE OBJECT_HANDLE PARSES H_PARSES EXECUTIONS FETCHES ROWS_PROCESSED LIOS PIOS SORTS CPU_MS ELA_MS USERS_EXECUTING ----- ---------------- ---------------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- --------------- 0 0000000069AC2D28 0000000062F19D70 3 7 2 2 0 1010 22 0 20.996 24.27 0 1 0000000069AC2D28 00000000696F7E48 2 7 2 2 0 2 0 0 3 2.783 0 2 0000000069AC2D28 000000006A3E05A8 0 7 2 2 0 4 0 0 2 2.473 0
三个游标均使用了同样的SQL Profile,执行计划因SQL Profile而受到保护。