Sure...your trash will drag you!!!

If you have figured out what happened, you may be wondering why Oracle implemented the free space view in that way, don't you?

In case you are lost in the darkness follow the next real-life case:

Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options

SQL> select count(*) from dba_free_space;

 COUNT(*)
----------
   193822
                              _
SQL> select count(*) from all_objects where object_name like '%BIN%';

 COUNT(*)
----------
   175249

SQL> set timing on
SQL> run
 1  select count(*) from all_objects where object_name like '%BIN%'
 2*

 COUNT(*)
----------
   175249

Elapsed: 00:00:27.00
SQL> select count(*) from dba_free_space;

 COUNT(*)
----------
   193821

Elapsed: 00:00:45.71

That is a long waiting time for a free space report, don't you think? ... I'm not a lazy and careless DBA, but you can't take my word for granted, therefore I will check if statistics are more-or-less accurate and later refresh them, anyway.

SQL> select num_rows, blocks from all_Tables where table_name = 'RECYCLEBIN$';

 NUM_ROWS     BLOCKS
---------- ----------
   185640       2308

Elapsed: 00:00:00.05
SQL> exec dbms_stats.gather_table_stats(ownname=> 'SYS',
2: tabname=> 'RECYCLEBIN$', partname=> NULL);

PL/SQL procedure successfully completed.

Elapsed: 00:00:06.70
SQL> select count(*) from dba_free_space;

 COUNT(*)
----------
   193820

Elapsed: 00:00:46.02
SQL> run
 1* select count(*) from dba_free_space

 COUNT(*)
----------
   193787

Elapsed: 00:00:45.82
SQL> set autotrace on explain statistics
SQL> run
 1* select count(*) from dba_free_space

 COUNT(*)
----------
   193787

Elapsed: 00:00:46.20

Execution Plan
----------------------------------------------------------

------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name             | Rows  | Bytes |TempSpc| Cost (%CPU)|
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                  |     1 |       |       |  1563  (53)|
|   1 |  SORT AGGREGATE                |                  |     1 |       |       |            |
|   2 |   VIEW                         | DBA_FREE_SPACE   |   190 |       |       |  1563  (53)|
|   3 |    UNION-ALL                   |                  |       |       |       |            |
|   4 |     NESTED LOOPS               |                  |     1 |    39 |       |     4   (0)|
|   5 |      NESTED LOOPS              |                  |     1 |    32 |       |     3   (0)|
|   6 |       TABLE ACCESS FULL        | FET$             |     1 |    26 |       |     3   (0)|
|   7 |       INDEX UNIQUE SCAN        | I_FILE2          |     1 |     6 |       |     0   (0)|
|   8 |      TABLE ACCESS CLUSTER      | TS$              |     1 |     7 |       |     1   (0)|
|   9 |     NESTED LOOPS               |                  |    90 |  4050 |       |    12   (9)|
|  10 |      NESTED LOOPS              |                  |    90 |  3510 |       |    12   (9)|
|  11 |       TABLE ACCESS FULL        | TS$              |    36 |   468 |       |    11   (0)|
|  12 |       FIXED TABLE FIXED INDEX  | X$KTFBFE (ind:1) |     3 |    78 |       |     0   (0)|
|  13 |      INDEX UNIQUE SCAN         | I_FILE2          |     1 |     6 |       |     0   (0)|
|  14 |     NESTED LOOPS               |                  |    98 |  6762 |       |  1530  (54)|
|  15 |      NESTED LOOPS              |                  |    98 |  6174 |       |  1530  (54)|
|  16 |       HASH JOIN                |                  |   169K|  3983K|  3920K|   840  (16)|
|  17 |        TABLE ACCESS FULL       | RECYCLEBIN$      |   174K|  1871K|       |   585  (14)|
|  18 |        TABLE ACCESS FULL       | TS$              |    36 |   468 |       |    11   (0)|
|  19 |       FIXED TABLE FIXED INDEX  | X$KTFBUE (ind:1) |     1 |    39 |       |     0   (0)|
|  20 |      INDEX UNIQUE SCAN         | I_FILE2          |     1 |     6 |       |     0   (0)|
|  21 |     TABLE ACCESS BY INDEX ROWID| RECYCLEBIN$      |     1 |    11 |       |     2   (0)|
|  22 |      NESTED LOOPS              |                  |     1 |    63 |       |    17   (0)|
|  23 |       NESTED LOOPS             |                  |     1 |    52 |       |    15   (0)|
|  24 |        NESTED LOOPS            |                  |     1 |    45 |       |    14   (0)|
|  25 |         TABLE ACCESS FULL      | UET$             |     1 |    39 |       |    14   (0)|
|  26 |         INDEX UNIQUE SCAN      | I_FILE2          |     1 |     6 |       |     0   (0)|
|  27 |        TABLE ACCESS CLUSTER    | TS$              |     1 |     7 |       |     1   (0)|
|  28 |         INDEX UNIQUE SCAN      | I_TS#            |     1 |       |       |     0   (0)|
|  29 |       INDEX RANGE SCAN         | RECYCLEBIN$_TS   |  7961 |       |       |     2   (0)|
------------------------------------------------------------------------------------------------

