Wednesday, August 26, 2015

Data pump sql trace

7. How to get SQL trace files of the Data Pump processes ?

For troubleshooting specific situations, it may be required to create a SQL trace file for an Export Data Pump or Import Data Pump job. These SQL trace files can be created by setting Event 10046 for a specific process (usually the Worker process). Note that these SQL trace files can become very large, so ensure that there is enough free space in the directory that is specified by the init.ora/spfile initialization parameter BACKGROUND_DUMP_DEST.
event 10046, level 1 = enable standard SQL_TRACE functionality
event 10046, level 4 = as level 1, plus trace the BIND values
event 10046, level 8 = as level 1, plus trace the WAITs
event 10046, level 12 = as level 1, plus trace the BIND values and the WAITs
Remarks:
  • level 1: lowest level tracing - not always sufficient to determine cause of errors;
  • level 4: useful when an error in Data Pump's worker or master process occurs;
  • level 12: useful when there is an issue with Data Pump performance.
When creating a level 8 or 12 SQL trace file, it is required that the init.ora/spfile initialization parameter TIMED_STATISTICS is set to TRUE before the event is set and before the Data Pump job is started. The performance impact of setting this parameter temporary to TRUE is minimal. The SQL trace files that were created with level 8 or 12 as especially useful for investigating performance problems.
Example:
-- For Event 10046, level 8 and 12: ensure we gather time related statistics:

CONNECT / as sysdba
SHOW PARAMETER timed_statistics

NAME                              TYPE        VALUE
--------------------------------- ----------- ---------------------------
timed_statistics                  string      FALSE

ALTER SYSTEM SET timed_statistics = TRUE SCOPE = memory;

-- Now set the event and start the Data Pump job


-- To set the value back to the default:

ALTER SYSTEM SET timed_statistics = FALSE SCOPE = memory; 

7.1. Create a standard SQL_TRACE file (level 1).

If the output of standard SQL_TRACE functionality is sufficient (i.e.: neither bind values nore waits details are needed), then this SQL tracing can be activated with the Data Pump parameter trace. To activate standard SQL tracing, use the value 1.
Example:
-- Trace Worker process (400300) with standard SQL_TRACE functionality (1):

% expdp system/manager DIRECTORY=my_dir DUMPFILE=expdp_f.dmp \
LOGFILE=expdp_f.log TABLES=scott.emp TRACE=400301 
Note that this level of tracing is usually not sufficient for tracing Data Pump when an error occurs or when there is an issue with Data Pump performance. For tracing Data Pump when an error occurs use level 4, and when there is an issue with Data Pump performance use level 12 (see sections below).

7.2. Activate SQL_TRACE on specific Data Pump process with higher trace level.

If a specific Data Pump process needs to traced, and more SQL_TRACE details are required, and it is not required to trace the start of the job, then the Event 10046 with the desired level can also be set on the process that needs to be traced (usually the Worker process).
Example:
- Start the Data Pump job, e.g.:

% expdp system/manager DIRECTORY=my_dir DUMPFILE=expdp_f%U.dmp \  
LOGFILE=expdp_f.log FILESIZE=2G FULL=y


-- In SQL*Plus, obtain Data Pump process info:
CONNECT / as sysdba

set lines 150 pages 100 numwidth 7
col program for a38
col username for a10
col spid for a7
select to_char(sysdate,'YYYY-MM-DD HH24:MI:SS') "DATE", s.program, s.sid,  
       s.status, s.username, d.job_name, p.spid, s.serial#, p.pid  
  from v$session s, v$process p, dba_datapump_sessions d 
 where p.addr=s.paddr and s.saddr=d.saddr; 

DATE                PROGRAM                                    SID STATUS
------------------- -------------------------------------- ------- --------
2007-10-19 08:58:41 ude@celclnx7.us.oracle.com (TNS V1-V3)     158 ACTIVE
2007-10-19 08:58:41 oracle@celclnx7.us.oracle.com (DM00)       143 ACTIVE
2007-10-19 08:58:41 oracle@celclnx7.us.oracle.com (DW01)       150 ACTIVE

