Monthly Archives: August 2012

Got Selected to Speak at DOAG 2012

I got selected to speak at DOAG 2012. Unfortunately I will not be able to make two international trips in one single month.  I feel very sad in declining this opportunity. Hopefully I will get another opportunity next year or so

Tracing specific SQL’s (Tracing Series-2)

Until 11g ,tracing was synonymous  with sessions.  You could not trace anything other than sessions (Don’t take this literally)

With 11g  you have the option of  tracing individual  SQL’s by means a event/trigger.   This is very useful  if  you are executing a long running process  and interested in tracing only a  particular SQL.  You can trace the SQL either at session level or system level.

Syntax

  • alter system set events ‘sql_trace [sql:sql_id] level 12’
  • alter session set events ‘sql_trace [sql:sql_id] level 12’

Note:  The SQL trace command can be executed  for  more than 1 SQL_ID too by separating the  sql_id’s with pipe symbol

alter system set events ‘sql_trace [sql:sql_id|sql_id] level 12′;

 

=-

Steps to Trace the SQL

Step-1: Execute the following Query  to get the SQL_ID. 

.

SQL>select object_name from dba_objects where object_name=’DBA_TABLES’;

Step-2: Find the SQL_ID from v$sql

..
 SQL> column sql_text format a80
 SQL> set lines 120 pages 2000
 SQL> set long 3000
 SQL>
 SQL> select sql_id , sql_text from v$sql where sql_text like 
'%select object_name from dba_objects where object_name=%';
SQL_ID SQL_TEXT
 ------------- --------------------------------------------------------------------------------
 gynhgrz60jayw    select object_name from dba_objects where object_name='DBA_TABLES'
3n6v2xv2s5wm4     select sql_id , sql_text from v$sql where sql_text like '%select object_name fro
                  m dba_objects  where object_name=%'
--

.

Step-3: Enable the trace for the SQL_ID

.

SQL> alter system set events ‘sql_trace [sql:gynhgrz60jayw] level 12’;

System altered

.

Step-4: Execute the SQL statement to generate trace

.

SQL> select object_name from dba_objects where object_name=’DBA_TABLES’;

OBJECT_NAME
————————————————————————————————————————
DBA_TABLES
DBA_TABLES

Step-5: Analyze the trace file. This is the fun part. Identifying problem SQL is often easy but fixing it …

Trace file /app/oracle/diag/rdbms/mydb/mydn/trace/mydb_ora_36897294.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 – 64bit Production
With the Partitioning option
ORACLE_HOME = /app/oracle/product/11.2.0.2/db
System name: AIX
Node name: mydb1
Release: 1
Version: 6
Machine: 00CF7$B54C00
Instance name: mydb
Redo thread mounted by this instance: 1
Oracle process number: 28
Unix process pid: 36897294, image: oracle@mydb1 (TNS V1-V3)
*** 2012-08-07 16:55:40.894
*** SESSION ID:(1012.117) 2012-08-07 16:55:40.894
*** CLIENT ID:() 2012-08-07 16:55:40.894
*** SERVICE NAME:(SYS$USERS) 2012-08-07 16:55:40.894
*** MODULE NAME:(SQL*Plus) 2012-08-07 16:55:40.894
*** ACTION NAME:() 2012-08-07 16:55:40.894

=====================
PARSING IN CURSOR #4575285296 len=37 dep=1 uid=0 oct=3 lid=0 tim=49002870757326