Statistics
----------------------------------------------------------
   4027917  recursive calls
       129  db block gets
    891718  consistent gets
    175114  physical reads
         0  redo size
       517  bytes sent via SQL*Net to client
       469  bytes received via SQL*Net from client
         2  SQL*Net roundtrips to/from client
         0  sorts (memory)
         0  sorts (disk)
         1  rows processed

SQL> set autotrace off

Let's see what happen if we get rid off all that garbage... be pacient, it'll take 2 or 3 hours to purge the recycle bin.

SQL> purge dbarecycle_bin;

Recyclebin purged

Our timings will improve by the order of thousands, getting results in results in fractions of seconds. That will make easier and faster your space management tasks... say good bye to those long chats with your peers between tablespace resize (if you are using Enterprise Manager is even worse!).

SQL> run
 1* select count(*) from all_objects where object_name like '%BIN%'

 COUNT(*)
----------
      103

Elapsed: 00:00:00.20

SQL> set linesize 255
SQL> set autotrace on explain statistics
SQL> run
 1* select count(*) from dba_free_space

 COUNT(*)
----------
     1140

Elapsed: 00:00:00.06

Execution Plan
----------------------------------------------------------

------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name             | Rows  | Bytes |TempSpc| Cost (%CPU)|
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                  |     1 |       |      |  1563  (53)|
|   1 |  SORT AGGREGATE                |                  |     1 |       |      |             |
|   2 |   VIEW                         | DBA_FREE_SPACE   |   190 |       |      |  1563  (53)|
|   3 |    UNION-ALL                   |                  |       |       |      |             |
|   4 |     NESTED LOOPS               |                  |     1 |    39 |      |      4   (0)|
|   5 |      NESTED LOOPS              |                  |     1 |    32 |      |      3   (0)|
|   6 |       TABLE ACCESS FULL        | FET$             |     1 |    26 |      |      3   (0)|
|   7 |       INDEX UNIQUE SCAN        | I_FILE2          |     1 |     6 |      |      0   (0)|
|   8 |      TABLE ACCESS CLUSTER      | TS$              |     1 |     7 |      |      1   (0)|
|   9 |     NESTED LOOPS               |                  |    90 |  4050 |      |    12   (9)|
|  10 |      NESTED LOOPS              |                  |    90 |  3510 |      |    12   (9)|
|  11 |       TABLE ACCESS FULL        | TS$              |    36 |   468 |      |    11   (0)|
|  12 |       FIXED TABLE FIXED INDEX  | X$KTFBFE (ind:1) |     3 |    78 |      |      0   (0)|
|  13 |      INDEX UNIQUE SCAN         | I_FILE2          |     1 |     6 |      |      0   (0)|
|  14 |     NESTED LOOPS               |                  |    98 |  6762 |      |  1530  (54)|
|  15 |      NESTED LOOPS              |                  |    98 |  6174 |      |  1530  (54)|
|  16 |       HASH JOIN                |                  |   169K|  3983K|  3920K|   840  (16)|
|  17 |        TABLE ACCESS FULL       | RECYCLEBIN$      |   174K|  1871K|      |   585  (14)|
|  18 |        TABLE ACCESS FULL       | TS$              |    36 |   468 |      |    11   (0)|
|  19 |       FIXED TABLE FIXED INDEX  | X$KTFBUE (ind:1) |     1 |    39 |      |      0   (0)|
|  20 |      INDEX UNIQUE SCAN         | I_FILE2          |     1 |     6 |      |      0   (0)|
|  21 |     TABLE ACCESS BY INDEX ROWID| RECYCLEBIN$      |     1 |    11 |      |      2   (0)|
|  22 |      NESTED LOOPS              |                  |     1 |    63 |      |    17   (0)|
|  23 |       NESTED LOOPS             |                  |     1 |    52 |      |    15   (0)|
|  24 |        NESTED LOOPS            |                  |     1 |    45 |      |    14   (0)|
|  25 |         TABLE ACCESS FULL      | UET$             |     1 |    39 |      |    14   (0)|
|  26 |         INDEX UNIQUE SCAN      | I_FILE2          |     1 |     6 |      |      0   (0)|
|  27 |        TABLE ACCESS CLUSTER    | TS$              |     1 |     7 |      |      1   (0)|
|  28 |         INDEX UNIQUE SCAN      | I_TS#            |     1 |       |      |      0   (0)|
|  29 |       INDEX RANGE SCAN         | RECYCLEBIN$_TS   |  7961 |       |      |      2   (0)|
------------------------------------------------------------------------------------------------

