Wednesday, April 24, 2013

SQL Developer Performance Issue

This happened when I was using SQL Developer in an Oracle 11.1.0.6 database. I clicked on the + sign next to Tables (Filtered) in the top left hand corner of the screen below (as usual, click on the image if necessary to enlarge it and bring it into focus):

 
The + turned to a – and Loading … appeared just below it:


After around 30 seconds, the table list appeared:

 
I repeated the process but this time, I traced the underlying session and ran the trace file through tkprof. This was the most expensive SQL in the .prf file. Incidentally, it had one of the biggest and most complicated explain plans I had ever seen (I won’t reproduce it here):

select * from (
  SELECT o.OBJECT_NAME, o.OBJECT_ID ,'' short_name, NULL partitioned,
                NULL iot_type,
         o.OWNER OBJECT_OWNER, o.CREATED, o.LAST_DDL_TIME, O.GENERATED, O.TEMPORARY, NULL EXTERNAL
    FROM SYS.ALL_OBJECTS O
    WHERE O.OWNER = :SCHEMA
    AND O.OBJECT_TYPE = 'TABLE'
union all
SELECT OBJECT_NAME, OBJECT_ID , syn.SYNONYM_NAME short_NAME, NULL partitioned,
                NULL iot_type,
       SYN.TABLE_OWNER OBJECT_OWNER, o.CREATED, o.LAST_DDL_TIME, O.GENERATED, O.TEMPORARY, NULL EXTERNAL
              FROM SYS.ALL_OBJECTS O, sys.user_synonyms syn
              WHERE  syn.table_owner = o.owner
              and    syn.TABLE_NAME = o.object_NAME
              and    o.object_type = 'TABLE'
              and    :INCLUDE_SYNS = 1
)
WHERE /**/OBJECT_NAME NOT IN (SELECT OBJECT_NAME FROM RECYCLEBIN)
                         AND not object_name like 'BIN$%'
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.09       0.11          0          0          0           0
Execute      1      0.83       0.81          0          0          0           0
Fetch        3     20.94      20.65          0    1017382          0         921
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        5     21.86      21.58          0    1017382          0         921
 
I looked elsewhere on the Internet and found somebody else who had experienced the same problem. He had substituted appropriate values for the bind variables and run the SQL with and without the subquery at the end. Removing it made the SQL run much faster so I decided that the problem might be connected with the recyclebin. I counted the number of objects in the SRCE user’s recyclebin and in dba_recyclebin then I purged the latter:
 
SQL> conn srce
Enter password:
Connected.
SQL> select count(*) from recyclebin;
 
  COUNT(*)
----------
        70
 
SQL> conn / as sysdba
Connected.
SQL> select count(*) from dba_recyclebin;
 
  COUNT(*)
----------
      3419
 
SQL> purge dba_recyclebin;
 
DBA Recyclebin purged.
 
SQL>
 
This made no difference. Then I rebuilt the 3 indexes on the recyclebin but this did not work either. Finally, I analyzed the recyclebin:
 
SQL> exec dbms_stats.gather_table_stats( -
> ownname=>'SYS',tabname=>'RECYCLEBIN$');
PL/SQL procedure successfully completed.
SQL>
 
After this, the table list appeared in a couple of seconds.

Saturday, April 20, 2013

LF_ROWS and DEL_LF_ROWS

This example was tested on Oracle 9.2.0.7. It shows how you can sometimes improve performance by rebuilding an index. I found a table:
 
SQL> desc braid.b_old_sp_profile_image
Name                       Null?    Type
-------------------------- -------- ------------------
SESSIONID                  NOT NULL NUMBER
SPLYPTID                   NOT NULL VARCHAR2(10)
START_DATE                 NOT NULL DATE
END_DATE                   NOT NULL DATE
BASELOAD_VOLUME            NOT NULL NUMBER(16,4)
PROFILE_VOLUME                      NUMBER(16,4)
 
SQL>
 
I counted its rows:
 
SQL> select count(*)
  2  from braid.b_old_sp_profile_image
  3  /
 
  COUNT(*)
----------
    610666
 
SQL>
 
I looked at the indexes on the table:
 
SQL> l
  1  select owner, index_name
  2  from dba_indexes
  3  where table_owner = 'BRAID'
  4* and table_name = 'B_OLD_SP_PROFILE_IMAGE'
SQL> /
 
OWNER                          INDEX_NAME
------------------------------ ------------------------------
BRAID                          OSPP_PK
 
SQL>
 
I checked which column(s) it indexed:
 
SQL> l
  1  select column_position, column_name
  2  from dba_ind_columns
  3  where table_owner = 'BRAID'
  4  and table_name = 'B_OLD_SP_PROFILE_IMAGE'
  5  and index_owner = 'BRAID'
  6  and index_name = 'OSPP_PK'
  7* order by 1
