干货 | Insert语句执行缓慢问题分析

作者 ：柴国树 | 东方龙马（OLM）

对于DBA来说，insert语句可能是最常见的sql之一了，但当insert语句出现性能问题时，很多时候我们往往无从下手，下面我们就分享一个关于insert语句性能问题的分析案例

注：本文中对客户以及表和sql语句等敏感信息做了屏蔽处理

用户发现应用发生阻塞，收集发生问题时的ASH报告如下图所示：

Top SQL Statements

可以看到，SQLID为“bunx3harbq71u”的SQL被阻塞，等待事件为“enq: TX - row lock contention”，很常见的行级排他锁

通过查询，发现多个会话都在执行sql语句bunx3harbq71u：SELECT *+ first_rows */ XX  FROM LINC.A WHERE  XX  FOR UPDATE OF DTIME

所有执行该sql的session均处于等待状态，阻塞者为SID为799的session

BLOCKING_SESSION 799

BLOCKING_SESSION_SERIAL#9535

该session当前正在执行如下sql语句：

79suf5b8ahm6c：INSERT INTO LINC.A (...) VALUES (...)

从该会话的信息我们发现该insert操作已经执行4分钟左右，通过查询确认该会话的事物没有提交，这是其他执行select for update的session产生行锁等待的原因。

在正常情况下，INSERT INTO LINC.A (...) VALUES (...)语句基本都是秒级操作，当前会话执行如此之慢并非一个正常情况，当即查看该session的等待事件：

从上表中我们看到，该会话等待事件为“db file sequential read”，该insert语句之所以执行速度缓慢，原因在于在插入操作之前，oracle读取了大量的数据块，产生db file sequential read等待，这是一种异常现象。

现场与用户进行沟通，确认该问题出现前，除了对表LINC.A做了一次数据批量插入以外，应用代码没有更新，数据库没有任何变更操作。

根据以往处理问题的经验，初步怀疑这是一个Oracle关于insert操作方面的bug，检索metalink相关文档，并验证了我们的猜测。

Oracle自9I后就推出了ASSM（自动段空间管理功能），对于数据块的空间使用位图方式进行管理

在执行批量数据插入时候，Oracle为保证效率，部分已经用满的数据块，在数据段头部不会立即标记为“FULL”，而显示为依然存在可用空间。批量插入结束后的下一次插入数据，若扫描到该数据块，因为剩余空间不足，则会并标记块为“FULL”状态，并查找下一个快，直至找到能够容纳当前记录的数据块。故做完大批量插入后，第一条INSERT的记录耗时会较长。该操作可以通过设置EVENT 10320和10162跟踪。

Metalink上文档1263496.1详细阐述了上述问题，该情况与客户遇到的情况相符

INSERT slow on ASSM (文档 ID 1263496.1)

SYMPTOMS

A single INSERT statement following a large batch INSERT is very slow. The second execution of the same INSERT finishes immediately.

The 10046 trace file for the first single slow INSERT shows excessive  waits on 'db file sequential read':

Elapsed times include waiting on following events:

Event waited on

Times  Max. Wait Total Waited

---------------------------------------- Waited ---------- ------

rdbms ipc reply                             1       0.00        0.00

SQL*Net more data from client         2       0.00        0.00

db file sequential read                    9670  0.02        13.73

db file scattered read                     56      0.02       0.84

SQL*Net break/reset to client           1        0.00       0.00

The execution statistics show excessive values for 'db block gets':

Statistics

------------------

1 recursive calls 

46272 db block gets 

13 consistent gets 

21101 physical reads 

2937940 redo size 

1123 bytes sent via SQL*Net to client 

1631 bytes received via SQL*Net from client 

4 SQL*Net roundtrips to/from client 

1 sorts (memory) 

0 sorts (disk) 

1 rows processed

The statistics for the second execution of the same INSERT shows low values for 'db block gets':