Statistics
----------------------------------------------------------
       295  recursive calls
       129  db block gets
     12437  consistent gets
         0  physical reads
         0  redo size
       516  bytes sent via SQL*Net to client
       469  bytes received via SQL*Net from client
         2  SQL*Net roundtrips to/from client
         0  sorts (memory)
         0  sorts (disk)
         1  rows processed

Please, before you go, don't forget to vote the poll regarding the content of this blog, thank you!

Your trash will drag you

If you think that Oracle recycle bin (feature available since 10g1) has no direct impact on your performance, you better think deep about it... seriously.

Try the following (if possible) : turn on statement timing, then issue a simple SELECT on DBA_FREE_SPACE and keep record of elapsed time; create a couple of hundreds of thousands tables in a 10g database, and then delete it (the DB recycle bin feature must be turned on) ... now you have a full-to-the-top recycle bin, then repeat the SELECT on DBA_FREE_SPACE, you'll see it will take a longer time to complete, and finally will get a huge number of rows. You may think that suddenly the free space has been multiplied... but your response time divided.

I don't know ... I'll let you think about this puzzling situation here and come back later to see how you doing.

Question: Can you figure out what is happening?

Subscribe to Oracle Database Disected by Email

2 minute guide for Statspack Installation

Ver este articulo en Español

Statspack is an Oracle database tool that is both powerful and underused, it's the first reporting resource you have (it's free, comes in the box) to see what is happening in your DB at a glance.

Ingredients
1 Oracle sql*plus session
1 Tablespace with at least 200Mb (9i) or 400Mb (10g) of free space*
1 user with DBA power

*Recommend you create a brand new tablespace

Preparation
You need to install Statspack previous to any use, then you have to run just one script... yes, it's that easy.
Login with your powerful user, then at the prompt type:

SQL> @?/rdbms/admin/spcreate

...you've started the Statspack setup, that will create the owner for the Statspack objects, which username is fixed to PERFSTAT. In order to acomplish that, asks for the tablespace where all objects will be stored, the temporary tablespace Statspack will use for sorting data and the user password.

You'll end with a message like this, and a result listing at the place you executed sqlplus.

It's recommended to establish a baseline for your reporting, then you must connect as PERFSTAT and take your first snapshot:

