Oracle - alfredokriegdba.com

Understanding Oracle SQL Plan Management SPM – Part 3

This is the third post of SQL Plan Management. In the previous post, Understanding SQL Plan Management– Part 2, I described the three main components of SPM, this time I want to show you how to manually capture plans from the cursor cache. In other words, manually capture plans that reside in memory.

In order to manually capture plans, I’m considering that automatic capture is disabled or OPTIMIZER_CAPTURE_SQL_PLAN_BASELINES is set to FALSE. Oracle provides a function named DBMS_SPM.load_plans_from_cursor_cache to manual capture plans from cursor cache.

DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE (

sql_id IN VARCHAR2,

plan_hash_value IN NUMBER := NULL,

sql_text IN CLOB,

fixed IN VARCHAR2 := ‘NO’,

enabled IN VARCHAR2 := ‘YES’)

RETURN PLS_INTEGER;

The common use for this function, is to specify the sql_id of the statement we want to capture. We also can specify the plan_hash_value or the sql_text. Two more attributes can be set within this function, fixed is ‘NO’ by default and enabledis ‘YES’ by default. If you want to load plans, but you don’t want the CBO to make use if them; set the attribute enabled to ‘NO’.

In the below example I’m capturing all the SQL plans for sql_id4c372tsuhtunm and printing the number of plans loaded:

SQL> SET SERVEROUTPUT ON

DECLARE

l_plans_loaded PLS_INTEGER;

BEGIN

l_plans_loaded := DBMS_SPM.load_plans_from_cursor_cache(

sql_id => ‘4c372tsuhtunm’);

DBMS_OUTPUT.put_line(‘Plans Loaded: ‘ || l_plans_loaded);

END;

/SQL> 2 3 4 5 6 7 8 9

Plans Loaded: 8

PL/SQL procedure successfully completed.

To verify the SQL baselines created for this sql_id, I just need to query DBA_SQL_PLAN_BASELINES view:

SQL> select SIGNATURE,SQL_HANDLE,PLAN_NAME,ORIGIN,ENABLED,ACCEPTED,FIXED,REPRODUCED from dba_sql_plan_baselines;

SIGNATURE SQL_HANDLE PLAN_NAME ORIGIN ENABLED ACCEPTED FIXED REPRODUCED

——————— ——————— —————————— ————– ——- ——– —– ———-

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5ye8c8b02d MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5yc568a49d MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5ybff74238 MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5y0310173f MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5y8e42f3cc MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5y25375ef9 MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5y9de69d5d MANUAL-LOAD YES YES NO YES

5535156277878016190 SQL_4cd0d34ee73148be SQL_PLAN_4tn6m9vmm2k5yb76f0084 MANUAL-LOAD YES YES NO YES

8 rows selected.

Look at the data for the ORIGIN column, it shows from where the plans were loaded, either from manual load or auto capture.

Another method is to manual load plans from SQL Tuning Sets (STS). The STS may contain plans that are not present in memory, like plans in the AWR repository. This method is very useful when you want to create baselines of plans that were created by the CBO few days ago and are not in the cursor cache at this time. Keep in mind that STS requires a special license in order to be used. Oracle provides the function DBMS_SPM.load_plans_from_sqlset to accomplish this task.

DBMS_SPM.LOAD_PLANS_FROM_SQLSET (

sqlset_name IN VARCHAR2,

sqlset_owner IN VARCHAR2 := NULL,

basic_filter IN VARCHAR2 := NULL,

fixed IN VARCHAR2 := ‘NO’,

enabled IN VARCHAR2 := ‘YES’

commit_rows IN NUMBER := 1000)

RETURN PLS_INTEGER;

You just need to specify the sqlset_name and the sqlset_owner in order to load the plans contained in the STS. It also has the default parameters fixed, set to ‘NO’ and enabled,set to ‘YES’. Two interesting attributes can be set within this function. The basic_filter attribute allows you to select only the plans that meet this filter criteria, in other words, is like a ‘where’ in a query.

basic_filter => ‘sql_text like ”select /*LOAD_STS*/%”’ orbasic_filter => ‘sql_id=”4c372tsuhtunm“‘