hv=1398610540 ad=’700000127d65258′ sqlid=’grwydz59pu6mc’
select text from view$ where rowid=:1
END OF STMT
PARSE #4575285296:c=0,e=683,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=49002870757324
BINDS #4575285296:
Bind#0
oacdty=11 mxl=16(16) mxlc=00 mal=00 scl=00 pre=00
oacflg=18 fl2=0001 frm=00 csi=00 siz=16 off=0
kxsbbbfp=110b54bf0 bln=16 avl=16 flg=05
value=000004D6.0000.0001
EXEC #4575285296:c=0,e=1314,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=1028580536,tim=49002870772280
FETCH #4575285296:c=0,e=89,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,plh=1028580536,tim=49002870772402
STAT #4575285296 id=1 cnt=1 pid=0 pos=1 obj=59 op=’TABLE ACCESS BY USER ROWID VIEW$ (cr=2 pr=0 pw=0 time=69 us cost=1 size=15 card=1)’
CLOSE #4575285296:c=0,e=52,dep=1,type=0,tim=49002870772481
=====================
PARSING IN CURSOR #4575285296 len=37 dep=1 uid=0 oct=3 lid=0 tim=49002870773099 hv=1398610540 ad=’700000127d65258′ sqlid=’grwydz59pu6mc’
select text from view$ where rowid=:1
END OF STMT
PARSE #4575285296:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=1028580536,tim=49002870773098
BINDS #4575285296:
Bind#0
oacdty=11 mxl=16(16) mxlc=00 mal=00 scl=00 pre=00
oacflg=18 fl2=0001 frm=00 csi=00 siz=16 off=0
kxsbbbfp=110b54bf0 bln=16 avl=16 flg=05
value=0000C0C4.0000.0001
EXEC #4575285296:c=0,e=77,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=1028580536,tim=49002870773248
FETCH #4575285296:c=0,e=15,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,plh=1028580536,tim=49002870773283
STAT #4575285296 id=1 cnt=1 pid=0 pos=1 obj=59 op=’TABLE ACCESS BY USER ROWID VIEW$ (cr=1 pr=0 pw=0 time=8 us cost=1 size=15 card=1)’
CLOSE #4575285296:c=0,e=29,dep=1,type=0,tim=49002870773333
=====================
PARSING IN CURSOR #4575286160 len=66 dep=0 uid=21 oct=3 lid=21 tim=49002870784095 hv=3423120348 ad=’7000001208cd1f8′ sqlid=’gynhgrz60jayw’
select object_name from dba_objects where object_name=’DBA_TABLES’
END OF STMT
EXEC #4575286160:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,plh=2998908629,tim=49002870784093
WAIT #4575286160: nam=’SQL*Net message to client’ ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=49002870784259
FETCH #4575286160:c=0,e=336,p=0,cr=17,cu=0,mis=0,r=1,dep=0,og=2,plh=2998908629,tim=49002870784629
WAIT #4575286160: nam=’SQL*Net message from client’ ela= 280 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=49002870784977
WAIT #4575286160: nam=’SQL*Net message to client’ ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=49002870785044
FETCH #4575286160:c=0,e=2993,p=0,cr=304,cu=0,mis=0,r=1,dep=0,og=2,plh=2998908629,tim=49002870787996
STAT #4575286160 id=1 cnt=2 pid=0 pos=1 obj=1195 op=’VIEW DBA_OBJECTS (cr=321 pr=0 pw=0 time=332 us cost=79 size=132 card=2)’
STAT #4575286160 id=2 cnt=2 pid=1 pos=1 obj=0 op=’UNION-ALL (cr=321 pr=0 pw=0 time=328 us)’
STAT #4575286160 id=3 cnt=2 pid=2 pos=1 obj=0 op=’FILTER (cr=317 pr=0 pw=0 time=321 us)’
STAT #4575286160 id=4 cnt=2 pid=3 pos=1 obj=0 op=’NESTED LOOPS (cr=317 pr=0 pw=0 time=315 us cost=78 size=65 card=1)’
STAT #4575286160 id=5 cnt=2 pid=4 pos=1 obj=0 op=’NESTED LOOPS (cr=314 pr=0 pw=0 time=323 us cost=77 size=61 card=1)’
STAT #4575286160 id=6 cnt=2 pid=5 pos=1 obj=507636 op=’TABLE ACCESS FULL OBJ$ (cr=311 pr=0 pw=0 time=263 us cost=76 size=39 card=1)’
STAT #4575286160 id=7 cnt=2 pid=5 pos=2 obj=507644 op=’INDEX RANGE SCAN I_USER2 (cr=3 pr=0 pw=0 time=57 us cost=1 size=22 card=1)’
STAT #4575286160 id=8 cnt=2 pid=4 pos=2 obj=507644 op=’INDEX RANGE SCAN I_USER2 (cr=3 pr=0 pw=0 time=10 us cost=1 size=4 card=1)’
STAT #4575286160 id=9 cnt=0 pid=3 pos=2 obj=19 op=’TABLE ACCESS BY INDEX ROWID IND$ (cr=0 pr=0 pw=0 time=0 us cost=2 size=8 card=1)’
STAT #4575286160 id=10 cnt=0 pid=9 pos=1 obj=36 op=’INDEX UNIQUE SCAN I_IND1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=0 card=1)’
STAT #4575286160 id=11 cnt=0 pid=3 pos=3 obj=0 op=’NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=30 card=1)’
STAT #4575286160 id=12 cnt=0 pid=11 pos=1 obj=507644 op=’INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)’
STAT #4575286160 id=13 cnt=0 pid=11 pos=2 obj=507640 op=’INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=10 card=1)’
STAT #4575286160 id=14 cnt=0 pid=2 pos=2 obj=0 op=’NESTED LOOPS (cr=4 pr=0 pw=0 time=199 us cost=1 size=29 card=1)’
STAT #4575286160 id=15 cnt=89 pid=14 pos=1 obj=507644 op=’INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=98 us cost=1 size=352 card=88)’
STAT #4575286160 id=16 cnt=0 pid=14 pos=2 obj=105 op=’INDEX RANGE SCAN I_LINK1 (cr=3 pr=0 pw=0 time=133 us cost=0 size=25 card=1)’

*** 2012-08-07 16:55:44.200
CLOSE #4575286160:c=0,e=38,dep=0,type=0,tim=49002874076143

Like Operator and Indexes

Trying to  predict Oracle’s behavior with respect to using indexes with LIKE operator is not simple.  However you may be able to get close enough with the following algorithm.  Let me  list  the number of ways you can use the single  LIKE operator along with the algorithm.

  1. Beginning of search expression (%ABC) :  Less likely to use an Index (Most likely to perform full table scan)
  2. End of search expression (ABC%): More likely to use an Index
  3. In  between search expression (A%BC) : More likely to used an Index

