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

数据和云

发布于 2021-02-08 14:36:31

4850

墨墨导读：某客户的数据库一条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 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 |        |       |    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> @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 |        |       |    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 off
Statement 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  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

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

本文参与腾讯云自媒体同步曝光计划，分享自微信公众号。

原始发表：2021-01-19，如有侵权请联系 cloudcommunity@tencent.com 删除

编程算法

sql

腾讯云测试服务

本文分享自数据和云微信公众号，前往查看

如有侵权，请联系 cloudcommunity@tencent.com 删除。

本文参与腾讯云自媒体同步曝光计划，欢迎热爱写作的你一起参与！

编程算法

sql

腾讯云测试服务

登录后参与评论

0 条评论

热度