暂无图片
暂无图片
6
暂无图片
暂无图片
暂无图片

oracle recyclebin过大导致的insert逻辑读暴增问题

2504

概述

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

测试过程

  1. 清空回收
SQL> purge dba_recyclebin; DBA Recyclebin purged.
  1. 创建测试表空间
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.
  1. 删除表 test.tmp1
SQL> drop table test.tmp1 ; Table dropped.
  1. 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
  1. 开启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.
  1. 观察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 逻辑读暴增!

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

  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
  1. purge相关段
  2. 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);
  1. Gather stats on RecycleBin$ table and indexes:
exec dbms_stats.gather_table_stats(ownname=>'SYS',tabname=>'RecycleBin$', cascade=>TRUE);
最后修改时间:2021-01-19 17:06:48
「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论