The commit_rows attribute, allows you to commit after the value specified, which is 1000 by default. Let’s assume that inside this STS we have 30000 plans and we want to load all of them, SPM will commit every 1000 plans to help to reduce the undo log.

Keep in mind that once you manually load plans for a specific SQL (signature), the CBO will continue capturing plans for it, even if the automatic capture is disabled. Those automatic captured plans will not be used by the CBO until you verify and evolve them.

In the next post, I’m going to show you how to evolve plans in 11g and 12c versions.

Thanks,

Alfredo

Understanding Oracle SQL Plan Management SPM – Part 2

In my previous post Understanding SQL Plan Management – Part 1, I tried to cover some basic concepts of SQL Plan Management (SPM). This post will show you the main components of SPM and how they work in the different versions of Oracle.

SQL plan management framework has three main components, plan capture, plan selection and plan evolution. These components allow administrators choose which plans should be executed by the database. Plan capture is the process of loading execution plans from different sources into the SQL management base. Plan selection is the process the database follows in order to choose the best plan available after considering many factors including SQL baselines. Plan evolution is the process of making baselines executable after verifying if any performance improvement is available.

Plan capture can be done in two forms, automatic and manual. Automatic plan capture takes place when the database initialization parameter OPTIMIZER_CAPTURE_SQL_PLAN_BASELINES is set to TRUE. Keep in mind that the default value for this parameter is FALSE. If automatic capture is enabled, the CBO will log the SQL signature of any SQL statement executed for the very first time in the database. When the SQL statement is executed for the second time it will recognize it as a repeatable statement in the database and SQL baselines are automatically created and marked as “ACCEPTED” for each repeatable SQL statement. Be careful with this feature because the baseline will be created using the execution plan of the second execution whether is optimal or not. If the CBO produces a better execution plan after the baseline is created, the plan will be stored in the SMB but not used until the plan is evolved.

Manual plan capture is the most common method to capture plans. It can be done in conjunction or instead of automatic capture for a single SQL statement or a group of statements. Plans can be manually loaded by using either DBMS_SPM package or Oracle Enterprise Manager (OEM) from four different sources. Manual loaded plans are automatically “ACCEPTED” and the CBO will continue to load plans automatically for this plans even if automatically plan capture is disabled. Plans automatically loaded after the manual load are marked as not “ACCEPTED”. You can load plans from four sources. From cursor cache, which are the active plans in memory. From SQL tuning sets, which require the SQL tuning pack or real application testing license. From stored outlines and from another Oracle database system using datapump. In order to transfer baselines from one database system to another, you must pack, load and unpack the baseline by following the below steps:

1. On the original system, create a staging table using the DBMS_SPM.CREATE_STGTAB_BASELINE procedure.

2. Pack the SQL plan baselines you want to export from the SQL management base into the staging table using the DBMS_SPM.PACK_STGTAB_BASELINE function.

3. Export the staging table into a flat file using the export command or Oracle Data Pump.

4. Transfer this flat file to the target system.

5. Import the staging table from the flat file using the import command or Oracle Data Pump.

6. Unpack the SQL plan baselines from the staging table into the SQL management base on the target system using the DBMS_SPM.UNPACK_STGTAB_BASELINE function.

The CBO calculates the execution plan every time the SQL statement is parsed (compiled) and then proceeds to execute the statement. If the OPTIMIZER_USE_SQL_PLAN_BASELINES is set to TRUE, the CBO will check if a SQL baseline exists before the plan is executed. If there is no SQL signature that matches the parsed SQL statement then the CBO will log this signature in the statement log if the automatic capture is enabled or just proceeds to execute the statement if disabled. If a signature matches the statement and a baseline doesn’t exists, it will proceed to create a plan for verification but if a baseline already exists then the baseline will be executed. If more than one “ACCEPTED” plan exists in the baseline, the CBO costs each plan for the given SQL statement and picks the one with the lowest cost. If a baseline is marked as “FIXED”, the CBO picks the lowest cost fixed plan unless all fixed plans are marked as non-reproducible.

Plan evolution, in simple terms is the process to “ACCEPT” or “REJECT” plans after verifying that performance is better or not compared with the current plan. Plan evolution as plan capture can be done automatic and manual. Automatic plan evolution is managed by the SQL tuning advisor task in 11g versions, while is managed by the SPM Evolve Advisor in 12c.