Statistics

--------------------- 

0 recursive calls

5 db block gets 

1 consistent gets

1 physical reads 

0 redo size 

1134 bytes sent via SQL*Net to client

1631 bytes received via SQL*Net from client

4 SQL*Net roundtrips to/from client 

1 sorts (memory)

0 sorts (disk) 

1 rows processed

Using the DBMS_SPACE.UNUSED_SPACE as listed below shows that the FS1 blocks before the first INSERT move to the FULL blocks following the slow execution:

create or replace procedure get_space_info is

。。。

prompt FS1 means 0-25% free space within a block

prompt FS2 means 25-50% free space within a block

prompt FS3 means 50-75% free space within a block

prompt FS4 means 75-100% free space within a block 

set serveroutput on

exec get_space_info;

When tracing the ASSM space allocation during the first single slow INSERT using the following events, the FS1 blocks appear to be marked as FULL:

SQL> ALTER SESSION SET EVENTS '10320 trace name context forever , level 3';

SQL> ALTER SESSION SET EVENTS '10612 trace name context forever , level 1';

SQL> -- run the single INSERT 

-- the trace file contains the following comments:

...

[ktspsrch] adddba dba:0x0100636b curl1:0x01006280 curl2:0x01002601

ktspfsrch: Returns: BlockDBA:0x0100637b

kdt_bseg_srch_cbk: examine dba=4.0x0100637b

kdt_bseg_srch_cbk: failed dba=4.0x0100637b avs=837 afs=0 tosp=837 full=1

ktspfupdst: state change tsn 4, objd 96400, objn 71401, blksz 8192

ktspfupdst: oldstate 2, newstate 1, delta bytes 1065

ktspfupdst: fdba: 0x01006280 offset: 251 nblks: 1 newstate: 1

kdt_bseg_srch_cbk: mark full ----------------------------------> the blocks is marked as full

ktspfsrch:Cbk didnot like 0x0100637b

...

This is the same situation as in Bug 7411960 "A SIMPLE INSERT CAUSES LOTS OF 'DB FILE SEQUENTIAL READ' WAITS" and it is the expected behavior. As per bug explanation, this is because there are multiple blocks with insufficient space to store the new data and Oracle needs to skip these blocks during the search for a good candidate. Oracle has been trying to balance the performance versus space management on ASSM segments. In this case, it seems Oracle inclined over the space management and this caused to have multiple blocks not marked as full, but not having enough space to accommodate new rows. So, Oracle needs to read multiple blocks in order to find one block with enough space to insert the new row. 

This behavior also applies to higher versions like 11g.

据库内置存储过程DBMS_REPAIR.SEGMENT_FIX_STATUS用于修正ASSM段头信息未及时更正数据块状态的问题，避免下次插入时用到块容量不一致的块。

官方解释：Provides the capability to fix the corrupted state of a bitmap entry when segment space management is AUTO

在批量insert插入完成后，执行以下语句来修正没有剩余空间的数据块未被标记为full的问题

EXECUTE DBMS_REPAIR.SEGMENT_FIX_STATUS('<owner>','<table_name>');

综上所述，如果数据库出现简单insert语句执行速度缓慢的情况，需要考虑所涉及的表是否之前做过批量插入操作，如果符合条件，那该问题与oracle批量插入后对数据块进行容量标记的机制有关，在批量插入数据后，某些没有剩余空间的块并没有被标示为full的状态，oracle认为其依然可用于以后的数据插入，导致后续insert操作需要读取多个块后才能找到合适的数据块进行写入，从而延长了整个语句的执行时间。

建议在批量插入后执行以下语句来正确标记块空间的使用情况，从而提高insert语句的插入速度。

SQL> EXECUTE DBMS_REPAIR.SEGMENT_FIX_STATUS('OWNER','TABLE_NAME');

|  北京    |    上海    |   广州    |   成都    |

4008-906-960