However one key thing I want to mention is that if possible avoid using LIKE operator even if index is used and look for ways to use replace LIKE with  SUBSTR/INSTR/ASCII and so on.  This is to reduce the number of consistent gets even if index is being used.

See example below  for all the 3 case scenarios. In the 1st few commands, we are creating tables , indexes and gathering stats.

 

SQL> CREATE TABLE MY_DBAOBJECTS AS SELECT * FROM DBA_OBJECTS UNION ALL 
 2 SELECT * FROM DBA_OBJECTS UNION ALL SELECT * FROM DBA_OBJECTS;
-
TABLE CREATED.
SQL> 
SQL> CREATE INDEX IDX_OBJ_NAME ON MY_DBAOBJECTS (OBJECT_NAME);
-
INDEX CREATED.

SQL> EXECUTE DBMS_STATS.GATHER_INDEX_STATS(OWNNAME=>'DATA_MASTER', INDNAME=>'IDX_OBJ_NAME');
-
PL/SQL PROCEDURE SUCCESSFULLY COMPLETED.
-
SQL> SET AUTOTRACE TRACEONLY EXPLAIN

-
Case:1
#####################################################################################
Beginning of search expression (%ABC): Less likely to use Index
#####################################################################################

SQL> SELECT OBJECT_ID FROM MY_DBAOBJECTS WHERE OBJECT_NAME LIKE '%DBA';
-
EXECUTION PLAN
------------------------------------------------------------------------
| ID | OPERATION | NAME | ROWS | BYTES | COST (%CPU)|
------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 11 | 869 | 276 (1)|
|* 1 | TABLE ACCESS FULL| MY_DBAOBJECTS | 11 | 869 | 276 (1)|
------------------------------------------------------------------------
PREDICATE INFORMATION (IDENTIFIED BY OPERATION ID):
---------------------------------------------------
1 - FILTER("OBJECT_NAME" IS NOT NULL AND "OBJECT_NAME" LIKE '%DBA')
NOTE
-----
 - 'PLAN_TABLE' IS OLD VERSION

-
Case-2
#####################################################################################
End of search expression (ABC%): More likely to use an Index
#####################################################################################

SQL> SELECT OBJECT_ID FROM MY_DBAOBJECTS WHERE OBJECT_NAME LIKE 'DBA%';
-
EXECUTION PLAN
----------------------------------------------------------------------------------
| ID | OPERATION | NAME | ROWS | BYTES | COST (%CPU)|
----------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 6176 | 476K| 10 (0)|
| 1 | TABLE ACCESS BY INDEX ROWID| MY_DBAOBJECTS | 6176 | 476K| 10 (0)|
|* 2 | INDEX RANGE SCAN | IDX_OBJ_NAME | | | 2 (0)|
----------------------------------------------------------------------------------
PREDICATE INFORMATION (IDENTIFIED BY OPERATION ID):
---------------------------------------------------
2 - ACCESS("OBJECT_NAME" LIKE 'DBA%')
 FILTER("OBJECT_NAME" LIKE 'DBA%')
NOTE
-----
 - 'PLAN_TABLE' IS OLD VERSION

--
Case-3
#####################################################################################
In between search expression (A%BC) : More likely to used an Index
#####################################################################################

SQL> SELECT OBJECT_ID FROM MY_DBAOBJECTS WHERE OBJECT_NAME LIKE 'DBA%T';
-
EXECUTION PLAN
----------------------------------------------------------------------------------
| ID | OPERATION | NAME | ROWS | BYTES | COST (%CPU)|
----------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 228 | 18012 | 10 (0)|
| 1 | TABLE ACCESS BY INDEX ROWID| MY_DBAOBJECTS | 228 | 18012 | 10 (0)|
|* 2 | INDEX RANGE SCAN | IDX_OBJ_NAME | 228 | | 2 (0)|
----------------------------------------------------------------------------------
PREDICATE INFORMATION (IDENTIFIED BY OPERATION ID):
---------------------------------------------------
2 - ACCESS("OBJECT_NAME" LIKE 'DBA%T')
 FILTER("OBJECT_NAME" LIKE 'DBA%T')
NOTE
-----
 - 'PLAN_TABLE' IS OLD VERSION
SQL>

I am Speaking at InSync12 (Melbourne)

 

I will be presenting once again at this year InSync conference at  Melbourne (Aug 21/22),  Australia.  My session is about Oracle GoldenGate Best Practices and performance optimization techniques.  Last years conference was in Sydney convention center and had impressive list of speakers including Tom Kyte, Richard Foote, Andrew Holdsworth & Graham Wood.  
..
..
About InSync12
..
The InSync12 Conference and Exhibitor Showcase is a joint event of the Quest ANZ user group – representing JDE and PeopleSoft customers, and the Australian Oracle User Group (AUSOUG) representing the Technology, Development and Applications users.  This is the fourth time the independent user groups in Australia will come together for one national conference.  See link for more details http://www.insync12.com.au/