[20240409]为什么一条sql语句在实例2执行要慢的分析.txt

来源：这里教程网时间：2026-03-03 19:49:35 作者：

[20240409]为什么一条sql语句在实例2执行要慢的分析.txt --//生产系统遇到一个奇怪现象,一条sql语句在实例2要比实例1慢很多,展开分析看看. 1.环境: SYS@127.0.0.1:9014/ywdb> @ ver1 PORT_STRING VERSION BANNER ------------------------------ -------------- -------------------------------------------------------------------------------- x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production 2.问题展开: SYS@127.0.0.1:9014/ywdb> @ sqlhh af4692qv1f56q 10/24 time unit : millisecond BEGIN_INTERVAL_TIME INST_ID SQL_ID PLAN_HASH_VALUE EXECUTIONS ELA_MS_PER_EXEC CPU_MS_PER_EXEC ROWS_PER_EXEC LIOS_PER_EXEC BLKRD_PER_EXEC IOW_MS_PER_EXEC AVG_IOW_MS CLW_MS_PER_EXEC APW_MS_PER_EXEC CCW_MS_PER_EXEC ------------------- ---------- ------------- --------------- ---------- --------------- --------------- ------------- ------------- -------------- --------------- ----------- --------------- --------------- --------------- 2024-04-09 00:00:19 1 af4692qv1f56q 1518780269 1 4 4 1.0 209 0 0 0.0 0 0 0 2024-04-09 00:00:19 2 af4692qv1f56q 1518780269 1 1968 1698 1.0 265 0 0 0.0 0 0 0 2024-04-09 01:00:24 1 af4692qv1f56q 1518780269 4 4 3 1.0 209 0 0 0.0 0 0 0 2024-04-09 01:00:24 2 af4692qv1f56q 1518780269 1 2097 2010 1.0 265 0 0 0.0 0 0 0 2024-04-09 02:00:06 1 af4692qv1f56q 1518780269 3 5 5 1.0 209 0 0 0.0 0 0 0 2024-04-09 02:00:06 2 af4692qv1f56q 1518780269 1 2095 1722 1.0 265 0 0 0.0 0 0 0 2024-04-09 03:00:18 1 af4692qv1f56q 1518780269 3 4 4 1.0 209 0 0 0.0 0 0 0 2024-04-09 03:00:18 2 af4692qv1f56q 1518780269 1 2022 1846 1.0 265 0 0 0.0 0 0 0 2024-04-09 04:00:05 1 af4692qv1f56q 1518780269 2 5 5 1.0 209 0 0 0.0 0 0 0 2024-04-09 04:00:05 2 af4692qv1f56q 1518780269 2 1007 998 1.0 237 0 0 0.0 0 0 0 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2024-04-09 05:00:31 2 af4692qv1f56q 1518780269 5 4 3 1.0 209 0 0 0.0 0 0 0 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2024-04-09 05:00:31 1 af4692qv1f56q 1518780269 1 4 3 1.0 209 0 0 0.0 0 0 0 2024-04-09 06:00:33 2 af4692qv1f56q 1518780269 3 4 3 1.0 209 0 0 0.0 0 0 0 2024-04-09 06:00:34 1 af4692qv1f56q 1518780269 2 3 3 1.0 209 0 0 0.0 0 0 0 2024-04-09 07:00:53 1 af4692qv1f56q 1518780269 2 4 4 1.0 209 0 0 0.0 0 0 0 2024-04-09 07:00:53 2 af4692qv1f56q 1518780269 3 4 3 1.0 209 0 0 0.0 0 0 0 2024-04-09 08:00:07 2 af4692qv1f56q 1518780269 3 5 4 1.0 209 0 0 0.0 0 0 0 2024-04-09 08:00:07 1 af4692qv1f56q 1518780269 2 4 4 1.0 209 0 0 0.0 0 0 0 18 rows selected. --//可以发现一个特点,执行没有变化PLAN_HASH_VALUE=1518780269,实例2执行要有一点慢,也有执行快的时候,如果你仔细看就可以发现 --//这条sql语句执行次数很少.无论是实例1还是实例2.按照道理这类sql语句应该不会记录在dba_hist_sqlstat里面,可以推断,因为实例 --//2共享内存紧张,该语句经常被踢出共享池,导致执行出现硬分析导致的情况,而且每次硬分析时间还"很长". SYS@127.0.0.1:9014/ywdb> @ ashtop inst_id,module sql_id='af4692qv1f56q' &day '' Total Distinct Distinct Distinct Seconds AAS %This INST_ID MODULE FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1 --------- ------- ------- ---------- ------------------------------ ------------------- ------------------- ---------- -------- ----------- 150 .0 100% | 2 httpd.exe 2024-04-08 09:15:24 2024-04-09 04:25:32 1 150 150 --//仅仅实例2出现性能问题. --//先看看是什么语句: SYS@127.0.0.1:9014/ywdb> @ sqlid_fms af4692qv1f56q C200 --------------------------------------------------------------------------------------------------------------------------------- SELECT D.constraint_type as CONSTRAINT_TYPE, C.COLUMN_NAME, C.position, D.r_constraint_name, E.table_name as table_ref, f.column_name as column_ref, C.table_name FROM ALL_CONS_COLUMNS C inner join ALL_constraints D on D.OWNER = C.OWNER and D.constraint_name = C.constraint_name left join ALL_constraints E on E.OWNER = D.r_OWNER and E.constraint_name = D.r_constraint_name left join ALL_cons_columns F on F.OWNER = E.OWNER and F.constraint_name = E.constraint_name and F.position = c.position WHERE C.OWNER = 'PORTAL_HIS' and C.table_name = 'DATA_EXCHANGE_FP' and D.constraint_type <> 'P' order by d.constraint_name, c.position --//多数情况这语句是递归调用执行的,这类语句里面的视图定义非常复杂,如果查看执行计划非常复杂.第1次分析时间长,不可避免的. time unit : microsecond SQL_ID CHILD_NUMBER INST_ID FIRST_LOAD_TIME BUFFER_GETS EXECUTIONS ELAPSED_TIME AVG_ELA_TIME PLAN_HASH_VALUE LIOS_PER_EXEC FORCE_MATCHING_SIGNATURE ------------- ------------ ---------- -------------------------------------- ----------- ---------- ------------ ------------ --------------- ------------- ------------------------ af4692qv1f56q 0 2 2024-03-29/10:25:38 3400 16 2071474 129467.13 1518780269 213 3702873826194195448 af4692qv1f56q 0 1 2024-03-29/10:04:51 131289 628 4634160 7379.24 1518780269 209 3702873826194195448 --//可以发现实例2记录的执行次数少(16次),可以推断该语句一直呆在实例1共享池中,而实例2经常被刷出共享池,导致实例2的执行出现硬分析. --//如果仔细看sql语句的执行计划就知道,这条sql语句的执行计划非常复杂,可以参考链接: --//https://blog.itpub.net/267265/viewspace-3008682/ => 20240311]sql_id=c8s65f1cuhcb1的优化.txt ,与这个例子有一些类似. --//如何验证我的推断呢? SYS@127.0.0.1:9014/ywdb> @ ashtop inst_id,event sql_id='af4692qv1f56q' &day '' Total Distinct Distinct Distinct Seconds AAS %This INST_ID EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1 --------- ------- ------- ---------- ------------------------------------------ ------------------- ------------------- ---------- -------- ----------- 148 .0 100% | 2 2024-04-08 09:25:30 2024-04-09 04:25:32 1 148 148 --//event记录为空,基本消耗CPU上,如果知道消耗集中在分析上呢? --//最新的ashtop脚本加入了time_model_name,可以了解一些细节. SYS@127.0.0.1:9014/ywdb> @ ashtop inst_id,time_model_name,time_model sql_id='af4692qv1f56q' &day '' Total Distinct Distinct Distinct Seconds AAS %This INST_ID TIME_MODEL_NAME TIME_MODEL FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1 --------- ------- ------- ---------- -------------------------------------------------- ---------- ------------------- ------------------- ---------- -------- ----------- 148 .0 100% | 2 PARSE HARD_PARSE 144 2024-04-08 09:25:30 2024-04-09 04:25:32 1 148 148 --//很明显CPU的消耗集中在PARSE HARD_PARSE,注:我猜测PARSE表示软分析,HARD_PARSE是硬分析. --//TIME_MODEL= 144 = 0x90 $ echo "obase=2;144" | bc -l 10010000 --//第4,7位为1,从0开始计数. --//看看ashtop.sql脚本的其中一段: , CASE WHEN BITAND(time_model, POWER(2, 01)) = POWER(2, 01) THEN 'DBTIME ' END ||CASE WHEN BITAND(time_model, POWER(2, 02)) = POWER(2, 02) THEN 'BACKGROUND ' END ||CASE WHEN BITAND(time_model, POWER(2, 03)) = POWER(2, 03) THEN 'CONNECTION_MGMT ' END ||CASE WHEN BITAND(time_model, POWER(2, 04)) = POWER(2, 04) THEN 'PARSE ' END ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ||CASE WHEN BITAND(time_model, POWER(2, 05)) = POWER(2, 05) THEN 'FAILED_PARSE ' END ||CASE WHEN BITAND(time_model, POWER(2, 06)) = POWER(2, 06) THEN 'NOMEM_PARSE ' END ||CASE WHEN BITAND(time_model, POWER(2, 07)) = POWER(2, 07) THEN 'HARD_PARSE ' END ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ||CASE WHEN BITAND(time_model, POWER(2, 08)) = POWER(2, 08) THEN 'NO_SHARERS_PARSE ' END ||CASE WHEN BITAND(time_model, POWER(2, 09)) = POWER(2, 09) THEN 'BIND_MISMATCH_PARSE ' END ||CASE WHEN BITAND(time_model, POWER(2, 10)) = POWER(2, 10) THEN 'SQL_EXECUTION ' END ||CASE WHEN BITAND(time_model, POWER(2, 11)) = POWER(2, 11) THEN 'PLSQL_EXECUTION ' END ||CASE WHEN BITAND(time_model, POWER(2, 12)) = POWER(2, 12) THEN 'PLSQL_RPC ' END ||CASE WHEN BITAND(time_model, POWER(2, 13)) = POWER(2, 13) THEN 'PLSQL_COMPILATION ' END ||CASE WHEN BITAND(time_model, POWER(2, 14)) = POWER(2, 14) THEN 'JAVA_EXECUTION ' END ||CASE WHEN BITAND(time_model, POWER(2, 15)) = POWER(2, 15) THEN 'BIND ' END ||CASE WHEN BITAND(time_model, POWER(2, 16)) = POWER(2, 16) THEN 'CURSOR_CLOSE ' END ||CASE WHEN BITAND(time_model, POWER(2, 17)) = POWER(2, 17) THEN 'SEQUENCE_LOAD ' END ||CASE WHEN BITAND(time_model, POWER(2, 18)) = POWER(2, 18) THEN 'INMEMORY_QUERY ' END ||CASE WHEN BITAND(time_model, POWER(2, 19)) = POWER(2, 19) THEN 'INMEMORY_POPULATE ' END ||CASE WHEN BITAND(time_model, POWER(2, 20)) = POWER(2, 20) THEN 'INMEMORY_PREPOPULATE ' END ||CASE WHEN BITAND(time_model, POWER(2, 21)) = POWER(2, 21) THEN 'INMEMORY_REPOPULATE ' END ||CASE WHEN BITAND(time_model, POWER(2, 22)) = POWER(2, 22) THEN 'INMEMORY_TREPOPULATE ' END ||CASE WHEN BITAND(time_model, POWER(2, 23)) = POWER(2, 23) THEN 'TABLESPACE_ENCRYPTION ' END time_model_name --//注意看下划线,cpu消耗集中在PARSE 以及HARD_PARSE上,这也验证我的判断. 3.继续: --//按照链接https://blog.itpub.net/267265/viewspace-3008682/ => 20240311]sql_id=c8s65f1cuhcb1的优化.txt --//应该还有优化空间,尝试看看,不行放弃!! --//像这类硬分析很慢的sql语句如何解决呢,可以使用sql profile来控制减少分析时间. --//参考 https://blog.itpub.net/267265/viewspace-2151428/=>[20180302]sql profile能减少分析时间吗? --//注意如果你使用sql profile,一般情况下记录是一些统计信息,并不是执行计划的outline. --//必须使用sql profile交换方法. SYS@127.0.0.1:9014/ywdb> @ spsw af4692qv1f56q 0 af4692qv1f56q 0 '' true PL/SQL procedure successfully completed. ================================================================================================================================================= if drop or alter sql profile ,run : execute dbms_sqltune.drop_sql_profile(name => 'switch tuning af4692qv1f56q') execute dbms_sqltune.alter_sql_profile(name => 'switch tuning af4692qv1f56q',attribute_name=>'STATUS',value=>'DISABLED') ================================================================================================================================================= --//先禁用sql profile SYS@127.0.0.1:9014/ywdb> execute dbms_sqltune.alter_sql_profile(name => 'switch tuning af4692qv1f56q',attribute_name=>'STATUS',value=>'DISABLED') PL/SQL procedure successfully completed. $ cat aa.txt alter session set current_schema=PORTAL_PPI; alter session set statistics_level=all; column COLUMN_REF format a20 SELECt D.constraint_type as CONSTRAINT_TYPE, C.COLUMN_NAME, C.position, D.r_constraint_name, E.table_name as table_ref, f.column_name as column_ref, C.table_name FROM ALL_CONS_COLUMNS C inner join ALL_constraints D on D.OWNER = C.OWNER and D.constraint_name = C.constraint_name left join ALL_constraints E on E.OWNER = D.r_OWNER and E.constraint_name = D.r_constraint_name left join ALL_cons_columns F on F.OWNER = E.OWNER and F.constraint_name = E.constraint_name and F.position = c.position WHERE C.OWNER = 'PORTAL_HIS' and C.table_name = 'DATA_EXCHANGE_FP' and D.constraint_type <> 'P' order by d.constraint_name, c.position; alter session set current_schema=SYS ; --//注:适当将SELECT换成小写,做小量修改. SYS@127.0.0.1:9014/ywdb> @ aa.txt Session altered. Session altered. C COLUMN_NAME POSITION R_CONSTRAINT_NAME TABLE_REF COLUMN_REF TABLE_NAME - -------------------- ---------- ------------------------------ ------------------------------ -------------------- ---------- C NO DATA_EXCHANGE_FP Elapsed: 00:00:02.30 Session altered. --//可以发现第1次执行需要硬分析总是在2秒上下. SYS@127.0.0.1:9014/ywdb> execute dbms_sqltune.alter_sql_profile(name => 'switch tuning af4692qv1f56q',attribute_name=>'STATUS',value=>'ENABLED') PL/SQL procedure successfully completed. --//适当修改aa.txt里面的sql语句,就是顺便找一个字符换成小写.我的测试依次将SELECT换成小写,这样sql profile依旧生效. SYS@127.0.0.1:9014/ywdb> @ aa.txt Session altered. Session altered. C COLUMN_NAME POSITION R_CONSTRAINT_NAME TABLE_REF COLUMN_REF TABLE_NAME - -------------------- ---------- ------------------------------ ------------------------------ -------------------- ---------- C NO DATA_EXCHANGE_FP Elapsed: 00:00:01.24 Session altered. --//再次小量修改aa.txt SYS@127.0.0.1:9014/ywdb> @ aa.txt Session altered. Session altered. C COLUMN_NAME POSITION R_CONSTRAINT_NAME TABLE_REF COLUMN_REF TABLE_NAME - -------------------- ---------- ------------------------------ ------------------------------ -------------------- ---------- C NO DATA_EXCHANGE_FP Elapsed: 00:00:00.92 Session altered. --//可以发现这样第一次执行的硬分析远比原来没有使用sql profile的时间小. --//不做修改: SYS@127.0.0.1:9014/ywdb> @ aa.txt Session altered. Session altered. C COLUMN_NAME POSITION R_CONSTRAINT_NAME TABLE_REF COLUMN_REF TABLE_NAME - -------------------- ---------- ------------------------------ ------------------------------ -------------------- ---------- C NO DATA_EXCHANGE_FP Elapsed: 00:00:00.02 Session altered. --//因为语句已经在共享池,做的是软分析,执行很快. --//顺便说一下,该问题也许跟我最近设置一些会话设置cursor_sharing=exact有关,谓词存在to_char函数,并且大量语句使用文字变量. --//等一段时间观察看看. SYS@127.0.0.1:9014/ywdb> @ sqlhh af4692qv1f56q 4/24 time unit : millisecond BEGIN_INTERVAL_TIME INST_ID SQL_ID PLAN_HASH_VALUE EXECUTIONS ELA_MS_PER_EXEC CPU_MS_PER_EXEC ROWS_PER_EXEC LIOS_PER_EXEC BLKRD_PER_EXEC IOW_MS_PER_EXEC AVG_IOW_MS CLW_MS_PER_EXEC APW_MS_PER_EXEC CCW_MS_PER_EXEC ------------------- ---------- ------------- --------------- ---------- --------------- --------------- ------------- ------------- -------------- --------------- ----------- --------------- --------------- --------------- 2024-04-09 12:00:15 2 af4692qv1f56q 1518780269 1 790 765 1.0 265 0 0 0.0 0 0 0 2024-04-09 12:00:15 1 af4692qv1f56q 1518780269 1 5 5 1.0 209 0 0 0.0 0 0 0 2024-04-09 13:00:23 1 af4692qv1f56q 1518780269 1 4 4 1.0 209 0 0 0.0 0 0 0 2024-04-09 13:00:23 2 af4692qv1f56q 1518780269 1 773 641 1.0 265 0 0 0.0 0 0 0 2024-04-09 14:00:00 1 af4692qv1f56q 1518780269 2 4 5 1.0 209 0 0 0.0 0 0 0 2024-04-09 14:00:00 2 af4692qv1f56q 1518780269 1 884 875 1.0 307 0 0 0.0 0 0 0 6 rows selected. --//下午观察,现在平均8XX毫秒,问题还是在实例2. SYS@127.0.0.1:9014/ywdb> @ dashtop to_char(sample_time,'yyyymmdd'),time_model sql_id='af4692qv1f56q' &100day Total Seconds AAS %This TO_CHAR TIME_MODEL FIRST_SEEN LAST_SEEN --------- ------- ------- -------- ---------- ------------------- ------------------- 180 .0 31% 20240408 144 2024-04-08 00:40:34 2024-04-08 23:18:10 110 .0 19% 20240407 144 2024-04-07 13:33:56 2024-04-07 23:09:44 90 .0 16% 20240329 144 2024-03-29 09:44:09 2024-03-29 23:48:32 70 .0 12% 20240313 144 2024-03-13 10:04:45 2024-03-13 21:12:21 30 .0 5% 20240401 144 2024-04-01 15:31:07 2024-04-01 16:44:27 30 .0 5% 20240409 144 2024-04-09 00:09:17 2024-04-09 13:24:14 20 .0 3% 20240311 144 2024-03-11 20:12:36 2024-03-11 21:53:53 20 .0 3% 20240330 144 2024-03-30 00:48:52 2024-03-30 00:58:55 10 .0 2% 20240331 144 2024-03-31 21:49:00 2024-03-31 21:49:00 10 .0 2% 20240401 1024 2024-04-01 20:51:10 2024-04-01 20:51:10 10 .0 2% 20240409 1024 2024-04-09 09:37:57 2024-04-09 09:37:57 11 rows selected. 4.附上sqlid_fms.sql脚本: $ cat sqlid_fms.sql -- Copyright 2023 lfree. All rights reserved. -- Licensed under the Apache License, Version 2.0. See LICENSE.txt for terms and conditions. -------------------------------------------------------------------------------- -- -- File name: sqlid_fms.sql -- Purpose: query sql_id to find force_matching_signature from gv$sql -- -- Author: lfree -- -- Usage: -- @ sqlid_fms.sql <sql_id> -- -------------------------------------------------------------------------------- SELECT REPLACE (sql_fulltext, CHR (13), '') c200 FROM gv$sqlarea WHERE sql_id = '&&1' AND ROWNUM = 1; prompt prompt time unit : microsecond prompt SELECT sql_id , child_number , inst_id , first_load_time , buffer_gets , executions , elapsed_time , ROUND (elapsed_time / nullif(executions, 0), 2) avg_ela_time , plan_hash_value, ROUND (buffer_gets / nullif(executions, 0), 2) lios_per_exec , force_matching_signature FROM gv$sql WHERE sql_id = '&&1' ORDER BY 4 DESC;

编辑推荐：

返回列表

[20240409]为什么一条sql语句在实例2执行要慢的分析.txt

编辑推荐：

相关推荐

excel表格怎样在数字前输入0

excel表格里怎么替换数据

excel表格里面如何插入圆形

excel表格里怎么添加表格数据透视表

excel表格中怎么添加线边框

excel表格里怎样设置条件自动排序

excel表格例怎样导入数据库

Excel表格如何设置数据排序

excel表格里怎么选择性粘贴快捷键

excel表格怎么插入分隔符号

excel表格怎么设置多行多列数据内容排序

Excel表格如何设置行和列相互转换

excel表格连接公式怎么使用

excel表格怎样链接到cad中

雷神推出 MIX PRO II 迷你主机：基于 Ultra 200H，玻璃上盖 + ARGB 灯效

制造商 Musnap 推出彩色墨水屏电纸书 Ocean C：支持手写笔、第三方安卓应用

最新软件资讯

热文推荐

天极热推