SQL> /
 
COLUMN_POSITION COLUMN_NAME
--------------- --------------------
              1 SESSIONID
              2 SPLYPTID
              3 START_DATE
 
SQL>
 
I ran a query and hoped it would use the index (it did):
 
SQL> alter session set sql_trace = true;
 
Session altered.
 
SQL> set timing on
SQL> select count(*) query1
  2  from braid.b_old_sp_profile_image
  3  where sessionid between 3000000 and 15000000
  4  /
 
    QUERY1
----------
    347244
 
Elapsed: 00:03:03.25
SQL> set timing off
SQL> alter session set sql_trace = false;
 
Session altered.
 
SQL>
 
It seemed slow so I checked the table had been analyzed recently:
 
SQL> l
  1  select last_analyzed
  2  from dba_tables
  3  where owner = 'BRAID'
  4* and table_name = 'B_OLD_SP_PROFILE_IMAGE'
SQL> /
 
LAST_ANALYZED
-------------
15-APR-13
 
SQL>
 
Then I ran the trace file through tkprof and looked at the output:
 
********************************************************************************
 
select count(*) query1
from braid.b_old_sp_profile_image
where sessionid between 3000000 and 15000000
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.02       0.02          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2     29.50     191.94     305413     305526          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     29.52     191.97     305413     305526          0           1
 
Misses in library cache during parse: 1
Optimizer goal: ALL_ROWS
Parsing user id: 236  (ORACLE)
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE
347244   INDEX FAST FULL SCAN OSPP_PK (object id 32074)
 
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: ALL_ROWS
      1   SORT (AGGREGATE)
347244    INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 'OSPP_PK' (UNIQUE)
 
********************************************************************************
 
I analyzed the index and saw that it had a high percentage of deleted leaf rows (as shown in the del_lf_rows column):
 
SQL> analyze index braid.ospp_pk validate structure;
 
Index analyzed.
 
SQL> l
  1  select name, lf_rows, del_lf_rows, height
  2* from index_stats
SQL> /
 
NAME                    LF_ROWS DEL_LF_ROWS     HEIGHT
-------------------- ---------- ----------- ----------
OSPP_PK                24121377    23510711          4
 
SQL>
 
… so I rebuilt it, checked that the deleted leaf rows had disappeared then analyzed the table again:
 
SQL> alter index braid.ospp_pk rebuild;
 
Index altered.
 
SQL> analyze index braid.ospp_pk validate structure;
 
Index analyzed.
 
SQL> select name, lf_rows, del_lf_rows, height
  2  from index_stats
  3  /
 
NAME                    LF_ROWS DEL_LF_ROWS     HEIGHT
-------------------- ---------- ----------- ----------
OSPP_PK                  610666           0          3
 
SQL> exec dbms_stats.gather_table_stats( -
> ownname => 'braid', -
> tabname => 'b_old_sp_profile_image');
 
PL/SQL procedure successfully completed.
 
SQL>
 
I reran the query and it finished very quickly:
 
SQL> alter session set sql_trace = true;
 
Session altered.
 
SQL> set timing on
SQL> select count(*) query2
  2  from braid.b_old_sp_profile_image
  3  where sessionid between 3000000 and 15000000
  4  /
 
    QUERY2
----------
    347244
 
Elapsed: 00:00:00.71
SQL> set timing off
SQL> alter session set sql_trace = false;
 
Session altered.
 
SQL>
 
I ran the trace file through tkprof and looked at the output, which was also very different:
 
********************************************************************************
 
select count(*) query2
from braid.b_old_sp_profile_image
where sessionid between 3000000 and 15000000
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.02       0.03          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.57       0.60          0       3010          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.60       0.64          0       3010          0           1
 
Misses in library cache during parse: 1
Optimizer goal: ALL_ROWS
Parsing user id: 236  (ORACLE)
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE
347244   INDEX FAST FULL SCAN OSPP_PK (object id 32074)
 
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: ALL_ROWS
      1   SORT (AGGREGATE)
347244    INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 'OSPP_PK' (UNIQUE)
 
********************************************************************************
 
Some people say that you should rebuild indexes when the percentage of deleted leaf rows is 20% or more. Personally I believe that there is a risk, albeit small, in any maintenance so you should only do it, as in this case, where you can demonstrate that you will achieve some measurable performance improvement.

Thursday, April 18, 2013

What Can You Do With GRANT ALL ON?

I saw somebody using the GRANT ALL ON command recently and decided to see what I could do with it in an Oracle 11.2.0.2.7 database. First I logged in as OPS$ORACLE:
 