SQL> exec statspack.snap;

It will run with detail level 5, which is the default ... and enough for 90% of the cases. Taking samples 2 to 5 minutes apart is the period recommended, you may take samples with longer intervals but some results will get their formatting exceded and show # marks.

You may be interested on scheduling execution of statspack.snap, please read 2 minute guide for Statspack sampling

Further ... and detailed reading at the Oracle(R) Database Performance Tuning Guide.

Subscribe to Oracle Database Disected by Email

Your own DB 'Big Brother'

How many times you have been in the unfortunate situation where something catastrophic has happened, caused by an OSI 'Layer-8' error, you've been asked whom did that... and you don't have a clue.

Well, for those cases Oracle provides a very useful auditing feature, that is very simple to enable.

Usually you start enabling auditing on users that have the privilege to do the activity you are interested on, after you may enable auditing on users suspicious of trying to do something they don't have the privilege to.

Let's give a short example, given the case I want to track who drops or modifies any user.

SQL> alter system set audit_trail=DB scope=spfile;

or edit your pfile to reflect above setting
SQL> shutdown
SQL> startup
SQL> audit drop user by admin;


SQL> audit alter user by admin;

SQL> alter user scott identified by tigre;
User Altered
SQL> select count(*) sys.aud$;

How do you check what is fasible to audit or what is beeing audited, you must check these views:
* SYSTEM_PRIVILEGE_MAP
* DBA_PRIV_AUDIT_OPTS
* DBA_AUDIT_OBJECT

If those views aren't available then you must create them running the cataudit.sql script from $ORACLE_HOME/rdbms/admin.

Further explanation you may find in the Oracle Database Administration Guide.

Subscribe to Oracle Database Disected by Email

FOR UPDATE... or not FOR UPDATE, that is the question

Have you considered the impact of an unnecesary FOR UPDATE on your queries?

I had this database which suddenly rised the redo log generation rate, running on archive log mode (like every production database must be) it become a nightmare, trying to backup logs every hour or planning a huge space increase for the archive log destination filesystem.

Fortunately we keep track of every development that is promoted to production; our records showed that near the date a recent interface was released, the database increased the redo log activity. Then we proceeded to disect the suspicious code, realizing that the programmer coded 4 nested loops (on 4GL, given we have BaaN) and every loop was coded using, a presumably unnecesary SELECT...FOR UPDATE.

Those findings pointed the way of my research, since on a previous review of the process, every intermediate result table was turned to NOLOGGING, without any reduction on redo log creation, the only place where logging was taking place was the UNDO tablespace, a behavior that cannot be turned off. But I've to verify this theory... and find a solution to the puzzle.

I knew where to look for the information needed: the Oracle Data Dictionary views, then I opened the Oracle Database Reference for 10gR2, which is the 'fortunate' release of our test environment, given that our production is running 9R2, both under HP-Unix and showing exactly the same behavior.

These views helped to find useful information, and finally pinpoint the issue:
V$FILESTAT : if the UNDO tablespace was under heavy IO, it may be reflected here.
DBA_DATA_FILE : I needed to translate the file number to something meaningful.
V$UNDOSTAT : provided a 7 day meassure window that allowed to correlate heavy redo log generation with high UNDO activity.
V$EVENT_HISTOGRAM : histograms for every wait event.
V$SESSTAT : timed statistics by user session.
V$SYSSTAT : timed sytem statistics.
V$STATNAME : name of every statistic.

First I tried the following query and the resulting set confirmed the theory: at the very first place was located the datafiles for the UNDO tablespace.

 SELECT b.file_name, a.phywrts, a.phyblkwrt, a.writetim
FROM v$filestat a, dba_data_files b
WHERE a.file# = b.file_id
ORDER BY a.phyblkwrt DESC

Then I built this test case to confirm if there was a difference between SELECT and SELECT..FOR UPDATE shown at redo log write.

SQL> create table test ( col1 varchar2(10) );

Table created