Adaptive SQL Plan Management is one of the new features of Oracle 12c. Adaptive SQL Plan Management, is just the new automatic evolve task SYS_AUTO_SPM_EVOLVE_TASK that runs in the nightly maintenance window and is enabled by default. This task ranks all unaccepted plans and runs the evolve process for them. If the plan performs 1.5x times better than the current plan in the SQL plan baseline, then the plan is automatically accepted and becomes usable by the optimizer. This ratio defined by the hidden parameter _PLAN_VERIFY_IMPROVEMENT_MARGIN and can be modified. After the evolve task is complete, a persistent report is generated with details on how the non-accepted plan perform compared to the accepted plan performance. Administrators can go back and check what plans were evolved to any point in time.

Manual plan evolution is bit different in every version of the database. In 11g release 1, is being controlled using the DBMS_SPM.ALTER_SQL_PLAN_BASELINE function and by changing the attribute_name ‘ACCEPTED’ to ‘YES’. Is the administrator’s responsibility verify that the plan is performing better than the current plan. In 11g release 2, the DBMS_SPM.EVOLVE_SQL_PLAN_BASELINE function helps the adminstrator verify if the plan performs better than the current plan and if it does, the plan is marked as “ACCEPTED”. A new SPM Evolve Advisor API is available in 12c version. Create task, execute task and report the evolve taks are part of the three step process of evolving plans. Unaccepted plans are not manually evolved when using the SPM Evolve Advisor, therfore the plan must be manually accepted using DBMS_SPM.ACCEPT_SQL_PLAN_BASELINE function.

In the next post I will show you how to use the different DBMS_SPM functions to capture and evolve plans.

Thanks,

Alfredo

Why you should attend to IOUG Collaborate 2015?

Today I want to share a personal story about IOUG’s Collaborate, a great conference that supports products from Engineered Systems, Oracle Databases to Fusion Middleware and Siebel. Last year was my first time as a speaker and was one of kind experience as I was able to share my knowledge in Oracle Database performance tuning with professionals that work on a daily basis with Oracle technologies.

This is what makes Collaborate great, professionals sharing their experiences to other professionals. You can be sure that the guys who are speaking at Collaborate really know what they are talking about, that’s a guarantee. Apart of education, networking is also great at Collaborate, so you can meet IT professionals, Oracle Product Managers and technology gurus (you may already seen their blogs).

This year Collaborate will be greater than ever, just imagine to learn from Tom Kyte, Craig Shallahamer and Kellyn Pot’Vin-Gorman, you don’t want to miss the opportunity!

If you want to be part of this big IT event, want to learn great stuff that will help you with your daily work and want to network with great people, you should register right away!

More information available at http://collaborate.ioug.org/

BTW. If you attend the Collaborate 2015, be sure to stop by my sessions about Oracle DB Performance and Oracle Enterprise Manager

http://coll15.mapyourshow.com/6_0/sessions/session-details.cfm?ScheduleID=3431

http://coll15.mapyourshow.com/6_0/sessions/session-details.cfm?ScheduleID=4503

Oracle Enterprise Manager at Collaborate 2015 https://lnkd.in/e3G6ZzK

Thanks,

Alfredo

Oracle Enterprise Manager Security– Disable SYSMAN access

In Enterprise Manager 12c SYSMAN user is the schema owner and as a best practice all the users should log in using their own individual accounts. To enforce this you can prevent SYSMAN from login into the console and/or emcli by setting SYSTEM_USER to -1 in the MGMT_CREATED_USERS table:

UPDATE MGMT_CREATED_USERS

SET SYSTEM_USER=’-1’

WHERE user_name=’SYSMAN’

To re-enable the access just set it to 1.

UPDATE MGMT_CREATED_USERS

SET SYSTEM_USER=’1’

WHERE user_name=’SYSMAN’

Refer to Oracle Support’s note:

How To Disable SYSMAN & SYSTEM Users from Logging into Grid Console? (Doc ID 867360.1)

Thanks,

Alfredo

Oracle Enterprise Manager – Reducing the noise, Part 1

