How to enable Trace for Concurrent Program in Oracle Apps

Oracle apps provide a mechanism using which you can trace the concurrent program. The trace file contains all this information that can help to identify the problematic query. It shows the explain plan, elapsed time, CPU time, and a lot of other useful information which can help you to tune the query.

In this article, let’s see how to enable a trace for a concurrent program and generate tkprof.

1. Go to concurrent program definition and enable trace

Log in to Oracle Apps and go to Application Developer-> Concurrent Program –> Define. Query the concurrent program (Use F11 and Ctrl + F11).

Check the Enable Trace checkbox as shown below and save.

Select Enable Trace Check Box for concurrent program (Oracle Apps)
Select Enable Trace Check Box for a concurrent program (Oracle Apps)

2. Run Concurrent Program

Now, go to the responsibility where the concurrent program is registered. Navigate to View -> Request -> Submit Request and submit the concurrent program. Wait till the concurrent program completes before moving to the next steps.

3. Find Trace file path

Use the below query to get the trace file location. This is the actual physical directory on the database server. The trace file is generated at the database tier.

SELECT value 
 FROM v$parameter
 WHERE name='user_dump_dest';

4. Get the name of the trace file

The trace file name follows some naming standards. It contains oracle_process_id generated internally. Let’s see how to find out the name. Assume that the request-id 35133016.

Use the below query to get Oracle Process id.

SELECT oracle_process_id
 FROM fnd_concurrent_Requests
WHERE request_id = 35133016;

It is 121313 for the request-id 35133016.

Now login to Unix/Linux database server. Navigate to the path which you got in the previous step and run below Unix ls command.

ls *121313*
-rwxrwxrwx. 1 nobody ora_dba 180K Mar 13 02:24 TSTINSTANCE_ora_121313_APPS_0313_020936.trc

The trace file name is TSTINSTANCE_ora_121313_APPS_0313_020936.trc.

5. Format Trace file using TKPROF

Generated trace file(.trc) file contains all information and it is not human readable. You need to use the tkprof command utility to convert into a readable format.

Sample trace file

PARSING IN CURSOR #139949424689864 len=33 dep=0 uid=173 oct=47 lid=173 tim=2369959266663 hv=1991901736 ad='8c58fed08' sqlid='4g2612tvbn0j8'
EXEC #139949424689864:c=8997,e=10037,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=2369959266661
WAIT #139949424689864: nam='SQL*Net message to client' ela= 2 driver id=1952673792 #bytes=1 p3=0 obj#=34388 tim=2369959266722
WAIT #139949424689864: nam='SQL*Net message from client' ela= 260 driver id=1952673792 #bytes=1 p3=0 obj#=34388 tim=2369959266999
CLOSE #139949424689864:c=0,e=12,dep=0,type=1,tim=2369959267035
WAIT #139949424692008: nam='SQL*Net message to client' ela= 0 driver id=1952673792 #bytes=1 p3=0 obj#=34388 tim=2369959267136

Run the below command to generate TKPROF on the Unix tier.

tkprof TSTINSTANCE_ora_121313_APPS_0313_020936.trc trace.txt apps/<apps username>

Below is generated TKPROF file

TKPROF: Release - Development on Tue Mar 13 02:23:39 2018

Copyright (c) 1982, 2014, Oracle and/or its affiliates.  All rights reserved.

Trace file: TSTINSTANCE_ora_108549_APPS_0313_020936.trc
Sort options: prsela  exeela  fchela  
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing 
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call

SELECT    f.column_seq_num                          Sequence, 
          f.form_left_prompt                        Prompt,
          f.end_user_column_name                    Name,
          f.description                             Description,
          decode(f.enabled_flag,'Y','Yes','No')     ParamEnabled ,
          decode(f.display_flag,'Y','Yes','No')     ParamDisplayed ,
          f.srw_param                               Token,
          fv.flex_value_set_name                    ValueSet,
          f.default_value                           DefaultValue,
          substr(descriptive_flexfield_name,7)   ParamConcProg
FROM      fnd_descr_flex_col_usage_vl  f ,
          fnd_flex_value_sets              fv
  WHERE ( f.flex_value_set_id = fv.flex_value_set_id ) AND ( :ConcProgName = substr(descriptive_flexfield_name,7))  order by f.column_seq_num

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.70       2.91      10977      11951          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.70       2.91      10977      11951          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 173  (APPS)

Rows     Execution Plan
-------  ---------------------------------------------------
      0   SORT (ORDER BY)
      0    HASH JOIN
      0     HASH JOIN
                 'FND_FLEX_VALUE_SETS' (TABLE)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  Disk file operations I/O                        5        0.00          0.00
  db file scattered read                        754        0.01          2.23
  db file sequential read                        15        0.00          0.02
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00


Generating trace and tkprof of concurrent programs help you to pinpoint the exact SQL which is causing the program to run slow.

I hope you found this helpful. Please share and subscribe.