How to set up End-to-End tracing

Based on Performing Application Tracing in Oracle Database 12.1 SQL Tuning Guide

Add the following to your application code:

ALTER SESSION SET TRACEFILE_IDENTIFIER = 'PublishInfoModule';
exec DBMS_APPLICATION_INFO.SET_CLIENT_INFO (client_info=>'BroadcastPublish');
exec DBMS_APPLICATION_INFO.SET_MODULE(module_name=>'Broadcast', action_name=>NULL);

Right before a SELECT statement:

exec DBMS_APPLICATION_INFO.SET_ACTION(action_name=>'GetRows');

Right before an UPDATE statement:

exec DBMS_APPLICATION_INFO.SET_ACTION(action_name=>'MarkAsPublished');

Enable statistics gathering for End-to-End Tracing. Note that the names of service, module and actions are case sensitive, and need to be referred to as they are found in v$sessions and v$services:

exec DBMS_MONITOR.SERV_MOD_ACT_STAT_ENABLE(service_name=>'proddb01',module_name=>'Broadcast',action_name=>'BroadcastPublish');
exec  DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name=>'proddb01',module_name=>'Broadcast',action_name   =>'MarkAsPublished', WAITS=>TRUE,binds=>TRUE,plan_stat=>'FIRST_EXECUTION');

Go to the trace file location, found as a subdirectory in the location specified by diagnostic_dest:

show parameter diagnostic_dest

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
diagnostic_dest                      string      /u01/oracle

In my case:

cd /u01/oracle/diag/rdbms/proddb01/proddb01/trace

You should now find files named according to your SET TRACEFILE_IDENTIFIER command previously:

-rw-r-----  1 oracle dba 732258822 Feb 26 07:49 alert_proddb01.log
-rw-r-----  1 oracle dba     24398 Feb 26 08:21 proddb01_ora_54248.trc
-rw-r-----  1 oracle dba    120418 Feb 26 08:21 proddb01_ora_54248.trm
-rw-r-----  1 oracle dba   3077570 Feb 26 08:26 proddb01_ora_35967_PublishInfoModule.trm
-rw-r-----  1 oracle dba 133643579 Feb 26 08:26 proddb01_ora_35967_PublishInfoModule.trc

Disable statistics gathering, and disable the trace:

exec DBMS_MONITOR.SERV_MOD_ACT_STAT_DISABLE(service_name=>'proddb01',module_name=>'Broadcast',action_name=>'BroadcastPublish');
exec DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(service_name=>'proddb01',module_name=>'Broadcast',action_name   =>'MarkAsPublished');

You can now format these using tkprof:

tkprof /u01/oracle/diag/rdbms/proddb01/proddb01/trace/proddb01_ora_35967_PublishInfoModule.trc
       /u01/oracle/admin/proddb01/sql/tuning/tkprof2/tkprof_2.out 
       waits=yes 
       sort=EXEDSK 
       insert=insert.sql 
       sys=no 
       explain=broadcaster/**** 
       record=tkprof_sqlstmts.sql 
       table=sys.PLAN_TABLE$
  

The output will be the file /u01/oracle/admin/proddb01/sql/tuning/tkprof2/tkprof_2.out

tkprof has many options and you should take some time to get familiarized with the tool before you start. A key point is to minimize the information so that you find what's relevant to you.

For a shortlist of commands, see this post.


If you have many trace files generated by multiple sessions, you need to use another tool called trcsess to merge all these into one single trace file that you then format with tkprof, which I will demonstrate next.

In the following example, I am creating tracefiles for a specific action set in the application code.
The application code uses this code:

ALTER SESSION SET TRACEFILE_IDENTIFIER = 'Reporter';

BEGIN 
  DBMS_APPLICATION_INFO.SET_ACTION(action_name=>'getNextOutlook/actions/report');
END;
/

So I will execute

cd trace
trcsess output=getNextOutlook.out action='getNextOutlook/actions/report' pks_*report*.trc

Which will search all trace files matching the wildkard pks_*report*.trc and generate the file getNextOutlook.out

DST_UPGRADE_STATE set to DATAPUMP(1) when running preupgrade_fixups.sql

During the preparation for a 12.2 upgrade, I found that the preupgrade-tool reported about an incomplete DST upgrade, where DST_UPGRADE_STATE was set to "DATAPUMP(1)".

The preupgrade tool reported:

$ORACLE_HOME/jdk/bin/java -jar /tmp/preupgradetool/preupgrade.jar TERMINAL TEXT
Report generated by Oracle Database Pre-Upgrade Information Tool Version
12.2.0.1.0

Upgrade-To version: 12.2.0.1.0

=======================================
Status of the database prior to upgrade
=======================================


Complete any pending DST update operation before starting the database
     upgrade.

     There is an unfinished DST update operation in the database.  It's
     current state is: DATAPUMP(1)

     There must not be any Daylight Savings Time (DST) update operations
     pending in the database before starting the upgrade process.
     Refer to My Oracle Support Note 1509653.1 for more information.

Then, running the preupgrade_fixups.sql:

Fixup
Check Name                Status  Further DBA Action
----------                ------  ------------------
purge_recyclebin          Passed  None
pending_dst_session       Failed  Manual fixup required.
invalid_objects_exist     Failed  None
dictionary_stats          Passed  None

Result:

SYS@proddb01 SQL> r
  1  SELECT PROPERTY_NAME, SUBSTR(property_value, 1, 30) value
  2  FROM DATABASE_PROPERTIES
  3  WHERE PROPERTY_NAME LIKE 'DST_%'
  4* ORDER BY PROPERTY_NAME

PROPERTY_NAME                            VALUE
---------------------------------------- --------------------
DST_PRIMARY_TT_VERSION                   18
DST_SECONDARY_TT_VERSION                 14
DST_UPGRADE_STATE                        DATAPUMP(1)

According to https://blog.oracle-ninja.com/2013/09/17/stuck-timezone-upgrades-and-smart-scans the solution would be, as sysdba:

1. ALTER SESSION SET EVENTS '30090 TRACE NAME CONTEXT FOREVER, LEVEL 32';
2. exec dbms_dst.unload_secondary;

I tried this, with the following result:

SYSproddb01 SQL> SELECT PROPERTY_NAME, SUBSTR(property_value, 1, 30) value FROM DATABASE_PROPERTIES WHERE PROPERTY_NAME LIKE 'DST_%' ORDER BY PROPERTY_NAME;

PROPERTY_NAME                            VALUE
---------------------------------------- --------------------
DST_PRIMARY_TT_VERSION                   18
DST_SECONDARY_TT_VERSION                 0
DST_UPGRADE_STATE                        NONE

I also executed

ALTER SESSION SET EVENTS '30090 TRACE NAME CONTEXT FOREVER, OFF';

just to be on the safe side.

Finally, run preupgrade_fixups.sql again:

Check Name                Status  Further DBA Action
----------                ------  ------------------
purge_recyclebin          Passed  None
pending_dst_session       Passed  None
invalid_objects_exist     Failed  None
dictionary_stats          Passed  None

PL/SQL-prosedyren ble fullført.

And the test is passed, and you are ready to upgrade

Roles necessary to administer and view the Unified Audit Trail

Oracle 12c provides two new roles for auditing purposes:

AUDIT_ADMIN for audit configuration/administration
AUDIT_VIEWER for viewing and analyzing audit data

The following can role was granted by myself to allow a senior developer to view the audit information generated in a test database:

grant audit_viewer to scott;

https://docs.oracle.com/database/121/DBSEG/release_changes.htm#DBSEG000
https://docs.oracle.com/database/121/DBSEG/auditing.htm#DBSEG617

How to use dbms_application_info to create session details

The package dbms_application_info lets you add supplemental information in your session, which can be picked up in the V$SESSION view.

A very useful package, which I have used many times myself, but for some reason it is rarely used by Developers. It should typically be called before beginning a transaction in order to register and name a transaction/client_info/module for later use when measuring performance across an application.

exec dbms_application_info.set_client_info('Step one.');
exec dbms_application_info.set_module('module1','gettrades');

Here is an example where I was troubleshooting a "hanging" delete statement for a customer.
Turned out the problem was concurrency locks:

select SID,SERIAL#,SQL_ID,STATUS,osuser,machine,schemaname,MODULE,ACTION,CLIENT_INFO,LOGON_TIME,EVENT,STATE,FINAL_BLOCKING_SESSION "blocking"
from v$session 
WHERE schemaname='SALES'
AND STATUS='ACTIVE'
UNION
select SID,SERIAL#,SQL_ID,STATUS,osuser,machine,schemaname,MODULE,ACTION,CLIENT_INFO,LOGON_TIME,EVENT,STATE,FINAL_BLOCKING_SESSION "blocking"
from v$session 
where SID = (SELECT FINAL_BLOCKING_SESSION FROM V$SESSION WHERE schemaname='SALES' AND STATUS='ACTIVE');

In the resulting two rows, the first one is mine, the second is the blocking session:

SID	SERIAL#	SQL_ID	STATUS	OSUSER	MACHINE	SCHEMANAME	MODULE	ACTION	CLIENT_INFO	LOGON_TIME	EVENT	STATE	blocking
32	4759	5jg1839cyxzgh	ACTIVE	oracle	mytestserver.com	SALES	DELETE MODULE	DELETE_SCHEMA	Delete XSD.	15.02.2018 12:04:43	library cache lock	WAITING	2285
2285	48625	g3bc37vx8fy3u	INACTIVE	JIM	COMPANY\PC-157	SALES	SQL*Plus			14.02.2018 14:08:57	SQL*Net message from client	WAITING	NULL

For more information, check the documentation
Tracing Enhancements Using DBMS_MONITOR (In 10g, 11g and Above) (Doc ID 293661.1) at My Oracle Support.

How to view default settings for dbms_stats

Thanks to the author of the blog "Thinking out loud" for writing this piece of code. It makes it easy to view the default settings that applies when gathering schema statistics:

SELECT 
  username,
  DBMS_STATS.get_prefs(ownname=>USER,pname=>'INCREMENTAL') incr,
  DBMS_STATS.get_prefs(ownname=>USER,pname=>'GRANULARITY') grty,
  DBMS_STATS.get_prefs(ownname=>USER,pname=>'STALE_PERCENT') "stale%",
  DBMS_STATS.get_prefs(ownname=>USER,pname=>'ESTIMATE_PERCENT') "estimate%",
  DBMS_STATS.get_prefs(ownname=>USER,pname=>'CASCADE') cascade,
  DBMS_STATS.get_prefs(pname=>'METHOD_OPT') method_opt,
  DBMS_STATS.get_prefs(pname=>'DEGREE') degree,
  DBMS_STATS.get_prefs(pname=>'CONCURRENT') CONC
FROM dba_users
WHERE username IN ('BILL','BOB','SCOTT','JANE')
ORDER BY username;

USERNAME	INCR	GRTY	STALE%	ESTIMATE%	CASCADE	METHOD_OPT	DEGREE	CONC
BILL	TRUE	AUTO	10	DBMS_STATS.AUTO_SAMPLE_SIZE	DBMS_STATS.AUTO_CASCADE	FOR ALL COLUMNS SIZE AUTO	DBMS_STATS.DEFAULT_DEGREE	OFF
BOB	TRUE	AUTO	10	DBMS_STATS.AUTO_SAMPLE_SIZE	DBMS_STATS.AUTO_CASCADE	FOR ALL COLUMNS SIZE AUTO	DBMS_STATS.DEFAULT_DEGREE	OFF
SCOTT	TRUE	AUTO	10	DBMS_STATS.AUTO_SAMPLE_SIZE	DBMS_STATS.AUTO_CASCADE	FOR ALL COLUMNS SIZE AUTO	DBMS_STATS.DEFAULT_DEGREE	OFF
JANE	TRUE	AUTO	10	DBMS_STATS.AUTO_SAMPLE_SIZE	DBMS_STATS.AUTO_CASCADE	FOR ALL COLUMNS SIZE AUTO	DBMS_STATS.DEFAULT_DEGREE	OFF

Why doesn't dbms_stats.set_schema_prefs seem to work?

When trying to alter the default settings for statistics gathering on partitioned tables, I had troubles setting schema-level preferences using dbms_stats.set_schema_prefs:

exec dbms_stats.set_schema_prefs('SCOTT','INCREMENTAL','TRUE');

PL/SQL procedure successfully completed.

But when you check if the setting has been accepted using dbms_stats.get_prefs, it still seem to be set to FALSE:

SELECT  DBMS_STATS.get_prefs(ownname=>'SCOTT',pname=>'INCREMENTAL') "INCREMENTAL" FROM DUAL;

INCREMENTAL
--------------------
FALSE

I found the following note by Maria Colgan:

http://www.nocoug.org/download/2011-11/Maria_Colgan_Optimizer_Statistics.pdf

which states that set_schema_prefs only applies to current objects in the schema and that new objects will pick up global preferences instead.

So according to the note, I was doing the right thing, after all I was trying to alter the default behaviour for the optimizer when working on existing objects.

How come the new setting didn't seem to stick?

In my case, a global change was acceptable, so I could try to set the parameter globally instead, using set_global_prefs:

BEGIN
  dbms_stats.set_global_prefs('INCREMENTAL','TRUE');
END;
/

PL/SQL procedure successfully completed.

After that, the setting certainly seem to stick:

SELECT  DBMS_STATS.get_prefs(ownname=>'SCOTT',pname=>'INCREMENTAL') "INCREMENTAL" FROM DUAL;

INCREMENTAL
--------------------
TRUE

Maria points out that a global change like the one above will apply to all existing objects as well as any new objects.

My conlution is that dbms_stats.get_prefs will report the settings that applies for future objects only, not existing ones. If that is the case, the output of the report is ambiguous, as it will give the DBA the impression that he/she has not made the change permanent.

To view the default settings for a particular schema, see this post.

Oracle Documentation on the subject is here

How to display processes in Linux in a tree-like fashion

The simplest way to see operating system processes and their sub-processes is to use

ps aufx

Output will look something like the following, where I have used the Oracle agent and its child proceesses to illustrate the formatted process tree:

oracle   33037  0.0  0.0 162892 15600 ?        S    Jan29   0:06 /u01/oracle/product/agent13c/agent_13.2.0.0.0/perl/bin/perl /u01/oracle/product/agent13c/agent_13.2.0.
oracle   33127  0.3  0.9 2714968 313308 ?      Sl   Jan29   5:01  \_ /u01/oracle/product/agent13c/agent_13.2.0.0.0/oracle_common/jdk/bin/java -Xmx128M -XX:MaxPermSize=
oracle   48285  0.0  0.0 331652 23220 ?        S    15:41   0:00      \_ /u01/oracle/product/agent13c/agent_13.2.0.0.0/perl/bin/perl /u01/oracle/product/agent13c/agent

Alternatively, use pstree:

pstree -p
pstree -p 12345

where 12345 is the process id.

For example, the Oracle agent is started via a perl script, and spawns multiple java child processes:

 ps -ef |grep agent | grep perl
oracle    12345      1  0 08:53 ?        00:00:00 /sw/oracle/product/agent13c/GoldImage/agent_13.4.0.0.0/perl/bin/perl /sw/oracle/product/agent13c/GoldImage/agent_13.4.0.0.0/bin/emwd.pl agent /sw/oracle/product/agent13c/agent_inst/sysman/log/emagent.nohup

Use the process id as an argument to pstree to see all the child processes process 12345 has spawned (output abbreviated):

pstree -p 12345
perl(12345)───java(32690)─┬─{java}(32691)
                          ├─{java}(32692)