SQL> select sid from v$mystat where rownum = 1;
1609

1 row returned
SQL> select name,a.value
2    from v$sesstat a, v$sysstat b
3    where b.statistic#=a.statistic#
4    and b.name = 'redo size' and sid = 1609;

redo size 13112
1 row selected

SQL> insert into test values ('World');

SQL> commit

SQL> select name,a.value
2    from v$sesstat a, v$sysstat b
3    where b.statistic#=a.statistic#
4    and b.name = 'redo size' and sid = 1609;

redo size 13504
1 row selected
SQL> select * from test;

SQL> select name,a.value
2    from v$sesstat a, v$sysstat b
3    where b.statistic#=a.statistic#
4    and b.name = 'redo size' and sid = 1609;

redo size 13504
1 row selected

SQL> select * from test for update;

redo size 14248
1 row selected

You may see that after issuing a simple SELECT there wasn't an effect in redo size, that effect was present modifying the query with the FOR UPDATE clause.

Explanation

Seems that SELECT...FOR UPDATE creates a copy of the information retrieved, which is stored at the UNDO tablespace. The undo tablespace logging behavior cannot be changed, therefore when the interface program was executed, there was m * n * p * q writes to the undo tablespace and therefore to the redo logs.

Results

After sending our recommendation to development to change their code and use simple SELECTs, the redo generation rate droped from 4 Gb to 500 Mb per hour, which is a considerable reduction.

Subscribe to Oracle Database Disected by Email

Poor's man Capacity Planning

Companies are struggling to follow the pace with IT governance standards; for instance, ITIL has released it's third delivery, doubling the number of 'books' documenting the guidelines.

On the other side, the IT operation is facing an explosive growth of business requirements and information flow that most of the time lends to insufficient resources, even if we planned ahead.

ITIL's Capacity planning intend to cover the broad range of IT operations, from document printing requests to server renovation or upgrade. I'll focus on ideas related to Database Capacity planning and related resources.

The Avalanche is here!
Yes, data growth is a headache and if you don't take actions in advance, you'll be buried by your data. Fortunately for us, this doesn't happen overnight and growth follows a pattern that will help you to forecast purchase of additional storage... or an eventual failure if nothing is done.

First you need to start collecting data for every one of your databases, consolidation of results may depend on your storage architecture, server assignation, business area or the grouping criteria of your choice.

This is very simple, you'll need to query the tablespace free and total space and store it in a table . If you have more than one database, its better to centralize information sending results to a repository. With oracle that is pretty straightforward: you'll need cron, sql*plus and sql*loader, just that.

The repository DB must be added to the local tnsnames.ora file, because sqlldr will access the repository using the username/password@database login form. You will need a table to store DB Name, Tablespace, Free Space, Used Space and the vital, Date of Sample.

You'll get the information from just three views of the Oracle Data Dictionary views: DBA_DATA_FILES, DBA_FREE_SPACE, V$PARAMETER. This is a sample of the query used.

SELECT p.value, 
       to_char(sysdate,'DD-MM-YYYY'),
       d.tablespace_name,
       NVL (a.BYTES / 1024 / 1024, 0),
       NVL (a.BYTES - NVL (f.BYTES, 0), 0) / 1024 / 1024)
FROM SYS.dba_tablespaces d,
     (SELECT tablespace_name, SUM (BYTES) BYTES
        FROM dba_data_files
    GROUP BY tablespace_name) a,
     (SELECT tablespace_name, SUM (BYTES) BYTES
        FROM dba_free_space
    GROUP BY tablespace_name) f,
     v$parameter p
WHERE d.tablespace_name = a.tablespace_name(+)
  AND d.tablespace_name = f.tablespace_name(+)
  AND NOT (d.extent_management LIKE 'LOCAL' AND d.CONTENTS LIKE 'TEMPORARY')
  AND p.name like '%instance%name%'

To be Continued... (growth patterns)

Subscribe to Oracle Database Disected by Email

OWI... wan-kenobi?

