How to use strace to figure out what files are being accessed by a shell script

I had a situation where an ebs-supplied script adstrtal.sh would not start - it kept throwing error

ORA-12541: TNS:no listener

Although $TNS_ADMIN was correctly set, and sqlplus and tnsping would confirm that the database was open and the listener was up, accepting connections on the desired port.

The sqlnet.log file created in the same directory from which I executed adstrtal.sh displayed the connection being attempted:

Fatal NI connect error 12541, connecting to:
 (DESCRIPTION=(CONNECT_DATA=(SERVICE_NAME=EBS32.oric.no)(CID=(PROGRAM=sqlplus)(HOST=oric-ebsapp-utv.oric.no)(USER=ebs)))
 (ADDRESS=(PROTOCOL=TCP)(HOST=162.20.5.225)(PORT=1521)))

We are not using default port 1521, but a different port.

I then used strace to find the source of the error, like this:

strace -f -o /tmp/strace.out ./adstrtal.sh apps/****

When going through the /tmp/strace.out file, I was pointed in the right direction:

openat(AT_FDCWD, "$INST_TOP/ora/10.1.3/network/admin/EBS32_oric-ebsapp-utv_ifile.ora", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)

Turns out that adstrtal.sh was looking for a tnsnames.ora entry not in the tnsnames.ora in $TNS_ADMIN ($INST_TOP/ora/10.1.2/network/admin) but rather in $INST_TOP/ora/10.1.3/network/admin.

As soon as I had added the correct tnsnames.ora entry, the adstrtall.sh script worked.

How to trace the dbca tool

These notes are taken directly from MOS, and jotted down here so I have it readily available for the future.

To trace the DBCA, we need to perform the following.

1. Do a copy of the original dbca file in $ORACLE_HOME/bin. For example:

cp $ORACLE_HOME/bin/dbca $ORACLE_HOME/bin/dbca.ori

2. vi the dbca file in the $ORACLE_HOME/bin directory.

3. At the end of the file, look for the following line:

# Run DBCA
$JRE_DIR/bin/jre -DORACLE_HOME=$OH -DJDBC_PROTOCOL=thin -mx64m -classpath $CLASSPATH oracle.sysman.assistants.dbca.Dbca $ARGUMENTS

4. Add the following just before the -classpath in the '$JRE_DIR' line:

-DTRACING.ENABLED=true -DTRACING.LEVEL=2

5. At the end of the dbca file, the string should now look like this:

# Run DBCA
$JRE_DIR/bin/jre -DORACLE_HOME=$OH -DJDBC_PROTOCOL=thin -mx64m -DTRACING.ENABLED=true -DTRACING.LEVEL=2 -classpath $CLASSPATH oracle.sysman.assistants.dbca.Dbca $ARGUMENTS

6. To trace, run:

[host]/u01/home/usupport> dbca > dbca.out >

The output will be written to the dbca.out file.

trcsess utility arguments

trcsess  [output=output_file_name]
         [session=session_id]
         [clientid=client_id]
         [service=service_name]
         [action=action_name]
         [module=module_name]
         [trace_files]

Documentation and examples for Oracle 19c can be found here

tkprof arguments

From Oracle Support note 29012.1

 print=integer    List only the first 'integer' SQL statements.
   insert=filename  List SQL statements and data inside INSERT statements.
   sys=no           TKPROF does not list SQL statements run as user SYS.
   record=filename  Record statements found in the trace file.
   sort=option      Set of zero or more of the following sort options:

     prscnt  number of times parse was called
     prscpu  cpu time parsing
     prsela  elapsed time parsing
     prsdsk  number of disk reads during parse
     prsqry  number of buffers for consistent read during parse
     prscu   number of buffers for current read during parse
     prsmis  number of misses in library cache during parse

     execnt  number of execute was called
     execpu  cpu time spent executing
     exeela  elapsed time executing
     exedsk  number of disk reads during execute
     exeqry  number of buffers for consistent read during execute
     execu   number of buffers for current read during execute
     exerow  number of rows processed during execute
     exemis  number of library cache misses during execute

     fchcnt  number of times fetch was called
     fchcpu  cpu time spent fetching
     fchela  elapsed time fetching
     fchdsk  number of disk reads during fetch
     fchqry  number of buffers for consistent read during fetch
     fchcu   number of buffers for current read during fetch
     fchrow  number of rows fetched

     userid  userid of user that parsed the cursor

How to run RMAN with debug information

Tested with Oracle 12.2

For example, to trace a duplicate database session, I have put the following into a file called "run_duplication.cmd":

spool trace to run_duplication.trc
spool log to run_duplication.log
set echo on;
debug on;


connect target sys/password@sourcedb
connect auxiliary sys/password@auxdb

run{
allocate channel c1 type disk;
allocate channel c2 type disk;
allocate auxiliary channel aux1 type disk;
allocate auxiliary channel aux2 type disk;
configure device type disk parallelism 2;
DUPLICATE DATABASE "sourcedb.mydomain.com" TO auxdb
FROM ACTIVE DATABASE
TABLESPACE TOOLS
USING COMPRESSED BACKUPSET;
}
exit

When you execute your rman script:

rman cmdfile='run_duplication.cmd'

your log and trace files will be generated in your working directory.

How to avoid the error Can't locate Data/Dumper.pm in @INC during installation of AHF

During installation of ahf, I received the following error:

Extracting AHF to /u01/ahf/oracle.ahf
Can't locate Data/Dumper.pm in @INC (@INC contains: /usr/local/lib64/perl5 /usr/local/share/perl5 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_per l /usr/lib64/perl5 /usr/share/perl5 . /u01/ahf/oracle.ahf/tfa/bin /u01/ahf/oracle.ahf/tfa/bin/common /u01/ahf/oracle.ahf/tfa/bin/modules /u01/ahf/oracle.a hf/tfa/bin/common/exceptions) at /u01/ahf/oracle.ahf/tfa/bin/common/tfactlshare.pm line 1350, line 1.
BEGIN failed--compilation aborted at /u01/ahf/oracle.ahf/tfa/bin/common/tfactlshare.pm line 1350, line 1.
Compilation failed in require at /u01/ahf/oracle.ahf/tfa/bin/tfasetup.pl line 107, line 1.
BEGIN failed--compilation aborted at /u01/ahf/oracle.ahf/tfa/bin/tfasetup.pl line 107, line 1.

Solution: Install missing packages:

su -
yum install perl-Data-Dumper

At this point, you need to uninstall AHF:

tfactl uninstall

Then cleanup old files. Go to the directory where you attempted to install AHF;

cd /u01/tfa
rm -rf oracle.ahf

Go to the directory where the zipped file has been extracted, and run the installation again:

/u01/oracle/patch/AHF
./ahf_setup

What is the 100046 trace event anyway?

The 100046 event is a Process Trace event. These trace certain system operations continuously until the tracing is canceled. The results are written to a trace files.

When do I start running 10046 events, then?

* When a process is having problems that can be identified, and you can control which session (or sessions) need to be traced without impacting other things.
* When users can clearly point to processes that need help, and you cannot clearly see what it is other means (statspack, v$sqlarea, etc)


Source: Burlesson Consulting

How to solve SP2-0618: Cannot find the Session Identifier. Check PLUSTRACE role is enabled

Logged in as the user owning the objects, you are getting the following error when trying to use the autotrace feature:

SP2-0618: Cannot find the Session Identifier.  Check PLUSTRACE role is enabled
SP2-0611: Error enabling STATISTICS report

Solution: run the necessary scripts first:

conn / as sysdba
@$ORACLE_HOME/sqlplus/admin/plustrce.sql
grant plustrace to scott;

conn scott/password

@$ORACLE_HOME/rdbms/admin/utlxplan.sql
exit

After this is done, the errors should no longer appear.

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

How to find the default trace file for the session

Use the v$diag_info view, which "describes the state of Automatic Diagnostic Repository (ADR) functionality"

SELECT value
FROM   v$diag_info
WHERE  name = 'Default Trace File';

Example output:

VALUE
/u01/oracle/diag/rdbms/proddb01/proddb01/trace/proddb01_ora_45082.trc

A real easy way to start a trace of your current session is

exec dbms_monitor.session_trace_enable;

Then execute your statements

When you're done, stop tracing with

exec dbms_monitor.session_trace_disable;

How to use trace event 10046

ALTER SESSION SET max_dump_file_size = unlimited;
ALTER SESSION SET tracefile_identifier = 'normal_run_with_trace_10046';
ALTER SESSION SET statistics_level = ALL;
ALTER SESSION SET events '10046 trace name context forever, level 12';

Your SQL statement(s) here

ALTER SYSTEM SET EVENTS '10046 trace name context off';
EXIT

Alternatively, use the oradebug utility:

select s.sid,s.serial#,p.spid
from v$session s, v$process p 
where sid = 29
and s.paddr = p.addr

Output:

SID	SERIAL#	SPID
29	9	24510662

Check that the process is indeed there:

prodserver1>ps -ef | grep 24510662
  ora11g 24510662        1   0 17:24:42      -  0:00 oraclemagr (LOCAL=NO)
prodserver1>proctree 24510662
  24510662    oraclemagr (LOCAL=NO)

Enable tracing on the operating system process, inside sqlplus:

SQL> oradebug setospid 24051998
Oracle pid: 420, Unix process pid: 24051998, image: oracle@ystu032ma
SQL> oradebug unlimit
SQL> oradebug event 10046 trace name context forever, level 12

When done, disable tracing:

SYS@magr SQL> oradebug setospid 24051998
Oracle pid: 420, Unix process pid: 24051998, image: oracle@ystu032ma

SQL> oradebug unlimit
SQL> oradebug event 10046 trace name context forever, level 12

You can now parse the trace file produced through tkprof:

tkprof mytracefile.trc mytracefile.out sys=yes waits=yes sort=exemis

For an extensive list of commands to be used with tkprof, simply type tkprof at the prompt.

An excellent note on 10046 trace event is called "How To Collect 10046 Trace (SQL_TRACE) Diagnostics for Performance Issues (Doc ID 376442.1)".

Another great note on tracing in general is "Tracing Enhancements Using DBMS_MONITOR (In 10g, 11g and Above) (Doc ID 293661.1)"

- both available on Oracle Supports site.

How to disable an event parameter in the database

During an Upgrade from 11.2.0.3 to 11.2.0.4 I had to remove an event-parameter in the database.

The syntax for this is:

alter system set event="10852 trace name context off" scope=spfile;

How to enable tracing for a session

To enable trace for a session:

execute dbms_monitor.session_trace_enable(session_id => 127,
                                  serial_num => 29,
                                  waits => TRUE,
                                  binds => FALSE);

Disable as follows:

execute dbms_monitor.session_trace_disable(127,29);


Alternatively, use the dbms_system package:

execute dbms_system.set_sql_trace_in_session(17,45171,true);


When finished, disable tracing:


dbms_system.stop_trace_in_session(17,45171);


To enable the writing of a trace file for your current session:

execute dbms_session.set_sql_trace(true);

Note that the user needs the ALTER SESSION privilege to perform tracing:

GRANT ALTER SESSION TO scott;

Note 293661.1 published on MOS is another great source to use the dbms_monitor package efficiently.

How to name a trace file to find it more easily

alter session set tracefile_identifier = 'your string for easy recognition here';

For example:

alter session set tracefile_identifier = 'data_pump_import_trace.trc';

If you trace your session now, your file will now be much easier to find in the udump directory (pre 11g) or in the diagnostic_dest/trace directory (11g and onwards)