This blog contains experience gained over the years of implementing (and de-implementing) large scale IT applications/software.

Oracle Tracing & Interpreting Traces – Notes

Oracle Trace Details; abstracted from MYOS Note ID 376442.1 and added flair.

This section details various ways of actually getting an Oracle session level trace file, interpreting the trace file and useful links to MYOS notes about the trace data:

/* Oracle 10g+ trace session using DBMS_MONITOR includes BINDS and WAITS */
/* However, this is limited to one session only */
EXEC DBMS_MONITOR.SESSION_TRACE_ENABLE(session_id =>1181,
                                       serial_num =>7218,
                                       waits      => TRUE,
                                       binds      => TRUE);

EXEC DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id => 1181,

                                        serial_num => 7218);

/* Oracle 9i Trace excludes BINDS and WAITS */
/* Again, limited to one session only */
EXEC DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(16,38779,TRUE);
EXEC DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(16,38779,FALSE);

/ * Trace your own session with BINDS and WAITS */
ALTER SESSION SET SQL_TRACE=TRUE;
or
ALTER SESSION SET EVENTS ''10046 trace name context forever, level 12'';

/* Trace using OraDebug with BINDS and WAITS */
connect / as sysdba
oradebug setorapid 9834  << Insert your Oracle PID here.
oradebug unlimit
oradebug event 10046 trace name context forever,level 12

/* And switch it off again */
oradebug event 10046 trace name context off

/* Logon trigger trace for Oracle 9i+ */
/* This is the best way to trace when using Oracle Forms because it allows for multiple spontaneous sessions.
I can also confirm that this traces sessions executed on a database link */
/* First you must grant ALTER SESSION to the user */
GRANT ALTER SESSION TO <USERNAME> ;

/ * Now create the trigger */
CREATE OR REPLACE TRIGGER SYS.set_trace
AFTER LOGON ON DATABASE
WHEN (USER like '&USERNAME')
DECLARE
lcommand varchar(200);
BEGIN
EXECUTE IMMEDIATE 'alter session set statistics_level=ALL';
EXECUTE IMMEDIATE 'alter session set max_dump_file_size=UNLIMITED';
EXECUTE IMMEDIATE 'alter session set events ''10046 trace name context forever, level 12''';
END set_trace;
/

/* Simply disable the trigger when done */
ALTER TRIGGER SYS.SET_TRACE DISABLE;

/* List non-system users, very useful when attempting to trace a session */
SELECT username,sid,serial#,status,module
   FROM v$session
 WHERE username is not null
      AND username <> 'SYS'
 ORDER BY username;