Sure you remember the Star Wars zaga ... and Obi-wan-kenobi as the first 'Force'-instructor of Luke. Well, my point here is how to use the Force with Oracle Server... with OWI or Oracle Wait Interface as its long name stands.

That is not an 'interface' in the way you pass values to the DB Kernel, instead you get information of waits generated in the system and wait events within the sessions... yes, prepare you laser-saber to fight all those annoying performance issues, your mind will broad his perception.

v$session_event (9i)
Lists all wait events for all sessions, with number of ocurrences and timing stats.

v$session_wait (9i)
Shows current wait event for sessions.

This is one of my favourite scripts that shows ans example of OWI usage. I've been using this script to analyze a performance issue with Peoplesoft: disk contention.

SELECT
a.sid,
a.osuser,
a.process,
substr(a.client_info,1,40) as "ClientInfo" ,
a.LOGON_TIME,
b."TimeWaited_Minutes",
((sysdate-LOGON_TIME)*24*60) as "Sess_TIME"
FROM v$session a,
(SELECT
sid,
total_waits,
TO_CHAR((time_waited/100)/60,'9,990.999') as "TimeWaited_Minutes"
FROM v$session_event c
WHERE c.EVENT = 'db file sequential read') b
WHERE username = '{PS owner username}'
AND status = 'ACTIVE'
AND a.SID = b.sid

v$event_histogram (10g)
Shows current instance histrograms for every wait event, organized on time interval buckets that progress following the formula 2^n milliseconds. For instance:

EVENT# EVENT         WAIT_TIME_MILLI WAIT_COUNT
11 Log archive I/O     1                29069
11 Log archive I/O     2                  115
11 Log archive I/O     4                  211
11 Log archive I/O     8                  391
11 Log archive I/O    16               140973
11 Log archive I/O    32               103846
11 Log archive I/O    64                21678
11 Log archive I/O   128                 4953
11 Log archive I/O   256                  822
11 Log archive I/O   512                   31

It's important to mention that the initizialization parameter TIMED_STATISTICS must be set to TRUE, and statistics are lost (or reset) when the database is shutdown or started up.

v$eventmetric (10g)
With this view you'll be able to see the last 60 seconds of wait event metrics, which gives a more recent time frame than v$event_histogram. This is a small sample of its content.

BEGIN_TIME   END_TIME  INTSIZE_CSEC EVENT# EVENT_ID NUM_SESS_WAITING TIME_WAITED WAIT_COUNT
29/02/2008 11:49:48 a.m. 29/02/2008 11:50:47 a.m. 5960 0 2516578839 0   0  0 
29/02/2008 11:49:48 a.m. 29/02/2008 11:50:47 a.m. 5960 1 3539483025 1   5564.8417 32 
29/02/2008 11:49:48 a.m. 29/02/2008 11:50:47 a.m. 5960 2 3934444552 0   0  0 
29/02/2008 11:49:48 a.m. 29/02/2008 11:50:47 a.m. 5960 3 866018717 10   50716.6575 9871 
29/02/2008 11:49:48 a.m. 29/02/2008 11:50:47 a.m. 5960 4 3083157888 0   0  0 
29/02/2008 11:49:48 a.m. 29/02/2008 11:50:47 a.m. 5960 5 2324796046 0   0  0 

You'll get a more meaningful output if you use (or modify) the following script:

SELECT
      b.NAME,
      to_char(a.BEGIN_TIME,'DD-MON-YYYY') as BeginDay,
      to_char(a.BEGIN_TIME,'HH24:MI:SS') as BeginTime,
      to_char(a.END_TIME, 'HH24:MI:SS' ) as EndTime,
      a.NUM_SESS_WAITING, a.TIME_WAITED, a.WAIT_COUNT
FROM  v$eventmetric a, v$event_name b
WHERE   a.EVENT_ID = b.EVENT_ID
ORDER BY time_waited DESC

Master these tables and you'll be invincible when fighting the Dark Side.

Subscribe to Oracle Database Disected by Email