Enterprise Manager 12c is a great monitoring tool, with it you can monitor a wide range of target types from databases to middleware; although out-of-the-box metrics can suit your monitoring requirements they can generate a considerable amount of white noise. In order to reduce this noise first you have to identify which are the top alerts in your system; Cloud Control comes with several predefined reports that help you to dig into multiple areas of your system, there’s a report “20 Most Common Alerts” which shows you the incidence of common alerts.

In the picture above, you can clearly see that metric “Database Time Spent Waiting (%)” appears twice in my Top 3, let’s find out our metric setting for my DB targets; in order to do this we must go to a DB home page then Oracle Database -> Monitoring -> Metrics and Collection Settings.

Wait a minute! Why I’m receiving alerts if there are no thresholds setup for any of those metrics?, this behavior is clearly explained in MOS note 1500074.1 about a default warning threshold of 30% inside the database configuration. Let’s take a look to dba_threshold to confirm.

set lines 300

column METRICS_NAME format a30

column WARNING_OPERATOR format a30

column WARNING_VALUE format a30

column CRITICAL_OPERATOR format a30

column CRITICAL_VALUE format a30

SELECT METRICS_NAME,WARNING_OPERATOR ,WARNING_VALUE,CRITICAL_OPERATOR ,CRITICAL_VALUE FROM DBA_THRESHOLDS;

METRICS_NAME WARNING_OPERATOR WARNING_VALUE CRITICAL_OPERATOR CRITICAL_VALUE

———————————– —————————— —————————— —————————— ——————————

Average Users Waiting Counts GT 10 NONE

Average Users Waiting Counts GT 30 NONE

Blocked User Session Count GT 0 NONE

Current Open Cursors Count GT 1200 NONE

Database Time Spent Waiting (%) GT 30 NONE

Database Time Spent Waiting (%) GT 50 NONE

Logons Per Sec GE 100 NONE

Session Limit % GT 90 GT 97

Tablespace Bytes Space Usage DO NOT CHECK 0 DO_NOT_CHECK 0

Tablespace Space Usage GE 85 GE 97

22 rows selected.

There you go!, all metrics for “Database Time Spent Waiting (%)” are set to 30% or 50% values, now the trick to disable these metrics is to set them to a different value like 99%; this will override the default value as follows:

Let’s look at the database setting again:

set lines 300

column METRICS_NAME format a30

column WARNING_OPERATOR format a30

column WARNING_VALUE format a30

column CRITICAL_OPERATOR format a30

column CRITICAL_VALUE format a30

METRICS_NAME WARNING_OPERATOR WARNING_VALUE CRITICAL_OPERATOR CRITICAL_VALUE

———————————– —————————— —————————— —————————— ——————————

Average Users Waiting Counts GT 10 NONE

Average Users Waiting Counts GT 30 NONE

Blocked User Session Count GT 0 NONE

Current Open Cursors Count GT 1200 NONE

Database Time Spent Waiting (%) GT 99 NONE

Logons Per Sec GE 100 NONE

Session Limit % GT 90 GT 97

Tablespace Bytes Space Usage DO NOT CHECK 0 DO_NOT_CHECK 0

Tablespace Space Usage GE 85 GE 97

25 rows selected.

We successfully modified these metrics to a very high value; at this point you can decide to stay at 99% or you can remove that threshold in order to completely disable them.

Now let’s confirm those settings in the database:

set lines 300

column METRICS_NAME format a30

column WARNING_OPERATOR format a30

column WARNING_VALUE format a30

column CRITICAL_OPERATOR format a30

column CRITICAL_VALUE format a30

METRICS_NAME WARNING_OPERATOR WARNING_VALUE CRITICAL_OPERATOR CRITICAL_VALUE

———————————– —————————— —————————— —————————— ——————————

Average Users Waiting Counts GT 10 NONE

Average Users Waiting Counts GT 30 NONE

Blocked User Session Count GT 0 NONE

Current Open Cursors Count GT 1200 NONE

Logons Per Sec GE 100 NONE

Session Limit % GT 90 GT 97

Tablespace Bytes Space Usage DO NOT CHECK 0 DO_NOT_CHECK 0

Tablespace Space Usage GE 85 GE 97

14 rows selected.

The metrics are not there anymore and hopefully the alerts neither. This behavior is also noted for “Average Users Waiting Counts” metric, if you are receiving considerable white noise for this metric you can disable as well following the same procedure. A good practice is to create a Monitoring template to help you modify these thresholds for multiple targets at once.

