Thursday, February 12, 2015

Track and Trace E-Business Suite Concurrent Request - EBS Logs, O/S Process IDs, Locks

I often get asked to take a look at an Oracle eBusiness Suite concurrent request to see what it is doing, this can come from a few different angles:

What requests are currently running?
I have an operating system process that is taking too much CPU - what is it doing?
Can you tell me where the request is at? I've clicked on the log but it doesn't show anything!
My request is taking too long - can you check for blocking locks?
There are a number of strategies to track and trace where things are at for a running request, these include:

Monitor the currently running requests in fnd_concurrent_requests
Checking the v$sqlarea to see what SQL statement or PL/SQL is running
Tailing the concurrent request log / output file while it is being written to near realtime - prior to request completing
Checking for locks blocking the concurrent request

set pages 9999 feed on lines 150
col user_concurrent_program_name format a40 head PROGRAM trunc
col elapsed format 9999
col request_id format 9999999 head REQUEST
col user_name format a12
col oracle_process_id format a5 head OSPID
col inst_name format a10
col sql_text format a30
col outfile_tmp format a30
col logfile_tmp format a30

REM *********************
REM **** RAC VERSION ****
REM *********************
select /*+ ordered */ 
       fcp.user_concurrent_program_name
,      fcr.request_id
,      round(24*60*( sysdate - actual_start_date )) elapsed
,      fu.user_name
,      fcr.oracle_process_id
,      sess.sid
,      sess.serial#
,      inst.inst_name
,      sa.sql_text
,      cp.plsql_dir || '/' || cp.plsql_out outfile_tmp
,      cp.plsql_dir || '/' || cp.plsql_log logfile_tmp
from   apps.fnd_concurrent_requests fcr
,      apps.fnd_concurrent_programs_tl fcp
,      apps.fnd_concurrent_processes cp
,      apps.fnd_user fu
,      gv$process pro
,      gv$session sess
,      gv$sqlarea sa
,      sys.v_$active_instances inst
where  fcp.concurrent_program_id = fcr.concurrent_program_id
and    fcp.application_id = fcr.program_application_id
and    fcr.controlling_manager = cp.concurrent_process_id
and    fcr.requested_by = fu.user_id (+)
and    fcr.oracle_process_id = pro.spid (+)
and    pro.addr = sess.paddr (+)
and    pro.inst_id = sess.inst_id (+)
and    sess.sql_address = sa.address (+)
and    sess.sql_hash_value = sa.hash_value (+)
and    sess.inst_id = inst.inst_number (+)
and    fcr.phase_code = 'R' /* only running requests */
;

PROGRAM                                   REQUEST ELAPSED USER_NAME    OSPID        SID    SERIAL# INST_NAME  SQL_TEXT                       OUTFILE_TMP                    LOGFILE_TMP
---------------------------------------- -------- ------- ------------ ----- ---------- ---------- ---------- ------------------------------ ------------------------------ ------------------------------
Workflow Background Process               2960551       1 TCS-ADMIN     24814        130      29699 APPLPROD1  BEGIN WF_ENGINE.BACKGROUNDCONC /usr/tmp/o0068194.tmp          /usr/tmp/l0068194.tmp
                                                                                                              URRENT(:errbuf,:rc,:A0,:A1,:A2
                                                                                                              ,:A3,:A4,:A5); END;

1 row selected.

From the above we can see key information:

The running Concurrent Request Program Name and Request_ID
The database node operating system process id (OSPID) so we can monitor usage via top / iostat / vmstat
The SID / Serial in case we want to kill the session via alter system kill session '130,29699';
The instance name the database session is running on in a RAC environment
The currently running SQL text
The temporary files where concurrent request log/out is being written to via utl_file while running. These files are copied over to the Concurrent Tier $APPLCSF/$APPLOUT and $APPLLOG after completion of the request.
We can break out the above into a few queries and procedures to drill into specific information information from the core EBS tables and DBA v$ views