SQL> conn /
Connected.
SQL> show user
USER is "OPS$ORACLE"
SQL>
 
Then I created a test table called CLAIMS:
 
SQL> create table claims (col1 number)
  2  /
 
Table created.
 
SQL>
 
… and did GRANT ALL ON it to another user:
 
SQL> grant all on claims to judy
  2  /
 
Grant succeeded.
 
SQL>
 
I logged in as the other user and found that she could run DML on the table:
 
SQL> conn judy/garland
Connected.
SQL> insert into ops$oracle.claims values (1)
  2  /
 
1 row created.
 
SQL> update ops$oracle.claims set col1 = 2
  2  /
 
1 row updated.
 
SQL> select * from ops$oracle.claims
  2  /
 
      COL1
----------
         2
 
SQL> delete ops$oracle.claims
  2  /
 
1 row deleted.
 
SQL>
 
She could also modify its structure:
 
SQL> alter table ops$oracle.claims
  2  add (col2 varchar2(1))
  3  /
 
Table altered.
 
SQL> desc ops$oracle.claims
Name                       Null?    Type
-------------------------- -------- ------------------
COL1                                NUMBER
COL2                                VARCHAR2(1)
 
SQL>
 
… but she could not DROP the table:
 
SQL> drop table ops$oracle.claims
  2  /
drop table ops$oracle.claims
                      *
ERROR at line 1:
ORA-01031: insufficient privileges
 
SQL>
 
So I was a little surprised to see that, according to Donald Burleson, the GRANT ALL ON command does allow a user to DROP a table (as usual, click on the image to enlarge it and bring it into focus):


I have written to them to ask for clarification . As soon as I hear back I will update this post accordingly.

Wednesday, April 10, 2013

ORA-01555 (SET TRANSACTION READ ONLY - Part 6)

In What it Does (SET TRANSACTION READ ONLY – Part 4), I explained that if you are in a read only transaction, select statements return data as it was when you ran the set transaction read only statement. Oracle uses before images in the undo tablespace to do this. These before images are created at the start of a transaction and kept until the next commit or rollback statement finishes that transaction. After that they risk being overwritten the next time Oracle needs some space in the undo tablespace. Oracle has no way of knowing which before images might be needed later on by select statements in a read only transaction. If a subsequent select statement in a read only transaction is unable to find a before image it needs, it fails with an ORA-01555. I proved this as follows in an Oracle 11.2.0.2.7 database. First I created an undo tablespace with a small datafile (this is not shown). Then in the red session which follows, I created a table:
 
SQL> create table tab1
  2  as select * from dba_objects
  3  /
 
Table created.
 
SQL>
 
Then in a new session in blue, I started a read only transaction and counted the number of rows in the table owned by OUTLN:  
 
SQL> set transaction read only
  2  /
 
Transaction set.
 
SQL> select count(*) from tab1
  2  where owner = 'OUTLN'
  3  /
 
  COUNT(*)
----------
         9
 
SQL>
 
I returned to the red session and tried to remove all the rows in the table owned by PUBLIC or SYS. There was not enough room in the undo tablespace for the before images of all these rows so this transaction failed with an ORA-30036. I then removed the rows successfully in two separate transactions. The before images created by the second transaction must have overwritten some of the before images of the first:  
 
SQL> delete tab1
  2  where owner in ('PUBLIC', 'SYS')
  3  /
delete tab1
       *
ERROR at line 1:
ORA-30036: unable to extend segment by 8 in undo
tablespace 'UNDOTBS2'
 
SQL> rollback
  2  /
 
Rollback complete.
 
SQL> delete tab1
  2  where owner = 'PUBLIC'
  3  /
 
27814 rows deleted.
 
SQL> commit
  2  /
 
Commit complete.
 
SQL> delete tab1
  2  where owner = 'SYS'
  3  /
 
31408 rows deleted.
 
SQL> commit
  2  /
 
Commit complete.
 
SQL>
 
Finally I returned to the blue session. I tried to recount the number of rows owned by OUTLN at the start of the read only transaction. This failed with an ORA-01555 as some of the before images required to work this out had been overwritten. To prove that the failure was caused by being in a read only transaction, I used a commit to end it. Then I was able to query the table successfully:
 
SQL> select count(*) from tab1
  2  where owner = 'OUTLN'
  3  /
select count(*) from tab1
                     *
ERROR at line 1:
ORA-01555: snapshot too old: rollback segment number
13 with name "_SYSSMU13_3270171812$" too small
 
SQL> commit
  2  /
 
Commit complete.
 
SQL> select count(*) from tab1
  2  where owner = 'OUTLN'
  3  /
 
  COUNT(*)
----------
         9
 
SQL>