[20240410]奇怪的逻辑读.txt

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

[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;

相关推荐