【原】案例精解：insert逻辑读暴增至20万，只因Oracle Recyclebin过大

墨墨导读：某客户的数据库一条insert某段时间突然变慢，平均单次执行逻辑读暴增至20万，最终定位为insert时因可用空间不充足递归清理recyclebin中的对象导致。

概述

某客户的数据库一条insert语句某段时间突然变慢，平均单次执行逻辑读暴增至20万，最终定位为insert时因可用空间不充足递归清理recyclebin中的对象导致，递归delete from RECYCLEBIN$，因没有合适的索引走full scan，正常情况下也没啥影响，但该客户的这套库SYS.RECYCLEBIN$竟然达到700M.最终导致了该问题。
这里在我的测试环境中，模拟重现该问题。

测试过程

1. 清空回收

SQL> purge dba_recyclebin;
DBA Recyclebin purged.

2. 创建测试表空间

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 setmypidStatement processed.SQL> oradebug event 10046 trace name context forever,level 12Statement processed.SQL> oradebug tracefile_name/app/oracle/diag/rdbms/db19c/db19c/trace/db19c_ora_2604.trcSQL> insert /*+gather_plan_statistics */into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> SQL> @xDisplay 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 * fromtest.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 | | | 52 (100)| 0 |00:00:00.02 | 2989 | 175 || 1 | LOAD TABLE CONVENTIONAL | TMP3 | 1 | | | | 0 |00:00:00.02 | 2989 | 175 || 2 | TABLE ACCESS FULL | TMP2 | 1 | 9999 | 1142K| 52 (0)| 9999 |00:00:00.01 | 176 | 175 |-------------------------------------------------------------------------------------------------------------------------
15 rows selected.

从上面的执行计划看到逻辑读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> @xDisplay 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 * fromtest.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 | | | 52 (100)| 0 |00:00:01.90 | 36872 | 22291 || 1 | LOAD TABLE CONVENTIONAL | TMP3 | 1 | | | | 0 |00:00:01.90 | 36872 | 22291 || 2 | TABLE ACCESS FULL | TMP2 | 1 | 9999 | 1142K| 52 (0)| 9999 |00:00:00.01 | 177 | 0 |-------------------------------------------------------------------------------------------------------------------------
15 rows selected.

这次insert逻辑读为36872，是正常INSERT逻辑读2989的10倍以上 !!!

SQL> oradebug event 10046 trace name context offStatement 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 b52m6vduutr8jdelete 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 0Execute 1 0.13 0.13 15807 16888 13 1Fetch 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: 1Misses in library cache during execute: 1Optimizer mode: CHOOSEParsing 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 逻辑读暴增！

表空间紧张，递归清理回收站大概逻辑

1. 使用以下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)

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);

墨天轮原文链接：https://www./db/40753（复制到浏览器中打开或者点击“阅读原文”）