1. Get concurrent requests running, temp files and Operating System PID

col user_concurrent_program_name format a40 head PROGRAM trunc
col elapsed format 9999
col request_id format 9999999 head REQUEST
col user_name format a12
col oracle_process_id format a5 head OSPID
select  fcp.user_concurrent_program_name
,       fcr.request_id
,       round(24*60*( sysdate - actual_start_date )) elapsed
,       fu.user_name
,       fcr.oracle_process_id
from    apps.fnd_concurrent_requests fcr
,       apps.fnd_concurrent_programs_tl fcp
,       apps.fnd_user fu
where   fcp.concurrent_program_id = fcr.concurrent_program_id
and     fcp.application_id = fcr.program_application_id
and     fu.user_id = fcr.requested_by
and     fcr.phase_code = 'R';

PROGRAM                                   REQUEST ELAPSED USER_NAME    OSPID
---------------------------------------- -------- ------- ------------ -----
Virtuate GL OLAP Data Refresh             2960541       5 TCS-ADMIN    21681


2. Get current running sql from instance (RAC inst_id/name) where request is running

col inst_name format a10
col sql_text format a30
col module format a20

REM *********************
REM **** RAC VERSION ****
REM *********************
select sess.sid
,      sess.serial#
,      sess.module
,      sess.inst_id
,      inst.inst_name
,      sa.fetches
,      sa.runtime_mem
,      sa.sql_text
,      pro.spid
from   gv$sqlarea sa
,      gv$session sess
,      gv$process pro
,      sys.v_$active_instances inst
where  sa.address = sess.sql_address
and    sa.hash_value = sess.sql_hash_value
and    sess.paddr = pro.addr
and    sess.inst_id = pro.inst_id
and    sess.inst_id = inst.inst_number (+)

and    pro.spid = &OSPID_from_running_request;

If you're running something that has long SQL statements, get the full SQL Statement by selecting from v$sqltext_with_newlines as follows

select t.sql_text
from   gv$sqltext_with_newlines t, s.inst_id gv$session s
where  s.sid = &SID
and    s.sql_address = t.address

order by t.piece

3. Find currently spooling temp file from request

col outfile format a30
col logfile format a30
select cp.plsql_dir || '/' || cp.plsql_out outfile
,      cp.plsql_dir || '/' || cp.plsql_log logfile
from  apps.fnd_concurrent_requests cr
,     apps.fnd_concurrent_processes cp
where cp.concurrent_process_id = cr.controlling_manager
and cr.request_id = &request_id;

OUTFILE                        LOGFILE
------------------------------ ------------------------------

/usr/tmp/PROD/o0068190.tmp     /usr/tmp/PROD/l0068190.tmp

If locks are the potential problem, then drill into those:

Currently held locks per concurrent request

set lines 150
col object_name format a32
col mode_held format a15
select /*+ ordered */
       fcr.request_id
,      object_name
,      object_type
,      decode( l.block
             , 0, 'Not Blocking'
             , 1, 'Blocking'
             , 2, 'Global'
             ) status
,      decode( v.locked_mode
             , 0, 'None'
             , 1, 'Null'
             , 2, 'Row-S (SS)'
             , 3, 'Row-X (SX)'
             , 4, 'Share'
             , 5, 'S/Row-X (SSX)'
             , 6, 'Exclusive'
             , to_char(lmode)
             ) mode_held
from   apps.fnd_concurrent_requests fcr
,      gv$process pro
,      gv$session sess
,      gv$locked_object v
,      gv$lock l
,      dba_objects d
where  fcr.phase_code = 'R'
and    fcr.oracle_process_id = pro.spid (+)
and    pro.addr = sess.paddr (+)
and    sess.sid = v.session_id (+)
and    v.object_id = d.object_id (+)
and    v.object_id = l.id1 (+)
;

I also got these scripts from someone which can be useful and handy at moments / situations.

Cheers !!!

No comments:

Post a Comment