/* Enable the trace on ALL current sessions of a specific user in the system. */
set serveroutput on size 10000;
DECLARE
BEGIN
FOR c1_row IN (SELECT sid,serial#
FROM v$session where username = '<<A USER>>') LOOP
DBMS_OUTPUT.PUT_LINE('Enabling trace for session: '||c1_row.sid||' serial#: '||c1_row.serial#);
DBMS_MONITOR.SESSION_TRACE_ENABLE(session_id => c1_row.sid, serial_num => c1_row.serial# ,waits => TRUE, binds => TRUE);
DBMS_OUTPUT.PUT_LINE('Tracing for session: '||c1_row.sid||' serial#: '||c1_row.serial#);
END LOOP;
EXCEPTION
WHEN OTHERS THEN
DBMS_OUTPUT.PUT_LINE(SUBSTR(SQLERRM,1,250));
END;
/
select username,sql_trace from v$session order by username;

/* Disable the trace on ALL current sessions of a specific user in the system. */
set serveroutput on size 10000;
DECLARE
BEGIN
FOR c1_row IN (SELECT sid,serial#
FROM v$session where username = '<<A USER>>') LOOP
DBMS_OUTPUT.PUT_LINE('Disabling trace for session: '||c1_row.sid||' serial#: '||c1_row.serial#);
DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id => c1_row.sid, serial_num => c1_row.serial#);
DBMS_OUTPUT.PUT_LINE('Tracing disabled for session: '||c1_row.sid||' serial#: '||c1_row.serial#);
END LOOP;
EXCEPTION
WHEN OTHERS THEN
DBMS_OUTPUT.PUT_LINE(SUBSTR(SQLERRM,1,250));
END;
/
select username,sql_trace from v$session order by username;

/* Run TKProf as sysdba with EXPLAIN plan included */
/* See TKProf Interpretation (9i and above) [ID 760786.1] */
tkprof <tracefile>.trc /tmp/<tracefile>.trc.tk explain=" / as sysdba"

/* TKProf sorting by highest elapsed time */
tkprof <tracefile>.trc /tmp/<tracefile>.trc.tk sort=fchela,exeela,prsela

Once you have your trace file and you have run it through TKProf and are still struggling, you may need to read it raw.
Check out the following MYOS articles:
“Interpreting Raw SQL_TRACE and DBMS_SUPPORT.START_TRACE output [ID 39817.1]”.

The excellent but slightly unheard of “Oracle Performance Diagnostic Guide (OPDG) [ID 390374.1]”.

Oracle Index Rows Per Leaf Block

The query below can be used to obtain the number of rows per index leaf block.
You will need to know the index name, the table name that the index references, the pk column in the index and the object id for the index:

SELECT object_id
from user_objects
WHERE object_name = 'MGMT_VERSIONS_PK';

SELECT rows_per_block, count(*) blocks
FROM (
      SELECT /*+ cursor_sharing_exact
                 dynamic_sampling(0)
                 no_monitoring
                 no_expand
                 index_ffs(serv_inst,ix_serv_inst)
                 noparallel_index(serv_inst,ix_serv_inst)
              */
             sys_op_lbid(349440,              -- << INDEX OBJECT ID HERE
                                 'L',rowid) block_id,
             count(*) rows_per_block
        FROM MGMT_VERSIONS                    -- << TABLE NAME HERE
       WHERE COMPONENT_NAME IS NOT NULL       -- << INDEX COL NAME HERE
      GROUP BY sys_op_lbid(349440,            -- << INDEX OBJECT ID HERE
                           'L',rowid)

     )
GROUP BY rows_per_block;

This is useful for determining sparse index blocks:
https://www.dba-oracle.com/t_sys_op_lbid_index_node_density.htm

It could be combined with this script (https://jonathanlewis.wordpress.com/segment-scans/) which helps to detect full table scans and index fast full scans:

select
       owner,

       object_type,
       object_name,
       obj#,
       subobject_name,

       tablespace_name,
       value scans
from
       V$segment_statistics
where
       statistic_name = 'segment scans'
  and  value != 0
order by owner, value;

(When I get time, I’ll combine it and post it here).

Running the first SQL statement, then checking if the table has “high” segment scans would then give a good indication if the index is used frequently for large multi-block operations and is very sparse (block wise) and potentially up for a re-build.

Gathering Oracle Statistics – the SAP way

Gathering stats on a table in an Oracle database, can significantly change the SQL excution plan.
In some cases this can be detrimental to the system performance.
I have seen this in a real production system, where the indexed column was 38 characters long.  The system had just been upgraded from 9i, the original table stats carried over and left up to Oracle.
Performance was dreadful, the 9i stats had been refreshed but not re-created.

See SAP note 365480 (“CBO: Field filled with leading “0” aligned to left”).
It suffered from an Oracle “bug” (773462) where only the first 32 characters are used to measure the distinct number of values for the column.  In a 38 character field, left padded with zeros, using the index can cause a problem.
If we had removed all stats and re-created them, no problem, as Oracle 10g would have probably generated histograms.
However, the real issue was that the stats shouldn’t have been there according to DBSTATC.

NOTE: SAP notes say to specifically disable the default Oracle 10g/11g GATHER_STATS_JOB.

As noted, if you let Oracle gather statistics it overrides the settings in the SAP DBSTATC table.
The DBSTATC table (see transaction DB20) controls where stats are gathered and how stats are gathered.
In actual fact, this is why you sometimes see “Harmful statistics” in the BR*Connect DBcheck results.

The stats are gathered using the Oracle DBMS_STATS package with Netweaver 7.0’s version of BR*Tools (more specifically, BR*Connect).

Below are some SQL and PL/SQL commands useful for analysing statistics problems in a SAP Oracle 10g environment.

/* Check if gather stats auto-job is enabled */
SELECT JOB_NAME,
OWNER,
ENABLED,
PROGRAM_NAME,
TO_CHAR(last_start_date,'DD-MM-YYYY HH24:MI:SS') last_start_date
FROM DBA_SCHEDULER_JOBS
WHERE JOB_NAME='GATHER_STATS_JOB';

/* Get GATHER_STATS_JOB program details */
SELECT PROGRAM_TYPE,
PROGRAM_NAME,
PROGRAM_ACTION
FROM dba_scheduler_programs
WHERE PROGRAM_NAME='GATHER_STATS_PROG';

/* Get the last time the GATHER_STATS_JOB ran and log info */
set linesize 400
col ADDITIONAL_INFO FORMAT A100
col LOG_DATE FORMAT a20
col JOB_NAME FORMAT A20
col RUN_DURATION FORMAT A25
col ACTUAL_START_DATE FORMAT A40
SELECT log_id,
actual_start_date,
run_duration,
job_name,
status,
log_date,
additional_info
FROM dba_scheduler_job_run_details
WHERE owner='SYS'
AND job_name='GATHER_STATS_JOB';

/* VERIFY STATS ON A COLUMN */
SELECT num_distinct,
density,
num_buckets,
sample_size,
avg_col_len,
histogram
FROM dba_tab_col_statistics
WHERE table_name = &TABNAME
AND column_name=&COLNAME;

/* VERIFY STATS ON A TABLE */
SELECT sample_size,
TO_CHAR(last_analyzed,'DD-MM-YYYY HH24:MI:SS') last_analzed,
global_stats,
user_stats,
stattype_locked,
stale_stats
FROM dba_tab_statistics
WHERE table_name = &TABNAME;

/* VERIFY HISTOGRAMS ON A TABLE */
SELECT *
FROM dba_tab_histograms
WHERE table_name=&TABNAME;

/* GATHER COLUMN STATS FOR A COLUMN ONLY */
BEGIN
       DBMS_STATS.GATHER_TABLE_STATS (
                                OWNNAME => 'SAPR3',
                                TABNAME => '< A TABLE>',
                                METHOD_OPT => 'FOR COLUMNS < A COLUMN> SIZE AUTO');
END;

/* GATHER TABLE STATS USING ESTIMATE 10% */
BEGIN
        DBMS_STATS.GATHER_TABLE_STATS (
                                 OWNNAME => 'SAPR3',
                                 TABNAME => '< A TABLE>',
                                 METHOD_OPT => 'FOR ALL COLUMNS SIZE AUTO',
                                 ESTIMATE_PERCENT => 10);
END;

/* ORACLE'S DEFAULT JOB TO GATHER STATS */
dbms_stats.gather_database_stats_job_proc;

/* DELETE ALL THE TABLE STATS CASCADE TO INDEXES and COLUMNS */
BEGIN
        DBMS_STATS.DELETE_TABLE_STATS (
                                   OWNNAME => 'SAPR3',
                                   TABNAME => '< A TABLE>',
                                   cascade_parts => TRUE,
                                   cascade_columns => TRUE,
                                   cascade_indexes => TRUE);
END;

/* DELETE COLUMN STATS ONLY */
BEGIN
         DBMS_STATS.DELETE_COLUMN_STATS (
                                   OWNNAME => 'SAPR3',
                                   TABNAME => '< A TABLE>',
                                   COLNAME => '< A COLUMN>',
                                   FORCE => TRUE);
END;

Oracle Core: Essential Internals for Troubleshooting

Whilst shopping on Amazon this morning I noticed that Jonathan’s book is up for pre-order.
The price gurantee from Amazon is very reasonable, so I’ve pre-ordered.

Should be a good read and more importantly a good weapon in any DBAs problem analysis methodology (is “weapon” the best way to describe it? Wouldn’t that make Jonathan an arms dealer?).
Of course it doesn’t mean I can possibly absorb everything from the book, but most of the time I find that it’s not that you know how to do it, it’s that you know it can be done.

https://www.amazon.co.uk/gp/product/1430239549

Oracle Storage Sub-system Load Stress Testing

Whilst looking around for an Oracle equivalent stress testing freebie (like SQLIO for SQL Server), I found out about ORION (ORacle I/O Numbers).
It’s been about for a while and can be used to stress test storage systems.
It’s a simple single binary file that generates I/O load on a storage system using Oracle’s I/O call stack.
No need to install Oracle at all!

Unfortunately for me, it only works with file systems that have Async I/O enabled.
I did not, and therefore could not use ORION.
When I finally get time to install Oracle on my new Oracle Enterprise Linux 6.1 environment, I’ll give it a go.