USERNAME   JOB_NAME                       SPID    SERIAL#     PID
---------- ------------------------------ ------- ------- -------
SYSTEM     SYS_EXPORT_FULL_01             17288        29      18
SYSTEM     SYS_EXPORT_FULL_01             17292        50      22
SYSTEM     SYS_EXPORT_FULL_01             17294        17      23  
In the example output above we see that the Data Pump Master process (DM00) has SID: 143 and serial#: 50 and the Data Pump Worker process (DW01) has SID: 150 and serial#: 17. These details can be used to activate SQL tracing in SQL*Plus with DBMS_SYSTEM.SET_EV, e.g.:
-- In SQL*Plus, activate SQL tracing with DBMS_SYSTEM and SID/SERIAL# 
-- Syntax: DBMS_SYSTEM.SET_EV([SID],[SERIAL#],[EVENT],[LEVEL],'')

-- Example to SQL_TRACE Worker process with level 4 (Bind values):  
execute sys.dbms_system.set_ev(150,17,10046,4,'');

-- and stop tracing:
execute sys.dbms_system.set_ev(150,17,10046,0,''); 


-- Example to SQL_TRACE Master Control process with level 8 (Waits): 
execute sys.dbms_system.set_ev(143,50,10046,8,''); 

-- and stop tracing: 
execute sys.dbms_system.set_ev(143,50,10046,0,'');
The example output of the query above also shows that the Data Pump Master process (DM00) has OS process Id: 17292 and the Data Pump Worker process (DW01) has OS process Id: 17294. With this information, it is also possible to use 'oradebug' in SQL*Plus to activate SQL tracing for those processes, e.g.:
-- In SQL*Plus, activate SQL tracing with ORADEBUG and the SPID:

-- Example to SQL_TRACE Worker process with level 4 (Bind values):
oradebug setospid 17294
oradebug unlimit
oradebug event 10046 trace name context forever, level 4
oradebug tracefile_name

-- Example to SQL_TRACE Master Control process with level 8 (Waits):
oradebug setospid 17292 
oradebug unlimit 
oradebug event 10046 trace name context forever, level 8 
oradebug tracefile_name 


-- To stop the tracing:
oradebug event 10046 trace name context off
Either DBMS_SYSTEM.SET_EV or 'oradebug' can be used to create a Data Pump trace file.

7.3. Place complete database in SQL_TRACE with specific level. 
It is possible that there is not enough time to activate tracing on a specific Data Pump process because an error occurs at an early stage of the job, or that the the Data Pump process needs to be traced from the beginning. In those cases, the Event 10046 with the desired level has to be set in SQL*Plus at database level, and the Data Pump job has to be started afterwards. When the job completes, unset the event again.
Example:
-- Activate SQL tracing database wide,
-- Be careful: all processes will be traced! 
--
-- never do this on production unless a maintenance window
-- once issued in PROD you may not be able to stop if load is high
-- careful with directories filling up
--

CONNECT / as sysdba  
ALTER SYSTEM SET EVENTS '10046 trace name context forever, level 4';  


- Start the Export Data Pump or Import Data Pump job, e.g.:

% expdp system/manager DIRECTORY=my_dir DUMPFILE=expdp_f.dmp \  
LOGFILE=expdp_f.log TABLES=scott.emp


-- Unset event immediately after Data Pump job ends:

ALTER SYSTEM SET EVENTS '10046 trace name context off';
Be careful though: the steps above will result in SQL tracing on all processes, so only use this method if no other database activity takes place (or hardly any other activity), and when the Data Pump job ends relatively quickly.

7.4. Analyze the SQL trace files and create a TKPROF output file.
If the SQL trace files were created with level 1 or 4 then we are usually interested in the statements (and their bind variables). Example scenario: Data Pump aborts with a specific error. When investigating those kind of errors, it makes sense to compress the complete trace file and upload the compressed file.

If the SQL trace files were created with level 8 or 12 then we are usually interested in the timing of the statements (and their wait events). Example scenario: there is an presumptive performance issue during a Data Pump job. These SQL trace files can become very large and the tkprof output after analyzing the files are in most cases more meaningful. When investigating those kind of errors, it makes sense to upload the tkprof output files only.
Example:
-- create standard tkprof output files for Data Pump Master and Worker SQL traces:

% cd /oracle/admin/ORCL/BDUMP
% tkprof orcl_dm00_17292.trc tkprof_orcl_dm00_17292.out waits=y sort=exeela
% tkprof orcl_dw01_17294.trc tkprof_orcl_dw01_17294.out waits=y sort=exeela
For details about Event 10046 and tkprof, see also:
Note:21154.1 "EVENT: 10046 "enable SQL statement tracing (including binds/waits)"
Note:32951.1 "Tkprof Interpretation"





************************************************************************************
My notes

Run expdp
go to db and run following query

select to_char(sysdate,'YYYY-MM-DD HH24:MI:SS') "DATE", s.program, s.sid, s.serial#,   
       s.status, s.username, d.job_name, p.spid, p.pid    
  from v$session s, v$process p, dba_datapump_sessions d   
 where p.addr=s.paddr and s.saddr=d.saddr;   

get sid and serial for dw0,dw1,dm0 processes

and

execute in the following fashion to enable trace

1st number sid
2nd number serial
3rd number 10046
4th number level(4,8,12) 
execute sys.dbms_system.set_ev(1381,55489,10046,8,'');  
execute sys.dbms_system.set_ev(1897,18963,10046,8,'');  
execute sys.dbms_system.set_ev(864,34228,10046,8,'');  


after completion turn off trace by changing the 4th number to zero


No comments:

Post a Comment

Featured Post

Apply Patch 22191577 latest GI PSU to RAC and DB homes using Opatch auto or manual steps

Patch 22191577: GRID INFRASTRUCTURE PATCH SET UPDATE 11.2.0.4.160119 (JAN2016) Unzip the patch 22191577 Unzip latest Opatch Version in or...