[20231012]奇怪的执行时长.txt

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

[20231012]奇怪的执行时长(sql_id=dtt2yfpx8jhp4).txt --//今天例行检查,我发现一个奇怪的sql语句,实际上以前也遇到过,太久不做维护了,有点忘记了!! 1.环境: SYS@192.168.100.235:1521/orcl> @ver1 SYS@192.168.100.235:1521/orcl> @ pr ============================== PORT_STRING : x86_64/Linux 2.4.xx VERSION : 19.0.0.0.0 BANNER : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production BANNER_FULL : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.3.0.0.0 BANNER_LEGACY : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production CON_ID : 0 PL/SQL procedure successfully completed. 2.分析: SYS@192.168.100.235:1521/orcl> @ ashtop sql_id 1=1 &day Total Distinct Distinct Seconds AAS %This SQL_ID FIRST_SEEN LAST_SEEN Execs Seen Tstamps --------- ------- ------- ------------- ------------------- ------------------- ---------- -------- 43254 .5 51% | 2023-10-11 08:35:40 2023-10-12 08:35:35 3 19604 3687 .0 4% | dtt2yfpx8jhp4 2023-10-11 15:40:01 2023-10-11 16:41:35 1 3687 2696 .0 3% | cyqv7gknyf7bh 2023-10-12 01:41:36 2023-10-12 08:34:38 1533 2696 1864 .0 2% | 1p68ys9y3582r 2023-10-11 08:40:25 2023-10-12 08:30:44 1857 1521 1393 .0 2% | g1v8dts358gq5 2023-10-11 08:35:39 2023-10-12 08:30:18 316 1205 1152 .0 1% | 8p09mg2dsvvfa 2023-10-11 08:40:07 2023-10-12 08:33:38 606 1015 1074 .0 1% | 3uzhsvstyytm2 2023-10-11 08:58:23 2023-10-11 23:52:26 148 1044 1052 .0 1% | bfcjfb3yhz8rt 2023-10-11 08:36:07 2023-10-12 08:34:57 779 1032 987 .0 1% | gxak7guzxkwbh 2023-10-11 08:37:05 2023-10-12 08:35:27 747 951 880 .0 1% | 89u3urxj9zs1x 2023-10-11 08:37:50 2023-10-12 08:33:04 179 880 ... 30 rows selected. --//dtt2yfpx8jhp4仅仅执行1次,竟然要1个小时，而且是w3wp.exe执行的。 SYS@192.168.100.235:1521/orcl> @ sql_id dtt2yfpx8jhp4 --SQL_ID = dtt2yfpx8jhp4 select *from lis_sample_operate where barcode=:Barcode and EXECUTE_STATE_TEXT='锁定报告' --//建立了barcode的索引,应该执行很快啊. SYS@192.168.100.235:1521/orcl> @ dpc dtt2yfpx8jhp4 '' '' PLAN_TABLE_OUTPUT ------------------------------------- SQL_ID dtt2yfpx8jhp4, child number 0 ------------------------------------- select *from lis_sample_operate where barcode=:Barcode and EXECUTE_STATE_TEXT='锁定报告' Plan hash value: 2118786184 ---------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | E-Rows |E-Bytes| Cost (%CPU)| E-Time | ---------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 12 (100)| | |* 1 | TABLE ACCESS BY INDEX ROWID BATCHED| LIS_SAMPLE_OPERATE | 1 | 127 | 12 (0)| 00:00:01 | |* 2 | INDEX RANGE SCAN | IX_LIS_SAMPLE_OPERATE_BARCODE | 8 | | 4 (0)| 00:00:01 | ---------------------------------------------------------------------------------------------------------------------- Query Block Name / Object Alias (identified by operation id): ------------------------------------------------------------- 1 - SEL$1 / LIS_SAMPLE_OPERATE@SEL$1 2 - SEL$1 / LIS_SAMPLE_OPERATE@SEL$1 Peeked Binds (identified by position): -------------------------------------- 1 - :1 (VARCHAR2(30), CSID=852): '1801158810' Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter("EXECUTE_STATE_TEXT"=U'\9501\5B9A\62A5\544A') 2 - access("BARCODE"=SYS_OP_C2C(:BARCODE)) Note ----- - Warning: basic plan statistics not available. These are only collected when: * hint 'gather_plan_statistics' is used for the statement or * parameter 'statistics_level' is set to 'ALL', at session or system level --//应该执行很快啊. --//查看传入的绑定变量值。 SYS@192.168.100.235:1521/orcl> @ bind_cap_awr dtt2yfpx8jhp4 '' @bind_cap_awr sql_id [column] SNAP_ID INSTANCE_NUMBER SQL_ID WAS LAST_CAPTURED NAME POSITION MAX_LENGTH DATATYPE_STRING VALUE_STRING ------- --------------- ------------- --- ------------------- -------- ---------- ---------- --------------- --------------- 24195 1 dtt2yfpx8jhp4 YES 2023-09-01 17:12:17 :BARCODE 1 32 VARCHAR2(32) _ 24196 1 dtt2yfpx8jhp4 YES 2023-09-01 17:12:17 :BARCODE 1 32 VARCHAR2(32) _ 24310 1 dtt2yfpx8jhp4 YES 2023-09-06 12:52:53 :BARCODE 1 32 VARCHAR2(32) _ 24311 1 dtt2yfpx8jhp4 YES 2023-09-06 12:52:53 :BARCODE 1 32 VARCHAR2(32) _ 24886 1 dtt2yfpx8jhp4 YES 2023-09-30 12:11:24 :BARCODE 1 32 VARCHAR2(32) 7211153713 24887 1 dtt2yfpx8jhp4 YES 2023-09-30 12:11:24 :BARCODE 1 32 VARCHAR2(32) 7211153713 25153 1 dtt2yfpx8jhp4 YES 2023-10-11 15:59:32 :BARCODE 1 32 VARCHAR2(32) 20231011001256 25154 1 dtt2yfpx8jhp4 YES 2023-10-11 15:59:32 :BARCODE 1 32 VARCHAR2(32) 20231011001256 8 rows selected. --//查询带入绑定变量的值马上明白为什么,存在带入'_'的情况,开发程序将'_'当作空值.(注意是下划线而非减号) SYS@192.168.100.235:1521/orcl> select count(*) from lis.LIS_SAMPLE_OPERATE where barcode='_'; COUNT(*) ---------- 598071 SYS@192.168.100.235:1521/orcl> select count(*) from lis.LIS_SAMPLE_OPERATE; COUNT(*) ---------- 136678697 --//598071/136678697 = .00437574408541515434 --//程序在操作时没有做输入检查或者需求就是这样,导致索引要扫描大量数据,导致执行缓慢,我记忆里以前也遇到过.再次做一个记录. --//我顺便查了几个数据块，几乎每个数据块都有barcode='_'的记录,走索引比全表扫描还慢.再看看表大小. SYS@192.168.100.235:1521/orcl> @ segsum lis.lis_sample_operate SEG_MB OWNER SEGMENT_NAME SEGMENT_TYPE SEG_TABLESPACE_NAME SUM(BLOCKS) ---------- -------------------- ------------------------------ -------------------- ------------------------------ ----------- 21062 LIS LIS_SAMPLE_OPERATE TABLE LIS_DATA 2695936 --//21G呢? 要建立索引估计给包括EXECUTE_STATE_TEXT字段,放弃!! --//正常的业务应该看不到带入_的查询,开发应该在程序中限制这样的情况出现. --//我自己做一个推测，这个值应该不是键盘输入的，而是通过手持扫描器输入的，可能在扫描时出现问题，比如出现非法字符，应用自动重置为_. --//操作员没看继续查询，出现问题，或者是扫描后马上自动执行。不过从执行次数上看仅仅1次，说明这个功能很少使用。 SYS@192.168.100.235:1521/orcl> select count(*), EXECUTE_STATE_TEXT from lis.LIS_SAMPLE_OPERATE where barcode='_' group by EXECUTE_STATE_TEXT; COUNT(*) EXECUTE_STATE_TEXT ---------- ------------------------ 156204 标本归档 10382 锁定报告 ~~~~~~~~~~~~~~~~~ 339 复制样本 ... 54 rows selected. --//如果查询返回10382条,这样的操作属于无效查询,没有任何意义. --//我总觉的在dba与开发之间存在一条无法跨越的鸿沟,沟通存在问题.