[20240410]奇怪的逻辑读.txt --//生产系统优化遇到奇怪的执行情况,搞不懂为什么?探究看看. 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> @ fms 5 10 &day FORCE_MATCHING_SIGNATURE SQL_ID_COUNT TOTAL_SECONDS ------------------------ ------------ ------------- 8680396602758190538 1400 1722 13026426528625086727 774 1169 6490285911540139840 277 320 12120531484079936454 275 289 8968795636694904691 148 252 16302384038956377077 200 225 15582081887848190096 134 184 13723358513528852507 92 160 7809763007758332172 143 159 10224702229797097847 45 67 10 rows selected. --//fms脚本用来查询gv$active_session_history记录FORCE_MATCHING_SIGNATURE相同sql_id不同的sql语句. SYS@127.0.0.1:9014/ywdb> @ ffms 8680396602758190538 10 C200 -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- select a.ksdm,a.jgid,a.ksmc,b.act from ms_ghks a,(select count(1) as act,ksdm,jgid from (SELECT MS_YYHY.HYID, to_char(MS_YYHY.GZRQ,'yyyymmdd') GZRQ ,MS_YYHY.YYSD, MS_GHKS.KSMC, MS_YYHY.KSDM, GY_YGDM .YGXM, MS_YYHY.YSDM, MS_YYHY.YYBZ,MS_MZGHF.GHF,MS_MZGHF.ZLF,MS_GHKS.JGID FROM MS_YYHY,MS_GHKS,GY_YGDM,MS_YSKS,MS_MZGHF WHERE MS_YYHY.KSDM = MS_GHKS.KSDM AND MS_YYHY.YSDM = GY_YGDM.YGDM AND MS_YSKS.Mzks = MS_YYHY.KSDM AND MS_YSKS.YSDM = GY_YGDM.YGDM AND MS_YSKS.FYXH = MS_MZGHF.FYXH AND MS_YYHY.T GBZ = 0 AND MS_YYHY.YYBZ = 0 AND MS_YYHY.NWBZ = 1 AND MS_YYHY.GZRQ = to_date('20240413','yyyymmdd') And MS_YYHY.YSDM='5729'AND MS_GHKS.KSDM =273) group by ksdm,jgid) b where a.ksdm=b.ksdm and a.jgid=b .jgid and a.ksdm =273 order by a.jgid time unit : microsecond SQL_ID CHILD_NUMBER INST_ID FIRST_LOAD_TIME BUFFER_GETS EXECUTIONS ROWS_PROCESSED ELAPSED_TIME AVG_ELA_TIME PLAN_HASH_VALUE LIOS_PER_EXEC ------------- ------------ ---------- ------------------- ----------- ---------- -------------- ------------ ------------ --------------- ------------- a2d7vmm3wtgvc 0 2 2024-04-10/10:05:14 231 1 0 61472 61472 1874477375 231 7f7kuqqd1z2zp 0 2 2024-04-10/10:05:14 231 1 0 60417 60417 1874477375 231 839152ckx6c48 0 2 2024-04-10/10:05:14 231 1 0 63390 63390 1874477375 231 5ka1w8x55q2yd 0 2 2024-04-10/10:05:13 231 1 0 66518 66518 1874477375 231 9v26k2ftumjqn 0 1 2024-04-10/10:05:13 231 1 0 64188 64188 1874477375 231 87r0x9fna7frj 0 2 2024-04-10/10:05:13 231 1 0 60880 60880 1874477375 231 gwtzpbubyaua2 0 2 2024-04-10/10:05:13 231 1 0 89278 89278 1874477375 231 765qr5schjdwh 0 2 2024-04-10/10:04:51 231 1 0 78078 78078 1874477375 231 86b5n8jdb72n0 0 1 2024-04-10/10:04:44 231 1 0 71647 71647 1874477375 231 6tc2gf72wz9jx 0 1 2024-04-10/10:04:44 231 1 0 49302 49302 1874477375 231 10 rows selected. --//ffms.sql脚本用来查询gv$sql看看FORCE_MATCHING_SIGNATURE=8680396602758190538有那些,参数2显示数量.前面查询的sql语句仅仅 --//显示1条作为参考. --//你可以发现1个现象,ROWS_PROCESSED=0.逻辑读231.并且执行次数基本都是1,扩大查询范围也是一样,而我手工执行逻辑读都是1(即使 --//我修改sql语句,做硬解析): Plan hash value: 1874477375 ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | | 7 (100)| | 0 |00:00:00.01 | 1 | | | | | 1 | NESTED LOOPS | | 1 | 1 | 68 | 7 (15)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 2 | VIEW | | 1 | 1 | 28 | 6 (17)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 3 | HASH GROUP BY | | 1 | 1 | 44 | 6 (17)| 00:00:01 | 0 |00:00:00.01 | 1 | 983K| 983K| | | 4 | NESTED LOOPS | | 1 | 1 | 44 | 6 (17)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 5 | NESTED LOOPS | | 1 | 1 | 41 | 6 (17)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 6 | NESTED LOOPS | | 1 | 1 | 29 | 5 (20)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 7 | VIEW | VW_GBF_32 | 1 | 1 | 24 | 5 (20)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 8 | HASH GROUP BY | | 1 | 1 | 46 | 5 (20)| 00:00:01 | 0 |00:00:00.01 | 1 | 964K| 964K| | | 9 | NESTED LOOPS | | 1 | 1 | 46 | 4 (0)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 10 | NESTED LOOPS | | 1 | 2 | 46 | 4 (0)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | | 11 | TABLE ACCESS BY INDEX ROWID| MS_GHKS | 1 | 1 | 20 | 1 (0)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | |* 12 | INDEX RANGE SCAN | I_MS_GHKS_KSDM | 1 | 1 | | 1 (0)| 00:00:01 | 0 |00:00:00.01 | 1 | | | | |* 13 | INDEX RANGE SCAN | I_MS_YYHY_GZRQ_YSDM | 0 | 2 | | 2 (0)| 00:00:01 | 0 |00:00:00.01 | 0 | | | | |* 14 | TABLE ACCESS BY INDEX ROWID | MS_YYHY | 0 | 1 | 26 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 | | | | |* 15 | INDEX UNIQUE SCAN | PK_GY_YGDM | 0 | 1 | 5 | 0 (0)| | 0 |00:00:00.01 | 0 | | | | | 16 | TABLE ACCESS BY INDEX ROWID | MS_YSKS | 0 | 1 | 12 | 1 (0)| 00:00:01 | 0 |00:00:00.01 | 0 | | | | |* 17 | INDEX UNIQUE SCAN | I_MS_YSKS_MZKS_YSDM | 0 | 1 | | 0 (0)| | 0 |00:00:00.01 | 0 | | | | |* 18 | INDEX UNIQUE SCAN | PK_MS_MZGHF | 0 | 1 | 3 | 0 (0)| | 0 |00:00:00.01 | 0 | | | | |* 19 | TABLE ACCESS BY INDEX ROWID | MS_GHKS | 0 | 1 | 40 | 1 (0)| 00:00:01 | 0 |00:00:00.01 | 0 | | | | |* 20 | INDEX RANGE SCAN | I_MS_GHKS_KSDM | 0 | 1 | | 0 (0)| | 0 |00:00:00.01 | 0 | | | | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- --//逻辑读是1.难道第1次执行许多递归的逻辑读都要计入该语句中吗? --//我使用set autotrace traceonly跟踪.适当修改sql语句,修改一个字符从大写变成小写,这样重新做1次硬分析. SYS@127.0.0.1:9014/ywdb> @ gzbpf991tzmtr.sql9_0 PL/SQL procedure successfully completed. Session altered. Session altered. no rows selected Execution Plan ---------------------------------------------------------- Plan hash value: 1874477375 ------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 68 | 7 (15)| 00:00:01 | | 1 | NESTED LOOPS | | 1 | 68 | 7 (15)| 00:00:01 | | 2 | VIEW | | 1 | 28 | 6 (17)| 00:00:01 | | 3 | HASH GROUP BY | | 1 | 44 | 6 (17)| 00:00:01 | | 4 | NESTED LOOPS | | 1 | 44 | 6 (17)| 00:00:01 | | 5 | NESTED LOOPS | | 1 | 41 | 6 (17)| 00:00:01 | | 6 | NESTED LOOPS | | 1 | 29 | 5 (20)| 00:00:01 | | 7 | VIEW | VW_GBF_32 | 1 | 24 | 5 (20)| 00:00:01 | | 8 | HASH GROUP BY | | 1 | 46 | 5 (20)| 00:00:01 | | 9 | NESTED LOOPS | | 1 | 46 | 4 (0)| 00:00:01 | | 10 | NESTED LOOPS | | 2 | 46 | 4 (0)| 00:00:01 | | 11 | TABLE ACCESS BY INDEX ROWID| MS_GHKS | 1 | 20 | 1 (0)| 00:00:01 | |* 12 | INDEX RANGE SCAN | I_MS_GHKS_KSDM | 1 | | 1 (0)| 00:00:01 | |* 13 | INDEX RANGE SCAN | I_MS_YYHY_GZRQ_YSDM | 2 | | 2 (0)| 00:00:01 | |* 14 | TABLE ACCESS BY INDEX ROWID | MS_YYHY | 1 | 26 | 3 (0)| 00:00:01 | |* 15 | INDEX UNIQUE SCAN | PK_GY_YGDM | 1 | 5 | 0 (0)| 00:00:01 | | 16 | TABLE ACCESS BY INDEX ROWID | MS_YSKS | 1 | 12 | 1 (0)| 00:00:01 | |* 17 | INDEX UNIQUE SCAN | I_MS_YSKS_MZKS_YSDM | 1 | | 0 (0)| 00:00:01 | |* 18 | INDEX UNIQUE SCAN | PK_MS_MZGHF | 1 | 3 | 0 (0)| 00:00:01 | |* 19 | TABLE ACCESS BY INDEX ROWID | MS_GHKS | 1 | 40 | 1 (0)| 00:00:01 | |* 20 | INDEX RANGE SCAN | I_MS_GHKS_KSDM | 1 | | 0 (0)| 00:00:01 | ------------------------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 12 - access(TO_NUMBER("KSDM")=75) 13 - access("MS_YYHY"."GZRQ"=TO_DATE(' 2024-04-11 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND "MS_YYHY"."YSDM"='650') 14 - filter(TO_NUMBER("MS_YYHY"."KSDM")=75 AND "MS_YYHY"."KSDM"="MS_GHKS"."KSDM") 15 - access("ITEM_2"="GY_YGDM"."YGDM") 17 - access("MS_YSKS"."MZKS"="ITEM_1" AND "MS_YSKS"."YSDM"="GY_YGDM"."YGDM") 18 - access("MS_YSKS"."FYXH"="MS_MZGHF"."FYXH") 19 - filter("A"."JGID" IS NOT NULL AND "A"."JGID"="B"."JGID") 20 - access(TO_NUMBER("KSDM")=75) Statistics ---------------------------------------------------------- 806 recursive calls 0 db block gets 231 consistent gets 0 physical reads 0 redo size 529 bytes sent via SQL*Net to client 509 bytes received via SQL*Net from client 1 SQL*Net roundtrips to/from client 0 sorts (memory) 0 sorts (disk) 0 rows processed --//确实是consistent gets=231,看看硬分析导致806次递规调用.开发应该重视合理地使用绑定变量. --//第2次执行,逻辑读就是1. Statistics ---------------------------------------------------------- 0 recursive calls 0 db block gets 1 consistent gets 0 physical reads 0 redo size 529 bytes sent via SQL*Net to client 509 bytes received via SQL*Net from client 1 SQL*Net roundtrips to/from client 0 sorts (memory) 0 sorts (disk) 0 rows processed --//再次看出没有使用绑定变量带来问题. --//另外一点注意的地方是在会话设置statistics_level=all,看执行计划的逻辑读并没有把一些递归执行的逻辑读记入. --//实际上如果看出有执行多次就很容易发现这个细节问题: SYS@127.0.0.1:9014/ywdb> @ ffms 8680396602758190538 200 SQL_ID CHILD_NUMBER INST_ID FIRST_LOAD_TIME PLAN_HASH_VALUE ELAPSED_TIME EXECUTIONS BUFFER_GETS ROWS_PROCESSED LIOS_PER_EXEC ROWS_PER_EXEC AVG_ELA_TIME ------------- ------------ ---------- -------------------- --------------- ------------ ---------- ----------- -------------- ------------- ------------- ------------ ... 1yht54qu3rpuy 0 2 2024-04-10/10:30:28 1874477375 66895 1 231 0 231 0 66895 88xpu4vgq7h3s 0 2 2024-04-10/10:30:28 1874477375 113700 2 232 0 116 0 56850 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 373a3r0sbhfbc 0 2 2024-04-10/10:30:25 1874477375 74739 1 235 0 235 0 74739 g0rj4kuhv7x65 0 2 2024-04-10/10:30:25 1874477375 60312 1 235 0 235 0 60312 f002tj5fjbv0a 0 1 2024-04-10/10:30:25 1874477375 79006 1 235 0 235 0 79006 5x4mqfw7vuphh 0 1 2024-04-10/10:30:25 1874477375 118722 2 240 0 120 0 59361 200 rows selected. 3.附上相关脚本: $ cat 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: fms.sql v1.0 -- Purpose: Query gv$active_session_history Force_Matching_Signature the same, sql_id different of information -- Author: lfree -- -- Usage: -- @ fms <count(*)_number> <display_record_number> <fromtime> <totime> -- <count(*)_number>=2> -- -- Example: -- @ fms 5 30 &day -- -- Other: -- This script uses only the in-memory GV$ACTIVE_SESSION_HISTORY, use -- @dfms.sql for accessiong the DBA_HIST_ACTIVE_SESS_HISTORY archive -- -------------------------------------------------------------------------------- WITH a1 AS (SELECT sql_id,force_matching_signature, count(*) cnt1 FROM gv$active_session_history WHERE force_matching_signature <> 0 AND sample_time BETWEEN &3 AND &4 and sql_opname<>'INSERT' GROUP BY sql_id, force_matching_signature ) , a2 AS (SELECT force_matching_signature, count(*) sql_id_count,sum(cnt1) total_seconds FROM a1 GROUP BY force_matching_signature HAVING count(*) >= &&1 ORDER BY 3 desc) SELECT force_matching_signature, sql_id_count,total_seconds FROM a2 WHERE rownum <= &2; --//显示字段顺序做了一些调整. $ cat ffms.sql -- Copyright 2023 lfree. All rights reserved. -- Licensed under the Apache License, Version 2.0. See LICENSE.txt for terms and conditions. -------------------------------------------------------------------------------- -- -- File name: ffms.sql -- Purpose: find force_matching_signature from gv$sql -- -- Author: lfree -- -- Usage: -- @ ffms FORCE_MATCHING_SIGNATURE <display_record_number> -- -------------------------------------------------------------------------------- SELECT REPLACE (sql_fulltext, CHR (13), '') c200 FROM gv$sqlarea WHERE FORCE_MATCHING_SIGNATURE = &&1 AND ROWNUM = 1; prompt prompt time unit : microsecond prompt column FIRST_LOAD_TIME format a20 SELECT * FROM ( SELECT sql_id ,child_number ,inst_id ,first_load_time ,plan_hash_value ,elapsed_time ,executions ,buffer_gets ,rows_processed ,ROUND (buffer_gets / nullif(executions,0),2) lios_per_exec ,ROUND (rows_processed / nullif(executions,0),2) rows_per_exec ,ROUND (elapsed_time / nullif(executions,0),2) avg_ela_time FROM gv$sql WHERE FORCE_MATCHING_SIGNATURE = &&1 ORDER BY 4 DESC) WHERE ROWNUM <= &&2;
[20240410]奇怪的逻辑读.txt
来源:这里教程网
时间:2026-03-03 19:53:53
作者:
编辑推荐:
下一篇:
相关推荐
-
雷神推出 MIX PRO II 迷你主机:基于 Ultra 200H,玻璃上盖 + ARGB 灯效
2 月 9 日消息,雷神 (THUNDEROBOT) 现已宣布推出基于英
-
制造商 Musnap 推出彩色墨水屏电纸书 Ocean C:支持手写笔、第三方安卓应用
2 月 10 日消息,制造商 Musnap 现已在海外推出一款 Oce
热文推荐
- 在线办公:巨头通往新质生产力的一把利剑
在线办公:巨头通往新质生产力的一把利剑
26-03-03 - 数据库管理-第175期 深入探索CPU性能(20240424)
数据库管理-第175期 深入探索CPU性能(20240424)
26-03-03 - Oracle 12CR2 RAC部署翻车,bug避坑经历
Oracle 12CR2 RAC部署翻车,bug避坑经历
26-03-03 - 单表分页语句优化思路
单表分页语句优化思路
26-03-03 - 第一次参加DTC归来
第一次参加DTC归来
26-03-03 - 数据库备份脚本嘎嘎香,被秀到了!
数据库备份脚本嘎嘎香,被秀到了!
26-03-03 - 地平线、黑芝麻智能扎堆上市:智驾黎明来了?
地平线、黑芝麻智能扎堆上市:智驾黎明来了?
26-03-03 - 关闭TED报ORA-28365: wallet is not open
关闭TED报ORA-28365: wallet is not open
26-03-03 - 19c数据库/dev/shm/过小导致pga内存不够
19c数据库/dev/shm/过小导致pga内存不够
26-03-03 - 毫秒级响应的INSERT操作为何会突发执行30秒
毫秒级响应的INSERT操作为何会突发执行30秒
26-03-03
