首页 > 数据库 > Oracle > [20230216]奇怪的高逻辑读3.txt
[20230216]奇怪的高逻辑读3.txt
--//昨天在生产系统看到一条逻辑读很高的sql语句,检查发现谓词使用了DBMS_LOB.SUBSTR函数.
--//开发真奇葩,我无论如何也想不出开发为什么这些写代码,当时脑子短路了,使用trunc还好理解一点.
--//我开始以为主要原因是lob类型导致fetch记录是1行1行提取,逻辑读提高,但是实测的效果要高出许多倍.
--//在测试环境模拟探究看看:
1.环境:
SCOTT@book> @ 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.建立测试例子:
create table t as select * from all_objects <=100;
@ gts t '' ''
SCOTT@book> @ desc_proc sys dbms_lob substr
INPUT OWNER PACKAGE_NAME OBJECT_NAME
sample : @desc_proc sys dbms_stats gather_%_stats
OWNER PACKAGE_NAME OBJECT_NAME SEQUENCE ARGUMENT_NAME DATA_TYPE IN_OUT DEFAULTED
---------- ------------ ----------- -------- ------------- --------- --------- ----------
SYS DBMS_LOB SUBSTR 1 RAW OUT N
2 LOB_LOC BLOB IN N
3 AMOUNT NUMBER IN Y
4 OFFSET NUMBER IN Y
1 VARCHAR2 OUT N
2 LOB_LOC CLOB IN N
3 AMOUNT NUMBER IN Y
4 OFFSET NUMBER IN Y
1 RAW OUT N
2 FILE_LOC BFILE IN N
3 AMOUNT NUMBER IN Y
4 OFFSET NUMBER IN Y
12 rows selected.
--//dbms_lob.substr函数参数与substr不一样,第2个参数AMOUNT表示取字符串的数量,第3个参数OFFSET表示字符串的偏移量.
--//注意最后一列DEFAULTED表明可以不输入第2,3参数(Y),不知道缺省怎么值.可以根据下面的执行推断offset缺省值=1.
3.测试:
SCOTT@book> @ sl all
alter session set statistics_level = all;
Session altered.
SCOTT@book> select * from t where dbms_lob.substr(object_name)='DEPT';
no rows selected
--//第1次执行:
Plan hash value: 1601196873
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | Reads |
-----------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 0 |00:00:00.07 | 3081 | 8 |
|* 1 | TABLE ACCESS FULL| T | 1 | 1 | 75 | 3 (0)| 00:00:01 | 0 |00:00:00.07 | 3081 | 8 |
-----------------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / T@SEL$1
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("DBMS_LOB"."SUBSTR"(INTERNAL_FUNCTION("OBJECT_NAME"))='DEPT')
--//第1次执行不稳定buffers=3081,估计存在一些递规,以后执行都是1298.
--//第2次执行:
Plan hash value: 1601196873
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 0 |00:00:00.02 | 1298 |
|* 1 | TABLE ACCESS FULL| T | 1 | 1 | 75 | 3 (0)| 00:00:01 | 0 |00:00:00.02 | 1298 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / T@SEL$1
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("DBMS_LOB"."SUBSTR"(INTERNAL_FUNCTION("OBJECT_NAME"))='DEPT')
select * from t where dbms_lob.substr(object_name,30,1)='DEPT';
select * from t where dbms_lob.substr(object_name,30.0,1.0)='DEPT';
Plan hash value: 1601196873
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 0 |00:00:00.02 | 1298 |
|* 1 | TABLE ACCESS FULL| T | 1 | 1 | 75 | 3 (0)| 00:00:01 | 0 |00:00:00.02 | 1298 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / T@SEL$1
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("DBMS_LOB"."SUBSTR"(INTERNAL_FUNCTION("OBJECT_NAME"),30,1)='DEPT')
--//如果执行如下:
select t.*,dbms_lob.substr(object_name) from t
Plan hash value: 1601196873
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 100 |00:00:00.01 | 4 |
| 1 | TABLE ACCESS FULL| T | 1 | 100 | 7500 | 3 (0)| 00:00:01 | 100 |00:00:00.01 | 4 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / T@SEL$1
--//仅仅4个逻辑读.
SCOTT@book> select rowid from t where rownum<=1;
ROWID
------------------
AABSzYAAEAAAAijAAA
SCOTT@book> @ rowid AABSzYAAEAAAAijAAA
OBJECT FILE BLOCK ROW ROWID_DBA DBA TEXT
---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------
339160 4 2211 0 0x10008A3 4,2211 alter system dump datafile 4 block 2211
--//记录数据块的dba地址,后面有用!!
4.开启跟踪:
SCOTT@book> alter system set "_trace_pin_time"=1 scope=spfile;
System altered.
--//重启数据库略.
SCOTT@book> select * from t where dbms_lob.substr(object_name)='DEPT';
no rows selected
--//讲跟踪文件内容拷贝到20230217.txt
$ awk '{print $2}' 20230217.txt | sort | uniq -c | sort -rn
1210 release
301 ktswh133:
201 ktswh102:
101 ktswh100:
100 ktswh134:
100 ktswh123:
100 ktswh111:
100 ktswh110:
100 ktswh108:
100 kdlwh01:
100 kdlwh00:
2 kdswh11: --//访问表
1 ktswh130:
1 ktswh129:
1 ktswh115:
1 ktswh114:
1 ktswh107:
1 ktswh105:
1 ktswh101:
1 ktewh26: --//访问表
$ grep 0x10008a 20230217.txt
pin ktewh26: kteinpscan dba 0x10008a2:4 time 2251552903
pin kdswh11: kdst_fetch dba 0x10008a3:1 time 2251553064
pin kdswh11: kdst_fetch dba 0x10008a4:1 time 2251602100
--//扫描表对应块仅仅3次.
--//问题在于ktswhNNN,取出pin release行中dba值,执行如下:
$ grep "pin release" 20230217.txt | awk '{print $7}' | sort | uniq -c
605 0x404b00:4
203 0x404b01:12
302 0x404b02:11
50 0x404b03:1
50 0x404b04:1
--//605+203+302+50+50 = 1210
--//0x404b00 = set dba 1,19200 = alter system dump datafile 1 block 19200 = 4213504
--//0x404b04 = set dba 1,19204 = alter system dump datafile 1 block 19204 = 4213508
--//也就是反复访问dba = 1,19200 1,19201 1,19202 1,19203 1,19204
--//dba冒号后面的数字表示怎么不知道?
SCOTT@book> @ which_obj 1 19200
SCOTT@book> @ pr
==============================
OWNER : SYS
SEGMENT_NAME : ARGUMENT$
PARTITION_NAME :
SEGMENT_TYPE : TABLE
TABLESPACE_NAME : SYSTEM
EXTENT_ID : 18
FILE_ID : 1
BLOCK_ID : 19200
BYTES : 1048576
BLOCKS : 128
RELATIVE_FNO : 1
PL/SQL procedure successfully completed.
--//也就是反复查询SYS.ARGUMENT$获取对应支持需要那些参数吗?
SELECT distinct DBMS_ROWID.ROWID_BLOCK_NUMBER (rowid)
FROM sys.argument$ a
WHERE procedure$='SUBSTR'
AND
argument IN ('LOB_LOC', 'AMOUNT', 'OFFSET');
DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID)
------------------------------------
10247
--//块对不上!!
SELECT DISTINCT OBJ#, PROCEDURE$
FROM sys.argument$
WHERE ROWID BETWEEN 'AAAADfAABAAAEsAAAA' AND 'AAAADfAABAAAEsEDDD';
OBJ# PROCEDURE$
---- -------------
9148 FS_GETXATTR
9148 FS_READDIR
9148 FS_RELEASEDIR
9148 FS_TRUNCATE
9148 FS_MOVE
9148 FS_OPENDIR
9148 FS_CHMOD
9148 FS_CHOWN
9148 FS_REMOVEXATTR
9148 FS_SETXATTR
9148 FS_MKDIR
9148 FS_MKNOD
9148 FS_OPEN
9148 FS_UTIME
9148 FS_WRITE
9148 FS_FSYNC
9148 FS_SYMLINK
9148 FS_DESTROY
9148 FS_RELEASE
9148 FS_STATFS
9148 FS_READ
9148 FS_FLUSH
9148 FS_FSYNCDIR
9148 FS_CREAT
9148 FS_INIT
9148 FS_LINK
9148 FS_RENAME
9148 FS_RMDIR
9148 FS_LISTXATTR
9148 FS_UNLINK
9148 FS_ACCESS
31 rows selected.
--//似乎是底层的一些函数.
SCOTT@book> @ sl all
alter session set statistics_level = all;
Session altered.
SCOTT@book> select dbms_lob.substr(object_name) ,t.* from t ;
SCOTT@book> @ dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID 031na24n0u8y7, child number 1
-------------------------------------
select dbms_lob.substr(object_name) ,t.* from t
Plan hash value: 1601196873
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 100 |00:00:00.01 | 4 |
| 1 | TABLE ACCESS FULL| T | 1 | 100 | 7500 | 3 (0)| 00:00:01 | 100 |00:00:00.01 | 4 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / T@SEL$1
--//这样查询仅仅4个逻辑读.
SCOTT@book> select * from (select dbms_lob.substr(object_name) xx,t.* from t) where xx='DEPT';
no rows selected
SCOTT@book> @ dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID 9vwbhftau3207, child number 0
-------------------------------------
select * from (select dbms_lob.substr(object_name) xx,t.* from t) where
xx='DEPT'
Plan hash value: 1601196873
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 0 |00:00:00.05 | 1298 |
|* 1 | TABLE ACCESS FULL| T | 1 | 1 | 75 | 3 (0)| 00:00:01 | 0 |00:00:00.05 | 1298 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$F5BB74E1 / T@SEL$2
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("DBMS_LOB"."SUBSTR"(INTERNAL_FUNCTION("OBJECT_NAME"))='DEPT')
--//放弃探究!!总之不知道开发不知道为什么这样写代码.
来自 “ ITPUB博客 ” ,链接:https://blog.itpub.net/267265/viewspace-2936071/ ,如需转载,请注明出处,否则将追究法律责任。