Monitor Session Activity Using Trace File (using tkprof)

Trace file are used to trace session/instance level activity. It is also called diagnostic file which are created by the server process. Now I am used DBMS_MONITOR to trace session level activity.

=============================================

C:\Users\rajib.pradhan>sqlplus /nolog

SQL*Plus: Release 11.2.0.1.0 Production on Thu Apr 16 15:47:31 2015

Copyright (c) 1982, 2010, Oracle.  All rights reserved.

SQL> conn HR/HR@192.168.56.100:1521/ORCLN1
Connected.
SQL> select SYS_CONTEXT('USERENV','SID') from dual;

SYS_CONTEXT('USERENV','SID')
--------------------------------------------------------------------------------
57

=============================================

[oracle@OEL64BN1 oracle]$ sqlplus /nolog

SQL*Plus: Release 11.2.0.3.0 Production on Thu Apr 16 15:47:09 2015

Copyright (c) 1982, 2011, Oracle.  All rights reserved.

SQL> conn /as sysdba

Connected.

SQL> SELECT S.SID,S.SERIAL#, P.TRACEFILE

FROM V$SESSION S, V$PROCESS P

WHERE  S.PADDR = P.ADDR

AND S.SID = 57;  2    3    4

       SID    SERIAL#

---------- ----------

TRACEFILE

--------------------------------------------------------------------------------

        57       7889

/u01/app/oracle/diag/rdbms/orcln1/orcln1/trace/orcln1_ora_20927.trc

SQL> EXEC DBMS_MONITOR.SESSION_TRACE_ENABLE(57,7889,true,true);

PL/SQL procedure successfully completed.

=============================================

SQL> SELECT LAST_NAME, SALARY, DEPARTMENT_NAME

  2  FROM EMPLOYEES E, DEPARTMENTS D

  3  WHERE E.DEPARTMENT_ID=D.DEPARTMENT_ID;

LAST_NAME                     SALARY DEPARTMENT_NAME

------------------------- ---------- ------------------------------

Whalen                          4400 Administration

Hartstein                      13000 Marketing

Fay                             6000 Marketing

Raphaely                       11000 Purchasing

Colmenares                      2500 Purchasing

Khoo                            3100 Purchasing

Baida                           2900 Purchasing

Tobias                          2800 Purchasing

106 rows selected.

SQL>

=============================================

SQL> EXEC DBMS_MONITOR.SESSION_TRACE_DISABLE(57,7889);

PL/SQL procedure successfully completed.

SQL> exit

Disconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options

[oracle@OEL64BN1 oracle]$ tkprof /u01/app/oracle/diag/rdbms/orcln1/orcln1/trace/orcln1_ora_20927.trc /u01/app/oracle/trace_output.txt

TKPROF: Release 11.2.0.3.0 - Development on Thu Apr 16 15:49:17 2015

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

[oracle@OEL64BN1 oracle]$

[oracle@OEL64BN1 oracle]$ cat trace_output.txt

TKPROF: Release 11.2.0.3.0 - Development on Thu Apr 16 15:49:17 2015

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

Trace file: /u01/app/oracle/diag/rdbms/orcln1/orcln1/trace/orcln1_ora_20927.trc

Sort options: default

********************************************************************************

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 LAST_NAME, SALARY, DEPARTMENT_NAME

FROM EMPLOYEES E, DEPARTMENTS D

WHERE E.DEPARTMENT_ID=D.DEPARTMENT_ID

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        9      0.00       0.00          0         18          0         106

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total       11      0.00       0.00          0         18          0         106

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 84

Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation

---------- ---------- ----------  ---------------------------------------------------

       106        106        106  MERGE JOIN  (cr=18 pr=0 pw=0 time=663 us cost=6 size=3286 card=106)

        27         27         27   TABLE ACCESS BY INDEX ROWID DEPARTMENTS (cr=12 pr=0 pw=0 time=702 us cost=2 size=432 card=27)

        27         27         27    INDEX FULL SCAN DEPT_ID_PK (cr=6 pr=0 pw=0 time=404 us cost=1 size=0 card=27)(object id 76362)

       106        106        106   SORT JOIN (cr=6 pr=0 pw=0 time=1087 us cost=4 size=1605 card=107)

       107        107        107    TABLE ACCESS FULL EMPLOYEES (cr=6 pr=0 pw=0 time=106 us cost=3 size=1605 card=107)

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       9        0.00          0.00

  SQL*Net message from client                     8        0.06          0.34

********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        9      0.00       0.00          0         18          0         106

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total       11      0.00       0.00          0         18          0         106

Misses in library cache during parse: 0

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       9        0.00          0.00

  SQL*Net message from client                     8        0.06          0.34

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        0      0.00       0.00          0          0          0           0

Execute      0      0.00       0.00          0          0          0           0

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        0      0.00       0.00          0          0          0           0

Misses in library cache during parse: 0

    1  user  SQL statements in session.

    0  internal SQL statements in session.

    1  SQL statements in session.

********************************************************************************

Trace file: /u01/app/oracle/diag/rdbms/orcln1/orcln1/trace/orcln1_ora_20927.trc

Trace file compatibility: 11.1.0.7

Sort options: default

       1  session in tracefile.

       1  user  SQL statements in trace file.

       0  internal SQL statements in trace file.

       1  SQL statements in trace file.

       1  unique SQL statements in trace file.

      62  lines in trace file.

       0  elapsed seconds in trace file.

[oracle@OEL64BN1 oracle]$