墨墨导读：某客户的数据库一条insert某段时间突然变慢，平均单次执行逻辑读暴增至20万，本文分享整个处理过程。
概述
某客户的数据库一条insert语句某段时间突然变慢，平均单次执行逻辑读暴增至20万，最终定位为insert时因可用空间不充足递归清理recyclebin中的对象导致，递归delete from RECYCLEBIN$，因没有合适的索引走full scan，正常情况下没有影响，但该客户的这套库SYS.RECYCLEBIN$竟然达到700M，最终导致了该问题。
这里在我的测试环境中，模拟重现该问题。
测试过程
清空回收
SQL> purge dba_recyclebin;
DBA Recyclebin purged.
创建测试表空间
SQL> create tablespace testtbs datafile '/home/oracle/data/testtbs.dbf' size 10m;
Tablespace created.
SQL> @df
TABLESPACE_NAME TotalMB UsedMB FreeMB % Used Ext Used
------------------------------ ---------- ---------- ---------- ------ --- ----------------------
SYSAUX 350 328 22 94% YES |################### |
SYSTEM 280 271 9 97% YES |####################|
TBS 20 17 3 85% NO |################# |
TBS2 10 2 8 20% NO |#### |
TEMP 36 -64 100 -177% YES ||
TESTTBS 10 1 9 10% NO |## |
UNDOTBS1 100 48 52 48% YES |########## |
7 rows selected.
SQL>
3. 创建3个测试表
tmp1,tmp2 10000条记录
tmp3 空表
SQL> create table test.tmp1 tablespace testtbs as select * from dba_objects where rownum<=10000;
Table created.
SQL> SQL> create table test.tmp2 tablespace testtbs as select * from dba_objects where rownum<10000;
Table created.
SQL> SQL> create table test.tmp3 tablespace testtbs as select * from dba_objects where 1=0;
Table created.
4. 删除表 test.tmp1
SQL> drop table test.tmp1 ;
Table dropped.
5. insert sys.RECYCLEBIN$,把sys.RECYCLEBIN$ 撑大
SQL> insert into sys.RECYCLEBIN$ select t.* from sys.RECYCLEBIN$ t connect by level<2000000;
insert into sys.RECYCLEBIN$ select t.* from sys.RECYCLEBIN$ t connect by level<2000000
*
ERROR at line 1:
ORA-30009: Not enough memory for CONNECT BY operation
这个报错，无影响，达到撑大sys.RECYCLEBIN$的目的就行。
SQL> rollback;
Rollback complete.
SQL> @seg sys.RECYCLEBIN$
SEG_MB OWNER SEGMENT_NAME SEG_PART_NAME SEGMENT_TYPE SEG_TABLESPACE_NAME BLOCKS HDRFIL HDRBLK
---------- -------------------- ------------------------------ ------------------------------ -------------------- ------------------------------ ---------- ---------- ----------
136 SYS RECYCLEBIN$ TABLE SYSTEM 17408 13 34656
26 SYS RECYCLEBIN$_OBJ INDEX SYSTEM 3328 13 34680
23 SYS RECYCLEBIN$_TS INDEX SYSTEM 2944 13 34672
24 SYS RECYCLEBIN$_OWNER INDEX SYSTEM 3072 13 34664
6. 开启10046，insert test.tmp3 重现该递归清理回收站问题
SQL> oradebug setmypid
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12
Statement processed.
SQL> oradebug tracefile_name
/app/oracle/diag/rdbms/db19c/db19c/trace/db19c_ora_2604.trc
SQL> insert /*+gather_plan_statistics */into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> SQL> @x
Display execution plan for last statement for this session from library cache...
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 1ndf8zpn2bpsp, child number 0
-------------------------------------
insert /*+gather_plan_statistics */into test.tmp3 select * from
test.tmp2
Plan hash value: 1016474986
-------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| A-Rows | A-Time | Buffers | Reads |
-------------------------------------------------------------------------------------------------------------------------
| 0 | INSERT STATEMENT | | 1 | | |
从上面的执行计划看到逻辑读2989，这是一个正常值。
继续insert数据，直到表空间不够递归清理回收站
SQL> insert /*+gather_plan_statistics */into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> insert /*+gather_plan_statistics */into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> insert /*+gather_plan_statistics */into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> @x
Display execution plan for last statement for this session from library cache...
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 1ndf8zpn2bpsp, child number 0
-------------------------------------
insert /*+gather_plan_statistics */into test.tmp3 select * from
test.tmp2
Plan hash value: 1016474986
-------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| A-Rows | A-Time | Buffers | Reads |
-------------------------------------------------------------------------------------------------------------------------
| 0 | INSERT STATEMENT | | 1 | |
这次insert逻辑读为36872，是正常INSERT逻辑读2989的10倍以上 !!!
SQL> oradebug event 10046 trace name context off
Statement processed.
7. 观察10046递归sql
[oracle@test ~]$ tkprof /app/oracle/diag/rdbms/db19c/db19c/trace/db19c_ora_2604.trc tk.txt
TKPROF: Release 19.0.0.0.0 - Development on Wed Nov 18 20:43:10 2020
Copyright (c) 1982, 2019, Oracle and/or its affiliates. All rights reserved.
sql_id b52m6vduutr8j
delete from RecycleBin$ where bo=:1
********************************************************************************
SQL ID: b52m6vduutr8j Plan Hash: 716146596
delete from RecycleBin$
where
bo=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.13 0.13 15807 16888 13 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.13 0.13 15807 16888 13 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 DELETE RECYCLEBIN$ (cr=16888 pr=15807 pw=0 time=131249 us starts=1)
1 1 1 TABLE ACCESS FULL RECYCLEBIN$ (cr=16888 pr=15801 pw=0 time=130870 us starts=1 cost=2 size=52 card=1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 30 0.00 0.00
db file scattered read 1352 0.00 0.02
****************************************
可以从trace中看到这样一条SQL,执行了一次，full scan,逻辑读16888，加上其它一些递归sql最终导致insert 逻辑读暴增！
表空间紧张，递归清理回收站大概逻辑
使用以下SQL查询该表空间中可以清理的回收站对象。按dropscn排序，最小drop的最先清理。
select obj#, type#, flags, related, bo, purgeobj, con# from RecycleBin$ where ts#=:1 and to_number(bitand(flags, 16)) = 16 order by dropscn
2. purge相关段
3. delete RecycleBin$
delete from RecycleBin$ where bo=:1
解决方法
mos上有一遍说明了purge时该递归sql的性能问题，并建议在RecycleBin$(bo)上创建索引。
Purging RECYCLEBIN Running Fosrever (Doc ID 2284986.1)
Create new index on bo column:
create index RecycleBin$_bo on RecycleBin$(bo);
2. Gather stats on RecycleBin$ table and indexes:
exec dbms_stats.gather_table_stats(ownname=>'SYS',tabname=>'RecycleBin$', cascade=>TRUE);
作者
范计杰，云和恩墨技术顾问，5年大型ORACLE数据库维护经验，擅长性能调优、故障处理等。
墨天轮原文链接：https://www.modb.pro/db/40753（复制到浏览器打开或者点击“阅读原文”立即查看）
推荐阅读：267页！2020年度数据库技术年刊
推荐下载：2020数据技术嘉年华PPT下载
2020数据技术嘉年华近50个PPT下载、视频回放已上传墨天轮平台，可在“数据和云”公众号回复关键词“2020DTC”获得！
视频号，新的分享时代，关注我们，看看有什么新发现？
数据和云
ID：OraNews
如有收获，请划至底部，点击“在看”，谢谢！
点击下图查看更多 ↓
云和恩墨大讲堂 | 一个分享交流的地方
长按，识别二维码，加入万人交流社群
请备注：云和恩墨大讲堂
点个“在看”
你的喜欢会被看到❤
扫一扫
382
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