Stay tuned for my next post about reducing OEM 12c noise.

Thanks,

Alfredo

Oracle Recursive Sessions ORA-00018

Today I want to talk about Oracle Database session usage; last week there was a problem with a database reporting ORA-00018: maximum number of sessions exceeded, but the number of sessions from v$session was much less than the one specified in SESSIONS parameter.

So, what was going on?

Turns out this is explained by internal recursive sessions that also account but they are not seen in the dictionary views. Note ID 419130.1 explains this in detail but I wanted to see this behavior in my 12c test database.

SQL> select count(*) from v$session;

COUNT(*)

———-

104

SQL> select count(*) from x$ksuse where bitand(ksspaflg,1) !=0 ;

COUNT(*)

———-

132

Also wanted to know what sessions were recursive and seems like all of them are performing DDL operations.

SQL> select INDX,decode(bitand(ksuseflg,19),17,’BACKGROUND’,1,’USER’,2,’RECURSIVE’,’?’),ksuudsna from x$ksuse s WHERE decode(bitand(ksuseflg,19),17,’BACKGROUND’,1,’USER’,2,’RECURSIVE’,’?’)=’RECURSIVE’;

INDX DECODE(BIT KSUUDSNA

———- ———- ——————————

8 RECURSIVE SYS

11 RECURSIVE SYS

14 RECURSIVE SYS

15 RECURSIVE SYS

17 RECURSIVE SYS

19 RECURSIVE SYS

20 RECURSIVE SYS

21 RECURSIVE SYS

29 RECURSIVE SYS

32 RECURSIVE SYS

38 RECURSIVE SYS

39 RECURSIVE SYS

40 RECURSIVE SYS

42 RECURSIVE SYS

123 RECURSIVE SYS

126 RECURSIVE SYS

129 RECURSIVE SYS

134 RECURSIVE SYS

136 RECURSIVE SYS

137 RECURSIVE SYS

138 RECURSIVE SYS

139 RECURSIVE SYS

142 RECURSIVE SYS

144 RECURSIVE SYS

145 RECURSIVE SYS

148 RECURSIVE SYS

154 RECURSIVE SYS

155 RECURSIVE SYS

156 RECURSIVE SYS

157 RECURSIVE SYS

242 RECURSIVE SYS

247 RECURSIVE SYS

249 RECURSIVE SYS

250 RECURSIVE SYS

252 RECURSIVE SYS

253 RECURSIVE SYS

255 RECURSIVE SYS

257 RECURSIVE SYS

259 RECURSIVE SYS

264 RECURSIVE SYS

265 RECURSIVE SYS

269 RECURSIVE SYS

272 RECURSIVE SYS

273 RECURSIVE SYS

275 RECURSIVE SYS

276 RECURSIVE SYS

278 RECURSIVE SYS

367 RECURSIVE SYS

369 RECURSIVE SYS

371 RECURSIVE SYS

375 RECURSIVE SYS

376 RECURSIVE SYS

379 RECURSIVE SYS

381 RECURSIVE SYS

383 RECURSIVE SYS

384 RECURSIVE SYS

388 RECURSIVE SYS

389 RECURSIVE SYS

391 RECURSIVE SYS

392 RECURSIVE SYS

60 rows selected.

This is something to keep in mind when setting SESSIONS parameter in future.

Thanks,

Alfredo

IOUG Collaborate 2014, final presentation

Today I want to share with you the final presentation of session 553 that I’m going to hold tomorrow morning in the IOUG Collaborate 2014.

Hope you enjoy it!

2014_553_Krieg_ppt.pdf

Extract AWR data to build Response Time graphs (awrrtsys.sql)

This SQL script extract AWR data required to perform Response Time analysis for Oracle Databases. All information about it will be presented in the IOUG Collaborate 2014 session “553: Oracle Database Performance: Are Database Users Telling Me The Truth?”

–#********************************************************************

–#– Filename : awrrtsys.sql

–#– Author : Alfredo Krieg

–#– Original : 17-Oct-12

–#– Last Update : 21-Ago-13

–#– Description : awrrtsys.sql- System Response time per snapshot in the last x days

–# per desired unit of work –

–#– Usage : start awrrtsys.sql

–#– This script use AWR data (licensing is required)

–#********************************************************************

set termout on

set feedback off

set heading on

set linesize 150

set pagesize 100

set feedback off verify off

col snap_id format 999999 heading “Snapshot Id”

col instance_number format 99 heading “Instance Number”

col snap_time format a25 heading “Snap Begin Time”

col non_idle_wait format 9999999.99 heading “Qt (s)”

col cpu_time format 9999999.99 heading “St (s)”

col lio format 9999999.99 heading “LIO”

col pio format 9999999.99 heading “PIO”

col uw_variable format 9999999.99 heading “UC”

col rt_ms_per_lio format 9999999.99 heading “RT (ms/lio)”

col rt_ms_per_pio format 9999999.99 heading “RT (ms/pio)”

col rt_ms_per_uw format 9999999.99 heading “RT (ms/uc)”

SELECT a.SNAP_ID,

b.instance_number,

TO_CHAR (END_INTERVAL_TIME, ‘mon/dd/yyyy HH24:mi’) AS snap_time,

non_idle_wait,

background_cpu+

db_cpu as cpu_time,

lio,

pio,

uwvariable AS UW_VARIABLE,

ROUND (

( ( (background_cpu + db_cpu) / lio) + (non_idle_wait / lio))

* 1000,

AS RT_ms_per_lio,

ROUND (

( ( (background_cpu + db_cpu) / pio) + (non_idle_wait / pio))

* 1000,

AS RT_ms_per_pio,

ROUND (

( ( (background_cpu + db_cpu) / (uwvariable))

+ (non_idle_wait / (uwvariable)))

* 1000,

AS RT_ms_per_uw

FROM (

SELECT SNAP_ID,

SUM (non_idle_wait) AS non_idle_wait,

ROUND (SUM (background_cpu), 0) AS background_cpu,

ROUND (SUM (db_cpu), 0) AS db_cpu,

SUM (lio) AS lio,

SUM (pio) AS pio,

SUM (uwvariable) AS uwvariable

FROM (

SELECT SNAP_ID,

ROUND (time_secs, 0) non_idle_wait,

0 AS background_cpu,

0 AS db_cpu,

0 AS lio,

0 AS pio,

0 AS uwvariable

FROM ( SELECT snap_id,

‘WAIT’ AS wait_class,

‘Non Idle’ AS name,

(SUM (VALUE) – SUM (value1)) / 1000000

AS time_secs

FROM ( SELECT snap_id,

0 AS snap2,

SUM (time_waited_micro) AS VALUE,

0 AS value1

FROM dba_hist_system_event

WHERE wait_class ‘Idle’

GROUP BY snap_id

UNION

SELECT snap_id + 1,

snap_id,

SUM (time_waited_micro) AS value1

FROM dba_hist_system_event

WHERE wait_class ‘Idle’

GROUP BY snap_id)

UNION

SELECT snap_id,

(SUM (VALUE) – SUM (value1)) / 1000000

AS background_cpu,

FROM (SELECT snap_id,

0 AS snap2,

stat_name,

VALUE,

0 AS value1

FROM dba_hist_sys_time_model

WHERE stat_name IN (‘background cpu time’)

UNION

SELECT snap_id + 1,

snap_id,

stat_name,

VALUE AS value1

FROM dba_hist_sys_time_model

WHERE stat_name IN (‘background cpu time’))

GROUP BY snap_id, stat_name

UNION

SELECT snap_id,

(SUM (VALUE) – SUM (value1)) / 1000000 AS db_cpu,

FROM (SELECT snap_id,

0 AS snap2,

stat_name,

VALUE,

0 AS value1

FROM dba_hist_sys_time_model

WHERE stat_name IN (‘DB CPU’)

UNION

SELECT snap_id + 1,

snap_id,

stat_name,

VALUE AS value1

FROM dba_hist_sys_time_model

WHERE stat_name IN (‘DB CPU’))

GROUP BY snap_id, stat_name

UNION

SELECT snap_id,

SUM (VALUE) – SUM (value1) AS lio,

FROM (SELECT snap_id,

0 AS snap2,

stat_name,

VALUE,

0 AS value1

FROM DBA_HIST_SYSSTAT

WHERE stat_name IN (‘session logical reads’)

UNION

SELECT snap_id + 1,

snap_id,

stat_name,

VALUE AS value1

FROM DBA_HIST_SYSSTAT

WHERE stat_name IN (‘session logical reads’))

GROUP BY snap_id, stat_name

UNION

SELECT snap_id,

SUM (VALUE) – SUM (value1) AS pio,

FROM (SELECT snap_id,

0 AS snap2,

stat_name,

VALUE,

0 AS value1

FROM DBA_HIST_SYSSTAT

WHERE stat_name IN (‘physical reads’)

UNION

SELECT snap_id + 1,

snap_id,

stat_name,

VALUE AS value1

FROM DBA_HIST_SYSSTAT

WHERE stat_name IN (‘physical reads’))

GROUP BY snap_id, stat_name

UNION

SELECT snap_id,

SUM (VALUE) – SUM (value1) AS uwvariable

FROM (SELECT snap_id,

0 AS snap2,

stat_name,

VALUE,

0 AS value1

FROM DBA_HIST_SYSSTAT

WHERE stat_name IN (‘&1’)

UNION

SELECT snap_id + 1,

snap_id,

stat_name,

VALUE AS value1

FROM DBA_HIST_SYSSTAT

WHERE stat_name IN (‘&1’))

GROUP BY snap_id, stat_name

)

GROUP BY snap_id

HAVING SUM (background_cpu) >= 0

ORDER BY snap_id DESC) a, DBA_HIST_SNAPSHOT B

WHERE a.SNAP_ID = b.SNAP_ID AND BEGIN_INTERVAL_TIME > SYSDATE – &2

ORDER BY 1;

MRP0: Background Media Recovery terminated with error 1237

Some days back checking an Oracle physical standby database found that the DB was some hours back than the primary database.

alter session set nls_date_format=’DD-MM-yyyy HH24:MI:SS’;

show parameter dest

select thread#,max(sequence#) from gv$log_history group by thread#;

select (a.amct-b.bmct)*24 “Hours Standby is Behind: ”

from (select max(completion_time) amct from v$archived_log) a,

(select max(completion_time) bmct from v$archived_log where applied=’YES’) b;

Hours Standby is Behind:

————————-

45.000054

The very next thing to check is what is going on with the MRP process.

select inst_id, process,status,sequence#, thread# from gv$managed_standby where process=’MRP0′;

no rows selected

So, the MRP process wasn’t running in the standby database. Let’s check the alert.log file.

MRP0: Background Media Recovery terminated with error 1237

…

ORA-01237: cannot extend datafile 13

The mount point where the datafile 13 resides is 100% full, that’s why the MRP couldn’t resize the datafile and was terminated by the instance.

In order to fix this you should increase the size of the mount point or if you have another mount point with enough free space you can do the following:

· Shutdown standby database

SQL> shutdown immediate

ORA-01109: database not open

Database dismounted.

ORACLE instance shut down.

· · Copy the datafile to the new location

#> cp –p users03.dbf /u02/oradata/test/users03.dbf

· Startup mount standby database

SQL> startup nomount

ORACLE instance started.

SQL> alter database mount standby database;

Database altered.

· · Modify “standby_file_management” parameter to manual

As per Oracle documentation:

STANDBY_FILE_MANAGEMENT enables or disables automatic standby file management. When automatic standby file management is enabled, operating system file additions and deletions on the primary database are replicated on the standby database.

SQL> alter system set standby_file_management=’MANUAL’ scope=both;

System altered.

· Rename the datafile in order to reflect the changes in the standby control file.

SQL> alter database rename file ‘/u01/oradata/test/users03.dbf’ to ‘/u02/oradata/test/users03.dbf’;

Database altered.

· Now let’s reset “standby_file_management” to AUTO.

SQL> alter system set standby_file_management=’AUTO’ scope=both;

System altered.

· And start the MRP process again.

SQL> alter database recover managed standby database disconnect from session;

Database altered.

After this MRP was able to successfully apply archive logs from primary database.

We have to be sure that every time we increase the size of a datafile in the primary database, have enough free space in the standby server to fit the new size of the datafile.

Thanks,

Alfredo

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;

–

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’

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