案例精解:insert邏輯讀暴增至20萬,只因Oracle Recyclebin過大

墨墨導讀：某客戶的資料庫一條insert某段時間突然變慢，平均單次執行邏輯讀暴增至20萬，最終定位為insert時因可用空間不充足遞歸清理recyclebin中的對象導致。

概述某客戶的資料庫一條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.
刪除表 test.tmp1
SQL> drop table  test.tmp1 ;
Table dropped.
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
開啟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 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 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 into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> insert into test.tmp3 select * from test.tmp2 ;
9999 rows created.
SQL> insert 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 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.
觀察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        rowsParse        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           0total        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    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
purge相關段
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);
Gather stats on RecycleBin$ table and indexes:
exec dbms_stats.gather_table_stats(ownname=>'SYS',tabname=>'RecycleBin$', cascade=>TRUE);
墨天輪原文連結：https://www.modb.pro/db/40753（複製到瀏覽器中打開或者點擊「閱讀原文」）

2020數據技術嘉年華近50個PPT下載、視頻回放已上傳墨天輪平臺，可在「數據和雲」公眾號回復關鍵詞「2020DTC」獲得！
視頻號，新的分享時代，關注我們，看看有什麼新發現？
數據和雲
ID：OraNews
如有收穫，請劃至底部，點擊「在看」，謝謝！
點擊下圖查看更多 ↓
長按，識別二維碼，加入萬人交流社群
請備註：雲和恩墨大講堂