Testing user calls

In the performance tuning world specially talking about Response Time Analysis (RTA), user calls is often used as a workload metric; however this instance statistic was not yet completely clear.

When this metric is incremented?, How this metric is instrumented?, Why sometimes user calls is less with the same SQL statement?; these were some questions rounding my mind.

My friend Craig Shallahamer did a great post in his blog “A Wider View” related to user calls (http://shallahamer-orapub.blogspot.mx/2010/05/understanding-user-calls.html), however looking into Tanel Poder’s blog today everything got clear.

Let’s start tracing an Oracle session using trace events ‘10046’ & ‘10051’. 

Event ‘10051’ will trace OPI calls, more information (http://blog.tanelpoder.com/2011/03/20/lobread-sql-trace-entry-in-oracle-11-2/), what are OPI calls?, well as per Oracle documentation:

Oracle Program Interface (OPI)

A networking layer responsible for responding to each of the possible messages sent by OCI. For example, an OCI request to fetch 25 rows would have an OPI response to return the 25 rows once they have been fetched.


Let’s do it!

SQL> ALTER SESSION SET EVENTS ‘10046 TRACE NAME CONTEXT FOREVER, LEVEL 12’;
ALTER SESSION SET EVENTS ‘10051 TRACE NAME CONTEXT FOREVER, LEVEL 12’;
Session altered.
SQL>
Session altered.
SQL> SELECT TRACEFILE FROM V$PROCESS WHERE ADDR =(SELECT PADDR FROM V$SESSION WHERE SID=49);
TRACEFILE
——————————————————————————–
/u01/app/oracle/diag/rdbms/rac/RAC1/trace/RAC1_ora_5393.trc

In another window open the trace file using tail –f in order to monitor the trace execution. Now let’s issue a small query:

SQL> select * from dual;
D
–
X
SQL>
Here’s the output of the trace file:

*** 2013-08-05 21:42:15.721
WAIT #3: nam=’SQL*Net message from client’ ela= 342028978 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1375756935721909
OPI CALL: type=105 argc= 2 cursor=  0 name=Cursor close all
CLOSE #3:c=0,e=18,dep=0,type=0,tim=1375756935722017
OPI CALL: type=94 argc=28 cursor=  0 name=V8 Bundled Exec
WAIT #1: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375756935722368
WAIT #1: nam=’ges message buffer allocation’ ela= 0 pool=0 request=1 allocated=0 obj#=-1 tim=1375756935722448
WAIT #1: nam=’library cache lock’ ela= 568 handle address=1287268616 lock address=1263092292 100*mode+namespace=65538 obj#=-1 tim=1375756935723089
WAIT #1: nam=’ges message buffer allocation’ ela= 1 pool=0 request=1 allocated=0 obj#=-1 tim=1375756935723137
WAIT #1: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375756935723205
WAIT #1: nam=’library cache pin’ ela= 473 handle address=1287268616 pin address=1263092428 100*mode+namespace=65538 obj#=-1 tim=1375756935723815
=====================
PARSING IN CURSOR #4 len=210 dep=1 uid=0 oct=3 lid=0 tim=1375756935724353 hv=864012087 ad=’4cb562e8′ sqlid=’96g93hntrzjtr’
select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2
END OF STMT
PARSE #4:c=0,e=70,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=2239883476,tim=1375756935724351
BINDS #4:
 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=0040a79c  bln=22  avl=03  flg=05
  value=116
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=0040a778  bln=24  avl=02  flg=05
  value=1
EXEC #4:c=0,e=89,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=2239883476,tim=1375756935724524
FETCH #4:c=0,e=51,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=3,plh=2239883476,tim=1375756935724594
STAT #4 id=1 cnt=1 pid=0 pos=1 obj=424 op=’TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=3 pr=0 pw=0 time=0 us)’
STAT #4 id=2 cnt=1 pid=1 pos=1 obj=426 op=’INDEX RANGE SCAN I_HH_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=0 us)’
CLOSE #4:c=0,e=40,dep=1,type=3,tim=1375756935724660
=====================
PARSING IN CURSOR #1 len=18 dep=0 uid=0 oct=3 lid=0 tim=1375756935725402 hv=942515969 ad=’4b5c8e54′ sqlid=’a5ks9fhw2v9s1′
select * from dual
END OF STMT
PARSE #1:c=3999,e=3334,p=0,cr=3,cu=0,mis=1,r=0,dep=0,og=1,plh=272002086,tim=1375756935725401
EXEC #1:c=0,e=13,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=272002086,tim=1375756935725457
WAIT #1: nam=’SQL*Net message to client’ ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1375756935725480
WAIT #1: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375756935725627
WAIT #1: nam=’gc cr grant 2-way’ ela= 1035 p1=1 p2=928 p3=4 obj#=116 tim=1375756935726935
WAIT #1: nam=’db file sequential read’ ela= 634 file#=1 block#=928 blocks=1 obj#=116 tim=1375756935737381
WAIT #1: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=116 tim=1375756935741146
WAIT #1: nam=’gc cr grant 2-way’ ela= 470 p1=1 p2=929 p3=1 obj#=116 tim=1375756935741693
WAIT #1: nam=’db file sequential read’ ela= 1312 file#=1 block#=929 blocks=1 obj#=116 tim=1375756935743074
FETCH #1:c=1999,e=17670,p=2,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=272002086,tim=1375756935743169
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=116 op=’TABLE ACCESS FULL DUAL (cr=3 pr=2 pw=0 time=0 us cost=2 size=2 card=1)’
WAIT #1: nam=’SQL*Net message from client’ ela= 221 driver id=1650815232 #bytes=1 p3=0 obj#=116 tim=1375756935743513
OPI CALL: type= 5 argc= 2 cursor=  1 name=FETCH
FETCH #1:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=272002086,tim=1375756935743579
WAIT #1: nam=’SQL*Net message to client’ ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=116 tim=1375756935743629
Snapper shows the below metrics for our session:

SQL> @snapper4 all 5 1 49
Sampling SID 49 with interval 5 seconds, taking 1 snapshots…
— Session Snapper v4.09 BETA – by Tanel Poder ( http://blog.tanelpoder.com ) – Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! 🙂
——————————————————————————————————————————————————————————————————————
 SID @INST, USERNAME  , TYPE, STATISTIC                                                 ,         DELTA, HDELTA/SEC,    %TIME, GRAPH       , NUM_WAITS,  WAITS/SEC,   AVERAGES
——————————————————————————————–
    49  @1, SYS       , STAT, opened cursors cumulative,             1,         .2,         ,             ,          ,           ,          1 per execution
    49  @1, SYS       , STAT, user calls,             3,        .59,         ,             ,          ,           ,          3 per execution
Now let’s create a dummy table and insert some rows:
SQL> insert into test_user (user_name) select username from dba_users;
36 rows created.

From trace file:
*** 2013-08-05 21:55:34.386
WAIT #1: nam=’SQL*Net message from client’ ela= 58636486 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1375757734386174
OPI CALL: type=105 argc= 2 cursor=  0 name=Cursor close all
CLOSE #1:c=0,e=15,dep=0,type=0,tim=1375757734386272
OPI CALL: type=94 argc=28 cursor=  0 name=V8 Bundled Exec
=====================
PARSING IN CURSOR #3 len=37 dep=1 uid=0 oct=3 lid=0 tim=1375757734387095 hv=1398610540 ad=’4cbf4cb0′ sqlid=’grwydz59pu6mc’
select text from view$ where rowid=:1
END OF STMT
PARSE #3:c=0,e=375,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1375757734387093
BINDS #3:
 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=1184df90  bln=16  avl=16  flg=05
  value=00002068.0000.0001
EXEC #3:c=2000,e=54991,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=3684871272,tim=1375757734442193
FETCH #3:c=0,e=34,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,plh=3684871272,tim=1375757734442283
STAT #3 id=1 cnt=1 pid=0 pos=1 obj=69 op=’TABLE ACCESS BY USER ROWID VIEW$ (cr=1 pr=0 pw=0 time=0 us cost=1 size=15 card=1)’
CLOSE #3:c=0,e=51,dep=1,type=0,tim=1375757734442357
WAIT #2: nam=’ges message buffer allocation’ ela= 4 pool=0 request=1 allocated=0 obj#=-1 tim=1375757734443204
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375757734443382
WAIT #2: nam=’library cache lock’ ela= 549 handle address=1222331724 lock address=1220909652 100*mode+namespace=65538 obj#=-1 tim=1375757734444345
WAIT #2: nam=’KJC: Wait for msg sends to complete’ ela= 10 msg=1361877012 dest|rcvr=65536 mtype=12 obj#=-1 tim=1375757734444389
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375757734444433
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375757734444564
WAIT #2: nam=’library cache pin’ ela= 640 handle address=1222331724 pin address=1220909516 100*mode+namespace=65538 obj#=-1 tim=1375757734445329
WAIT #2: nam=’KJC: Wait for msg sends to complete’ ela= 9 msg=1361877012 dest|rcvr=65536 mtype=12 obj#=-1 tim=1375757734445367
=====================
PARSING IN CURSOR #6 len=210 dep=1 uid=0 oct=3 lid=0 tim=1375757734475342 hv=864012087 ad=’4cb562e8′ sqlid=’96g93hntrzjtr’
select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2
END OF STMT
PARSE #6:c=0,e=73,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=2239883476,tim=1375757734475341
BINDS #6:
 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=0040210c  bln=22  avl=04  flg=05
  value=74760
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=004020e8  bln=24  avl=02  flg=05
  value=1
EXEC #6:c=0,e=91,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=2239883476,tim=1375757734475532
FETCH #6:c=0,e=15,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=3,plh=2239883476,tim=1375757734475567
STAT #6 id=1 cnt=0 pid=0 pos=1 obj=424 op=’TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=2 pr=0 pw=0 time=0 us)’
STAT #6 id=2 cnt=0 pid=1 pos=1 obj=426 op=’INDEX RANGE SCAN I_HH_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=0 us)’
CLOSE #6:c=0,e=1,dep=1,type=3,tim=1375757734475616
=====================
PARSING IN CURSOR #2 len=64 dep=0 uid=0 oct=2 lid=0 tim=1375757734477276 hv=1206268670 ad=’48d0a418′ sqlid=’4x5wmqj3yccry’
insert into test_user (user_name) select username from dba_users
END OF STMT
PARSE #2:c=10999,e=90955,p=0,cr=4,cu=0,mis=1,r=0,dep=0,og=1,plh=3422547789,tim=1375757734477275
WAIT #2: nam=’ges message buffer allocation’ ela= 5 pool=0 request=1 allocated=0 obj#=74760 tim=1375757734478040
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=74760 tim=1375757734478200
WAIT #2: nam=’enq: TM – contention’ ela= 616 name|mode=1414332419 object #=74760 table/partition=0 obj#=74760 tim=1375757734478936
WAIT #2: nam=’asynch descriptor resize’ ela= 4 outstanding #aio=0 current aio limit=384 new aio limit=390 obj#=-1 tim=1375757734486405
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=-1 tim=1375757734486564
WAIT #2: nam=’gc cr grant 2-way’ ela= 519 p1=1 p2=1976 p3=4 obj#=281 tim=1375757734487242
WAIT #2: nam=’db file sequential read’ ela= 788 file#=1 block#=1976 blocks=1 obj#=281 tim=1375757734488113
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=281 tim=1375757734488224
WAIT #2: nam=’gc cr grant 2-way’ ela= 431 p1=1 p2=1977 p3=1 obj#=281 tim=1375757734488790
WAIT #2: nam=’db file sequential read’ ela= 889 file#=1 block#=1977 blocks=1 obj#=281 tim=1375757734489741
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=281 tim=1375757734491203
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=281 tim=1375757734491352
WAIT #2: nam=’enq: HW – contention’ ela= 1020 name|mode=1213661190 table space #=0 block=4282248 obj#=281 tim=1375757734492503
WAIT #2: nam=’ges message buffer allocation’ ela= 2 pool=0 request=1 allocated=0 obj#=281 tim=1375757734492596
WAIT #2: nam=’gc current grant 2-way’ ela= 422 p1=1 p2=87945 p3=33554433 obj#=74760 tim=1375757734493138
EXEC #2:c=5000,e=15461,p=2,cr=41,cu=7,mis=0,r=36,dep=0,og=1,plh=3422547789,tim=1375757734493365
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=0 op=’LOAD TABLE CONVENTIONAL  (cr=41 pr=2 pw=0 time=0 us)’
STAT #2 id=2 cnt=36 pid=1 pos=1 obj=0 op=’HASH JOIN  (cr=40 pr=2 pw=0 time=35 us cost=24 size=1092 card=13)’
STAT #2 id=3 cnt=36 pid=2 pos=1 obj=0 op=’HASH JOIN  (cr=37 pr=2 pw=0 time=35 us cost=22 size=1053 card=13)’
STAT #2 id=4 cnt=36 pid=3 pos=1 obj=0 op=’HASH JOIN  (cr=28 pr=2 pw=0 time=35 us cost=17 size=1014 card=13)’
STAT #2 id=5 cnt=36 pid=4 pos=1 obj=0 op=’HASH JOIN OUTER (cr=19 pr=2 pw=0 time=140 us cost=13 size=975 card=13)’
STAT #2 id=6 cnt=36 pid=5 pos=1 obj=0 op=’HASH JOIN  (cr=16 pr=2 pw=0 time=35 us cost=10 size=598 card=13)’
STAT #2 id=7 cnt=36 pid=6 pos=1 obj=0 op=’HASH JOIN  (cr=13 pr=0 pw=0 time=0 us cost=8 size=572 card=13)’
STAT #2 id=8 cnt=2 pid=7 pos=1 obj=0 op=’MERGE JOIN CARTESIAN (cr=6 pr=0 pw=0 time=3 us cost=4 size=16 card=1)’
STAT #2 id=9 cnt=1 pid=8 pos=1 obj=280 op=’TABLE ACCESS FULL PROFILE$ (cr=3 pr=0 pw=0 time=0 us cost=2 size=8 card=1)’
STAT #2 id=10 cnt=2 pid=8 pos=2 obj=0 op=’BUFFER SORT (cr=3 pr=0 pw=0 time=1 us cost=2 size=8 card=1)’
STAT #2 id=11 cnt=2 pid=10 pos=1 obj=280 op=’TABLE ACCESS FULL PROFILE$ (cr=3 pr=0 pw=0 time=1 us cost=2 size=8 card=1)’
STAT #2 id=12 cnt=36 pid=7 pos=2 obj=22 op=’TABLE ACCESS FULL USER$ (cr=7 pr=0 pw=0 time=0 us cost=3 size=1008 card=36)’
STAT #2 id=13 cnt=2 pid=6 pos=2 obj=281 op=’TABLE ACCESS FULL PROFNAME$ (cr=3 pr=2 pw=0 time=1 us cost=2 size=2 card=1)’
STAT #2 id=14 cnt=2 pid=5 pos=2 obj=297 op=’TABLE ACCESS FULL RESOURCE_GROUP_MAPPING$ (cr=3 pr=0 pw=0 time=1 us cost=2 size=29 card=1)’
STAT #2 id=15 cnt=7 pid=4 pos=2 obj=16 op=’TABLE ACCESS FULL TS$ (cr=9 pr=0 pw=0 time=48 us cost=4 size=21 card=7)’
STAT #2 id=16 cnt=7 pid=3 pos=2 obj=16 op=’TABLE ACCESS FULL TS$ (cr=9 pr=0 pw=0 time=12 us cost=4 size=21 card=7)’
STAT #2 id=17 cnt=9 pid=2 pos=2 obj=292 op=’TABLE ACCESS FULL USER_ASTATUS_MAP (cr=3 pr=0 pw=0 time=8 us cost=2 size=27 card=9)’
WAIT #2: nam=’SQL*Net message to client’ ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=74760 tim=1375757734493823
And from Snapper:
SQL> @snapper4 all 10 1 49
Sampling SID 49 with interval 10 seconds, taking 1 snapshots…
— Session Snapper v4.09 BETA – by Tanel Poder ( http://blog.tanelpoder.com ) – Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! 🙂
——————————————————————————————————————————————————————————————————————
 SID @INST, USERNAME  , TYPE, STATISTIC                                                 ,         DELTA, HDELTA/SEC,    %TIME, GRAPH       , NUM_WAITS,  WAITS/SEC,   AVERAGES
——————————————————————————————————————————————————————————————————————
    49  @1, SYS       , STAT, opened cursors cumulative,             3,        .33,         ,             ,          ,           ,          1 per execution
    49  @1, SYS       , STAT, user calls,             2,        .22,         ,             ,          ,           ,        .67 per execution
Now let’s commit:
SQL> commit;
Commit complete.
SQL>
From trace file:
*** 2013-08-05 22:01:49.281
WAIT #2: nam=’SQL*Net message from client’ ela= 374787222 driver id=1650815232 #bytes=1 p3=0 obj#=74760 tim=1375758109281068
OPI CALL: type=105 argc= 2 cursor=  0 name=Cursor close all
CLOSE #2:c=0,e=20,dep=0,type=0,tim=1375758109281167
OPI CALL: type=94 argc=28 cursor=  0 name=V8 Bundled Exec
=====================
PARSING IN CURSOR #4 len=6 dep=0 uid=0 oct=44 lid=0 tim=1375758109281299 hv=3480936638 ad=’0′ sqlid=’23wm3kz7rps5y’
commit
END OF STMT
PARSE #4:c=0,e=91,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1375758109281298
XCTEND rlbk=0, rd_only=0, tim=1375758109281345
EXEC #4:c=0,e=102,p=0,cr=0,cu=1,mis=0,r=0,dep=0,og=0,plh=0,tim=1375758109281434
WAIT #4: nam=’log file sync’ ela= 24619 buffer#=4018 sync scn=1381492 p3=0 obj#=74760 tim=1375758109306071
WAIT #4: nam=’SQL*Net message to client’ ela= 351 driver id=1650815232 #bytes=1 p3=0 obj#=74760 tim=1375758109307375
From Snapper:
SQL> @snapper4 all 6 1 49
Sampling SID 49 with interval 6 seconds, taking 1 snapshots…
— Session Snapper v4.09 BETA – by Tanel Poder ( http://blog.tanelpoder.com ) – Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! 🙂
——————————————————————————————————————————————————————————————————————
 SID @INST, USERNAME  , TYPE, STATISTIC                                                 ,         DELTA, HDELTA/SEC,    %TIME, GRAPH       , NUM_WAITS,  WAITS/SEC,   AVERAGES
——————————————————————————————————————————————————————————————————————
    49  @1, SYS       , STAT, opened cursors cumulative,             1,        .17,         ,             ,          ,           ,          ~ per execution
    49  @1, SYS       , STAT, user commits,             1,        .17,         ,             ,          ,           ,          ~ per execution
    49  @1, SYS       , STAT, user calls,             2,        .34,         ,             ,          ,           ,          ~ per execution
This is just a little example of how OPI CALL is related to user calls metric. You can play and test more scenarios of select statements to see how they are being affected by ARRAYSIZE setting in SqlPlus.
Craig posted a table containing the result of his testing which is having the same results as this test.

SQL
User Calls
Select 1 row
3
Insert
2
Commit
2
Thanks,

Alfredo

Oracle 12c ASM new features


Today I will talk about some new features for ASM on 12c version.
Oracle Flex ASM
Oracle Flex ASM is a set of new features that provide critical capabilities required for cloud computing. Oracle Flex ASM redefines the traditional ASM cluster architecture of having one ASM instance on every node in the cluster; this means you can have less ASM instances than nodes in your cluster. In this configuration the number of ASM instances running is called ASM cardinality, by default the ASM cardinality is 3 and can be changed with a Clusterware command.
What are the benefits?
On the traditional architecture when an ASM instance fails; all DB instances connected to that instance in the node will also fail. With Oracle Flex ASM if the ASM instance fail the Clusterware will relocate that ASM instance to a different node and the DB instances will remotely (through private network) connect to the relocated ASM instance, all without disruption to the DB client.
Dedicated ASM Network
This new 12c feature provides the option to dedicate a private network for ASM network traffic only. There’s also the option to use the Oracle Clusterware interconnect private network.
Remote Access
As per the new Oracle Flex ASM feature, the DB instance can remotely connect to ASM instance hence the need of a password file in order to authenticate remote DB instances to ASM. Oracle Flex ASM has the ability of storing password files in a Disk Group and is extended to DB clients; this is really useful to avoid synchronizing multiple password files within the cluster.
Oracle Flex ASM is one of the most important enhancements to ASM in 12c version, however in the below whitepaper describes the rest of new features present.
Bertrand Drouvot has already tested this Oracle Flex ASM feature and uploaded the contents into his own blog (http://bdrouvot.wordpress.com/2013/06/29/build-your-own-flex-asm-12c-lab-using-virtual-box/).
Another interesting feature is the Extent Reading Selection Enhancement which evenly distributes the selection of which copy of a block is read in ASM Disk Groups with normal or high redundancy. This feature is enabled by default in 12c and states that users on I/O bound systems should notice a performance improvement while reading blocks from disks.
Thanks,
Alfredo

Why my new Disk Group is not getting mounted automatically when ASM instance starts?

Today I faced the issue that a new ASM Disk Group created in instance +ASM1 is not getting automatically mounted in instance +ASM2.

The first step was to check DB dependencies:

[oracle@ol5-112-rac2 trace]$ srvctl config database -d RAC
Database unique name: RAC
Database name: RAC
Oracle home: /u01/app/oracle/product/11.2.0/db_1
Oracle user: oracle
Spfile: +DATA/RAC/spfileRAC.ora
Domain: localdomain
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Server pools: RAC
Database instances: RAC1,RAC2
Disk Groups: DATA
Services: reports
Database is administrator managed
You can see that only dependent Disk Groups are ‘DATA’.

Let us add ‘FRA’ also as dependent Disk Group:

[oracle@ol5-112-rac2 trace]$ srvctl modify database -d RAC -a ‘DATA,FRA’
[oracle@ol5-112-rac2 trace]$ srvctl config database -d RAC
Database unique name: RAC
Database name: RAC
Oracle home: /u01/app/oracle/product/11.2.0/db_1
Oracle user: oracle
Spfile: +DATA/RAC/spfileRAC.ora
Domain: localdomain
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Server pools: RAC
Database instances: RAC1,RAC2
Disk Groups: DATA,FRA
Services: reports
Database is administrator managed
The next step is to add the Disk Groups to ASM_DISKGROUPS parameter:

SQL> ALTER SYSTEM SET ASM_DISKGROUPS=’DATA’,’FRA’ scope=both sid=’+ASM1′;
System altered.
SQL> ALTER SYSTEM SET ASM_DISKGROUPS=’DATA’,’FRA’ scope=both sid=’+ASM2′;
System altered.
After restarting +ASM2 instance we can see that FRA Disk Group is mounted automatically:

[oracle@ol5-112-rac2 trace]$ sqlplus / as sysasm
SQL*Plus: Release 11.2.0.1.0 Production on Wed Jun 12 15:44:44 2013
Copyright (c) 1982, 2009, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 – Production
With the Real Application Clusters and Automatic Storage Management options
SQL> set lines 1000
SQL> select * from V$ASM_DISKGROUP;
GROUP_NUMBER NAME                           SECTOR_SIZE BLOCK_SIZE ALLOCATION_UNIT_SIZE STATE       TYPE     TOTAL_MB    FREE_MB HOT_USED_MB COLD_USED_MB REQUIRED_MIRROR_FREE_MB USABLE_FILE_MB OFFLINE_DISKS COMPATIBILITY                                                DATABASE_COMPATIBILITY                                       V
———— —————————— ———– ———- ——————– ———– —— ———- ———- ———– ———— ———————– ————– ————- ———————————————————— ———————————————————— –
           1 DATA                                   512       4096              1048576 MOUNTED     EXTERN      15342      12616           0         2726                       0          12616     0 11.2.0.0.0                                                   10.1.0.0.0                                                   N
           2 FRA                                    512       4096              1048576 MOUNTED     EXTERN       6133       5962           0          171                       0           5962     0 11.2.0.0.0                                                   10.1.0.0.0                                                   N
SQL> exit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 – Production
With the Real Application Clusters and Automatic Storage Management options
Thanks,

Alfredo

ORA-15097: cannot SHUTDOWN ASM instance with connected client

In 11g R2 Clusterware configurations the OCR is located in ASM disk, that’s why ASM can’t be shutdown while the cluster is running.  You have to shutdown your cluster in order to shutdown ASM instance.

Oracle support note 984663.1

Here’s a good blog about this:
Example, how to shutdown ASM instance on node ol5-112-rac1:
[oracle@ol5-112-rac1 ~]$ crsctl status resource -t
——————————————————————————–
NAME           TARGET  STATE        SERVER                   STATE_DETAILS
——————————————————————————–
Local Resources
——————————————————————————–
ora.DATA.dg
               ONLINE  ONLINE       ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2
ora.FRA.dg
               OFFLINE OFFLINE      ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2
ora.LISTENER.lsnr
               ONLINE  ONLINE       ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2
ora.asm
               ONLINE  ONLINE       ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2             Started
ora.eons
               ONLINE  ONLINE       ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2
ora.gsd
               OFFLINE OFFLINE      ol5-112-rac1
               OFFLINE OFFLINE      ol5-112-rac2
ora.net1.network
               ONLINE  ONLINE       ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2
ora.ons
               ONLINE  ONLINE       ol5-112-rac1
               ONLINE  ONLINE       ol5-112-rac2
——————————————————————————–
Cluster Resources
——————————————————————————–
ora.LISTENER_SCAN1.lsnr
      1        ONLINE  ONLINE       ol5-112-rac1
ora.oc4j
      1        OFFLINE OFFLINE
ora.ol5-112-rac1.vip
      1        ONLINE  ONLINE       ol5-112-rac1
ora.ol5-112-rac2.vip
      1        ONLINE  ONLINE       ol5-112-rac2
ora.rac.db
      1        ONLINE  ONLINE       ol5-112-rac2             Open
      2        ONLINE  ONLINE       ol5-112-rac1
ora.rac.reports.svc
      1        ONLINE  ONLINE       ol5-112-rac1
ora.scan1.vip
      1        ONLINE  ONLINE       ol5-112-rac1
[oracle@ol5-112-rac1 ~]$
Shutdown RAC1 instance first:

[oracle@ol5-112-rac1 ~]$ srvctl stop instance –d RAC –I RAC1 –o immediate
Then proceed to shutdown cluster (root required):

[oracle@ol5-112-rac1 ~]$ su –
[root@ol5-112-rac1 bin]#
[root@ol5-112-rac1 bin]# ./crsctl stop cluster
CRS-2673: Attempting to stop ‘ora.crsd’ on ‘ol5-112-rac1’
CRS-2790: Starting shutdown of Cluster Ready Services-managed resources on ‘ol5-112-rac1’
CRS-2673: Attempting to stop ‘ora.LISTENER.lsnr’ on ‘ol5-112-rac1’
CRS-2673: Attempting to stop ‘ora.DATA.dg’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.LISTENER.lsnr’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.ol5-112-rac1.vip’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.ol5-112-rac1.vip’ on ‘ol5-112-rac1’ succeeded
CRS-2672: Attempting to start ‘ora.ol5-112-rac1.vip’ on ‘ol5-112-rac2’
CRS-2676: Start of ‘ora.ol5-112-rac1.vip’ on ‘ol5-112-rac2’ succeeded
CRS-2677: Stop of ‘ora.DATA.dg’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.asm’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.asm’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.ons’ on ‘ol5-112-rac1’
CRS-2673: Attempting to stop ‘ora.eons’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.ons’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.net1.network’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.net1.network’ on ‘ol5-112-rac1’ succeeded
CRS-2677: Stop of ‘ora.eons’ on ‘ol5-112-rac1’ succeeded
CRS-2792: Shutdown of Cluster Ready Services-managed resources on ‘ol5-112-rac1’ has completed
CRS-2677: Stop of ‘ora.crsd’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.cssdmonitor’ on ‘ol5-112-rac1’
CRS-2673: Attempting to stop ‘ora.ctssd’ on ‘ol5-112-rac1’
CRS-2673: Attempting to stop ‘ora.evmd’ on ‘ol5-112-rac1’
CRS-2673: Attempting to stop ‘ora.asm’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.cssdmonitor’ on ‘ol5-112-rac1’ succeeded
CRS-2677: Stop of ‘ora.evmd’ on ‘ol5-112-rac1’ succeeded
CRS-2677: Stop of ‘ora.ctssd’ on ‘ol5-112-rac1’ succeeded
CRS-2677: Stop of ‘ora.asm’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.cssd’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.cssd’ on ‘ol5-112-rac1’ succeeded
CRS-2673: Attempting to stop ‘ora.diskmon’ on ‘ol5-112-rac1’
CRS-2677: Stop of ‘ora.diskmon’ on ‘ol5-112-rac1’ succeeded
[root@ol5-112-rac1 bin]# ps -ef|grep pmon
root      7072  5722  0 14:45 pts/2    00:00:00 grep pmon
[root@ol5-112-rac1 bin]# ps -ef|grep +ASM1
root      7074  5722  0 14:46 pts/2    00:00:00 grep +ASM1
[root@ol5-112-rac1 bin]#
At this point ASM & Cluster Ready Services managed resources are down.

In order to start them again just need to issue:

[root@ol5-112-rac1 bin]# ./crsctl start cluster
[root@ol5-112-rac1 bin]# exit
[oracle@ol5-112-rac1 ~]$ srvctl start instance –d RAC –I RAC1

Thanks,
Alfredo

Cleanup After Failed Installation Oracle Clusterware 11gR2

In this blog I will talk about how to cleanup a failed installation of the Oracle Clusterware 11gR2 in one particular node. I was installing the new Oracle Clusterware 11.2.0.1 in my home lab by follwing Tom Kyte’s instructions (http://www.oracle-base.com/articles/11g/oracle-db-11gr2-rac-installation-on-oel5-using-virtualbox.php#install_grid_infrastructure), then went through the part that the installer GUI needs us to run the root.sh scripts.



The easy thought was to run the root.sh script in both nodes of my RAC (RAC1 & RAC2) at the same time, without reading the explicit instructions “Run the script on the local node first. After successful completion, you can run the script in parallel on all other nodes.”:



The script run successful in the RAC1 node but in the RAC2 node. So when the script finished in RAC1 tried to run it again in RAC2, but the same results “the output was that the script was already ran”.

What to do next?, do I have to start over from scratch?

Surfing the web found a good & useful article from Guenadi Jilevski (http://gjilevski.com/2010/08/12/how-to-clean-up-after-a-failed-11g-crs-install-what-is-new-in-11g-r2-2/), here shows how to perform a manual cleanup in 11gR1, but also shows the new features and scripts in 11gR2.

Summarized steps:

Deconfigure Oracle Clusterware 11.2.x.x without removing the binaries:

  • Log in as root user on the node you encountered the error. Change directory to $GRID_HOME/crs/install.
          # cd $GRID_HOME/crs/install

  • Run rootcrs.pl with the -deconfig -force flags on the node you have the issue.
          # perl rootcrs.pl -deconfig -force

  • If you are deconfiguring Oracle Clusterware on all the nodes in the cluster, then you have to add the -lastnode flag on the last one in order to deconfigure OCR and Voting disks.
          # perl rootcrs.pl -deconfig -force -lastnode

After these steps, run the root.sh script again. This time it will smoothly run.

You should also want to read the complete OSS note:
How to Deconfigure/Reconfigure(Rebuild OCR) or Deinstall Grid Infrastructure [ID 1377349.1]

Thanks,
Alfredo

Historical SQL Statistics And Execution Plan Change

How many times have you received user’s phone call stating that the DB is slow?, well sometimes this has nothing to do with the DB’s overall performance itself, but with a user’s query.

Now the question is, is this query really slow?, the best way to find this out is comparing the actual execution time with the ones in the past. Here’s a SQL statement which search inside AWR repository (Caution!!! a special license is required!!!), it compares the execution plan of all SQL_ID’s against the previous snapshot.

awr_planchanges.sql

  prompt enter the number of days in the past to scan
  SET LINES 500
  SELECT A.SNAP_ID,
         BEGIN_INTERVAL_TIME,
         SQL_ID,
         HASH_VALUE1,
         HASH_VALUE2,
         VALUE1 as “ELAPSED TIME PER EXEC 1” ,
         VALUE2 as “ELAPSED TIME PER EXEC 2”,
         ROUND (CHANGE_PERCENT) as “CHANGE PERCENT”
    FROM (  SELECT SNAP_ID,
                   SQL_ID,
                   SUM (pvalue1) HASH_VALUE1,
                   SUM (pvalue2) HASH_VALUE2,
                   SUM (value1) VALUE1,
                   SUM (value2) VALUE2,
                   (SUM (VALUE1) + 1) * 100 / (SUM (VALUE2) + 1)
                      AS CHANGE_PERCENT
              FROM (SELECT snap_id,
                           0 AS snap2,
                           sql_id,
                           plan_hash_value AS pvalue1,
                           0 AS pvalue2,
                           ROUND (
                              elapsed_time_delta / executions_delta / 1000000,
                              3)
                              AS value1,
                           0 AS value2
                      FROM dba_hist_sqlstat sql
                     WHERE executions_delta > 0
                    UNION
                    SELECT snap_id + 1,
                           snap_id AS snap2,
                           sql_id,
                           0 AS pvalue1,
                           plan_hash_value AS pvalue2,
                           0 AS vaule,
                           ROUND (
                              elapsed_time_delta / executions_delta / 1000000,
                              3)
                              AS value2
                      FROM dba_hist_sqlstat sql
                     WHERE executions_delta > 0)
          GROUP BY SNAP_ID, SQL_ID) A,
         dba_hist_snapshot B
   WHERE     A.SNAP_ID = B.SNAP_ID
         AND HASH_VALUE1 > 0
         AND HASH_VALUE2 > 0
         AND HASH_VALUE1 != HASH_VALUE2
         AND BEGIN_INTERVAL_TIME > SYSDATE – (&days)
ORDER BY A.SNAP_ID
/

This is the output of the script:

SNAP_ID BEGIN_INTERVAL_TIME       SQL_ID       HASH_VALUE1 HASH_VALUE2 SEC PER EXE 1 SEC PER EXE 2 CHANGE % 
——– ———————–  ————- ———– ———– ————- ————- ——–
9547 01-OCT-12 01.00.07.841 AM   4urszd9dt9fjv  4862331523   891004645          .015          .007       101
9585 02-OCT-12 03.00.41.798 PM   4urszd9dt9fjv  4862331523   891004645          .009          .003       101
9586 02-OCT-12 04.00.36.393 PM   4urszd9dt9fjv   891004645  4862331523          .006          .009       100
9587 02-OCT-12 05.00.25.306 PM   1k30v0pyg32vu   414828074   878600859          .179          .157       102
9587 02-OCT-12 05.00.25.306 PM   dsm86bzuqtd2r  2452407222  3005749068          .048         1.37         44
9616 03-OCT-12 10.00.34.499 PM   4urszd9dt9fjv  4862331523   891004645          .018          .023       100
9621 04-OCT-12 03.00.06.979 AM   4urszd9dt9fjv   891004645  4862331523          .03           .027       100
9640 04-OCT-12 09.00.40.250 PM   4urszd9dt9fjv  4862331523   891004645          .042          .012       103
9641 04-OCT-12 10.00.22.954 PM   dfmu8nm1cscx7  3810296266  4308029399          .938          .703       114
9710 07-OCT-12 07.00.09.269 PM   4urszd9dt9fjv  4862331523   891004645          .046          .015       103
9750 09-OCT-12 11.00.59.162 AM   1k30v0pyg32vu  1634868183   414828074          .16           .155       100
9758 09-OCT-12 07.00.10.659 PM   b70xavb9wv27v  1111647858  4256287279         5.937         6.475        93

12 rows selected.

You can clearly see how the HASH_VALUE changed and the execution time as well. If the CHANGE % is above 100% means that execution time decreased, on the other hand CHANGE % below 100% means the execution time increased.

ORAganism blog is having a really good script which searches by SQL_ID.

http://oraganism.wordpress.com/2011/12/14/a-dba_hist_sqlstat-query-that-i-am-very-fond-of/ 


Happy troubleshooting,
Alfred

Same post in Spanish here!