（点击
上方公众号
，可快速关注）
作者：潇湘隐者
www.cnblogs.com/kerrycode/p/5836015.html
如有好文章投稿，请点击 → 这里了解详情
今天遇到一个很有意思的问题，一个开发人员反馈在测试服务器ORACLE数据库执行的一条简单SQL语句非常缓慢，他写的一个SQL没有返回任何数据，但是耗费了几分钟的时间。让我检查分析一下原因，分析解决过后，发现事情的真相有点让人哭笑不得，但是也是非常有意思的。我们先简单构造一下类似的案例，当然只是简单模拟。
假设一个同事A，创建了一个表并初始化了数据（实际环境数据量较大，有1G多的数据），但是他忘记提交了。我们简单模拟如下：
SQL
>
create
table
test_uncommit
2
as
3
select
*
from
dba_objects
where
1
=
0;
Table
created.
SQL
>
declare
rowIndex
number;
2
begin
3
for
rowIndex
in
1..70
loop
4
insert
into
test_uncommit
5
select
*
from
dba_objects;
6
end loop
;
7
end
;
8
/
PL
/
SQL
procedure
successfully
completed.
SQL
>
另外一个同事B对这个表做一些简单查询操作，但是他不知道同事A的没有提交INSERT语句，如下所示，查询时间用了大概5秒多（这个因为构造的数据量不是非常大的缘故。实际场景耗费了几分钟）
SQL
>
SET
TIMING
ON
;
SQL
>
SET
AUTOTRACE
ON
;
SQL
>
SELECT COUNT
(1)
FROM
SYS.TEST_UNCOMMIT
WHERE
OBJECT_ID
=
39;
COUNT
(1)
----------
0
Elapsed:
00:00:05.38
Execution
Plan
----------------------------------------------------------
Plan
hash
value
:
970680813
------------------------------------------------------------------------------------
|
Id
|
Operation
|
Name
|
Rows
|
Bytes
|
Cost
(%CPU)|
Time
|
------------------------------------------------------------------------------------
|
0
|
SELECT
STATEMENT
|
|
1
|
13
|
6931
(3)|
00:00:10
|
|
1
|
SORT
AGGREGATE
|
|
1
|
13
|
|
|
|*
2
|
TABLE
ACCESS
FULL
|
TEST_UNCOMMIT
|
1
|
13
|
6931
(3)|
00:00:10
|
------------------------------------------------------------------------------------
Predicate
Information
(
identified by
operation
id):
---------------------------------------------------
2
-
filter(
"OBJECT_ID"
=39)
Note
-----
-
dynamic
sampling
used
for
this
statement
Statistics
----------------------------------------------------------
4
recursive
calls
0
db
block
gets
229304
consistent
gets
61611
physical
reads
3806792
redo
size
514
bytes
sent
via
SQL
*
Net
to
client
492
bytes
received
via
SQL
*
Net
from
client
2
SQL
*
Net
roundtrips
to
/
from
client
0
sorts
(
memory
)
0
sorts
(disk)
1
rows
processed
SQL
>
当时是在SQL Developer工具里面分析SQL的执行计划，并没有注意到redo size非常大的情况。刚开始怀疑是统计信息不准确导致，手工收集了一下该表的统计信息，执行的时间和执行计划依然如此，没有任何变化。 如果我们使用SQL*Plus，查看执行计划，就会看到redo size异常大，你就会有所察觉（见后面分析）
SQL
>
exec
dbms_stats.gather_table_stats(
'SYS'
,
'TEST_UNCOMMIT'
);
PL
/
SQL
procedure
successfully
completed.
Elapsed:
00:00:12.29
因为ORACLE里面的写不阻塞读，所以不可能是因为SQL阻塞的缘故，然后我想查看这个表到底有多少记录，结果亮瞎了我的眼睛，记录数为0，但是空间用掉了852 个数据块
SQL
>
SELECT
TABLE_NAME,
NUM_ROWS,
BLOCKS
FROM
DBA_TABLES
WHERE
TABLE_NAME=
'TEST_UNCOMMIT'
;
TABLE_NAME
NUM_ROWS
BLOCKS
----------------------------
-- ---------- ----------
TEST_UNCOMMIT
0
852
SQL
>
于是我使用Tom大师的show_space脚本检查、确认该表的空间使用情况，如下所示，该表确实使用852个数据块。
SQL
>
set
serverout
on
;
SQL
>
exec
show_space(
'TEST_UNCOMMIT'
);
Free
Blocks.............................
852
Total
Blocks............................
896
Total
Bytes.............................
7,340,032
Total
MBytes............................
7
Unused
Blocks...........................
43
Unused
Bytes............................
352,256
Last
Used
Ext
FileId....................
1
Last
Used
Ext
BlockId...................
88,201
Last
Used
Block.........................
85
PL
/
SQL
procedure
successfully
completed.
SQL
>
分析到这里，那么肯定是遇到了插入数据操作,却没有提交的缘故。用下面脚本检查发现一个会话ID为883的对这个表有一个ROW级排他锁，而且会话还有一个事务排他锁，那么可以肯定这个会话执行了DML操作，但是没有提交。
SET
linesize
190
COL
osuser
format
a15
COL
username
format
a20
wrap
COL
object_name
format
a20
wrap
COL
terminal
format
a25
wrap
COL
req_mode
format
a20
SELECT
B.SID,
C.USERNAME,
C.OSUSER,
C.TERMINAL,
DECODE
(B.ID2,
0,
A.OBJECT_NAME,
'TRANS-'
||TO_CHAR(B.ID1))
OBJECT_NAME,
B.
TYPE
,
DECODE
(B.LMODE,
0,
'WAITING'
,
1,
'NULL'
,
2,
'Row-S(SS)'
,
3,
'ROW-X(SX)'
,
4,
'SHARE'
,
5,
'S/ROW-X(SSX)'
,
6,
'EXCLUSIVE'
