Table of contents
Preamble
An interesting problem came to me while I was checking one of our critical database performance and so top wait events. I obviously used AWR reports and, a script I have not used since very long time, $ORACLE_HOME/rdbms/admin/sqltrpt.sql to display 15 Most expensive SQL in the cursor cache and 15 Most expensive SQL in the workload repository.
Surprisingly I have immediately seen a well know monitoring administrative SQL in I/O consumer SQL (top 15):
CREATE TABLE dba_free_space_dfspace AS SELECT a.file_id,SUM(bytes) AS bytes FROM dba_free_space a GROUP BY a.file_id |
It was also the opportunity to discover that my teammates decided to run this tablespace completion monitoring script every half an hour which is, in my opinion, not a good idea (4 times a day looks enough)… The story behind is that one day they failed to discover fast enough a tablespace full so the idiot decision to increase monitoring frequency…
How recycle bin comes in loop
I already had many issue performance with this DBA_FREE_SPACE view but this was dark ages time of dictionary tablespaces. UET$ and FET$ can become very big with lots of dictionary tablespaces and so selecting on this view was taking around half an hour on my DataWareHouse Terabytes database… Migration to locally managed tablespaces completely solved the issue.
Even if complex the explain plan is (always in cursor cache but I used AWR, don’t know why):
SQL> SELECT * FROM TABLE(dbms_xplan.display_awr('cq7u51dmn6hpr')); PLAN hash VALUE: 4099389883 ------------------------------------------------------------------------------------------------------ | Id | Operation | Name | ROWS | Bytes | COST (%CPU)| TIME | ------------------------------------------------------------------------------------------------------ | 0 | CREATE TABLE STATEMENT | | | | 1135K(100)| | | 1 | LOAD AS SELECT | | | | | | | 2 | HASH GROUP BY | | 36 | 576 | 1135K (24)| 03:47:05 | | 3 | VIEW | DBA_FREE_SPACE | 1247K| 19M| 1135K (24)| 03:47:04 | | 4 | UNION-ALL | | | | | | | 5 | NESTED LOOPS | | 51 | 1479 | 9 (0)| 00:00:01 | | 6 | MERGE JOIN CARTESIAN | | 36 | 720 | 8 (0)| 00:00:01 | | 7 | TABLE ACCESS FULL | TS$ | 1 | 11 | 6 (0)| 00:00:01 | | 8 | BUFFER SORT | | 36 | 324 | 2 (0)| 00:00:01 | | 9 | TABLE ACCESS FULL | FILE$ | 36 | 324 | 2 (0)| 00:00:01 | | 10 | TABLE ACCESS CLUSTER | FET$ | 1 | 9 | 1 (0)| 00:00:01 | | 11 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| | | 12 | NESTED LOOPS | | 86 | 5590 | 31 (0)| 00:00:01 | | 13 | NESTED LOOPS | | 86 | 4816 | 6 (0)| 00:00:01 | | 14 | TABLE ACCESS FULL | TS$ | 12 | 204 | 6 (0)| 00:00:01 | | 15 | FIXED TABLE FIXED INDEX | X$KTFBFE (ind:1) | 7 | 273 | 0 (0)| | | 16 | TABLE ACCESS FULL | FILE$ | 1 | 9 | 0 (0)| | | 17 | NESTED LOOPS | | 1247K| 118M| 1132K (24)| 03:46:25 | | 18 | NESTED LOOPS | | 3206K| 278M| 261K(100)| 00:52:20 | | 19 | HASH JOIN | | 41688 | 1058K| 132 (2)| 00:00:02 | | 20 | TABLE ACCESS FULL | RECYCLEBIN$ | 41688 | 366K| 125 (1)| 00:00:02 | | 21 | TABLE ACCESS FULL | TS$ | 12 | 204 | 6 (0)| 00:00:01 | | 22 | FIXED TABLE FIXED INDEX | X$KTFBUE (ind:1) | 77 | 5005 | 6 (100)| 00:00:01 | | 23 | TABLE ACCESS FULL | FILE$ | 1 | 9 | 0 (0)| | | 24 | NESTED LOOPS | | 1 | 42 | 128 (2)| 00:00:02 | | 25 | NESTED LOOPS | | 1 | 31 | 127 (2)| 00:00:02 | | 26 | NESTED LOOPS | | 1 | 22 | 126 (2)| 00:00:02 | | 27 | TABLE ACCESS FULL | RECYCLEBIN$ | 41688 | 366K| 125 (1)| 00:00:02 | | 28 | TABLE ACCESS CLUSTER | UET$ | 1 | 13 | 0 (0)| | | 29 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 0 (0)| | | 30 | TABLE ACCESS BY INDEX ROWID| FILE$ | 1 | 9 | 1 (0)| 00:00:01 | | 31 | INDEX UNIQUE SCAN | I_FILE2 | 1 | | 0 (0)| | | 32 | TABLE ACCESS CLUSTER | TS$ | 1 | 11 | 1 (0)| 00:00:01 | | 33 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| | ------------------------------------------------------------------------------------------------------ |
Nothing apparently noticeable except the select on RECYCLEBIN$ with more than 40,000 rows that moved to more than one hundred Megabytes with hash join and nested loop.
While searching on My Oracle Support (MOS) I found on MOS note “Queries on DBA_FREE_SPACE are Slow [ID 271169.1]” that explains that slow query can be explained by recyclebin and found that our HP OpenView monitoring account (OVO) is owning most of them:
SQL> SELECT owner,COUNT(*) FROM dba_recyclebin GROUP BY owner; OWNER COUNT(*) ------------------------------ ---------- OVO 53481 DATALOAD 634 |
Re-entered in script to which I participated a long time ago and found those Linked to two drop/create objects. The issue never came in loop because normally the default tablespace of this monitoring account is SYSTEM and accordingly to Oracle official documentation recycle bin are generated only if:
The table must have resided in a locally managed tablespace other than the SYSTEM tablespace.
I purged it (more than 1/4 hour to do it !!) and select on DBA_FREE_SPACE moved from more than one minute to few seconds !! The monitoring job now does 100 times less I/O, 30 times less buffer get, using 400 time less CPU and executed 40 times more faster !! Not bad…
If using SYSTEM tablespace is not an option (normal situation) then you have few tricks to avoid recycle bin generation for your session or at database level:
ALTER SESSION|SYSTEM SET recyclebin=off; DROP TABLE xxx purge; |
References
- Queries on DBA_FREE_SPACE are Slow [ID 271169.1]
