Tuesday, December 22, 2009

Using dbms_system.ksdddt to write customized trace file


[oracle@rh4 sql]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.1.0 Production on Tue Dec 22 12:06:51 2009

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


Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> set echo on
SQL> @dbms_utility_demo.sql
SQL> declare
2 elapsed_time_t1 number;
3 elapsed_time_t2 number;
4 cpu_time_t1 number;
5 cpu_time_t2 number;
6 begin
7 elapsed_time_t1 := dbms_utility.get_time;
8 cpu_time_t1 := dbms_utility.get_cpu_time;
9 dbms_stats.gather_schema_stats('SPOTLIGHT');
10 elapsed_time_t2 := dbms_utility.get_time;
11 cpu_time_t2 := dbms_utility.get_cpu_time;
12 sys.dbms_system.ksdddt; -- Prints the date stamp to the target file (trace,alertlog, or both)
13 -- 1st argument of dbms_system.ksdwrt
14 -- 1: Write to the standard trace file
15 -- 2: Write to the alert log
16 -- 3: Write to both files at once
17 sys.dbms_system.ksdwrt(3,'=== Elapsed Time: '||
18 to_char((elapsed_time_t2-elapsed_time_t1)/100) ||
19 ' sec CPU: '||
20 to_char((cpu_time_t2-cpu_time_t1)/100) ||
21 ' sec');
22 end;
23 /

PL/SQL procedure successfully completed.

SQL>
SQL>
SQL> oradebug setmypid
Statement processed.
SQL> oradebug tracefile_name
/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30185.trc
SQL> exit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options



[oracle@rh4 sql]$ cat /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30185.trc
Trace file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30185.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1
System name: Linux
Node name: rh4.ncs.com.sg
Release: 2.6.18-128.1.10.el5
Version: #1 SMP Thu May 7 10:39:21 EDT 2009
Machine: i686
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 32
Unix process pid: 30185, image: oracle@rh4.ncs.com.sg (TNS V1-V3)


*** 2009-12-22 12:07:07.982
*** SESSION ID:(20.210) 2009-12-22 12:07:07.982
*** CLIENT ID:() 2009-12-22 12:07:07.982
*** SERVICE NAME:(SYS$USERS) 2009-12-22 12:07:07.982
*** MODULE NAME:(sqlplus@rh4.ncs.com.sg (TNS V1-V3)) 2009-12-22 12:07:07.982
*** ACTION NAME:() 2009-12-22 12:07:07.982

=== Elapsed Time: 1 sec CPU: .97 sec

*** 2009-12-22 12:07:15.051
Processing Oradebug command 'setmypid'

*** 2009-12-22 12:07:15.051
Oradebug command 'setmypid' console output:

*** 2009-12-22 12:07:20.178
Processing Oradebug command 'tracefile_name'

*** 2009-12-22 12:07:20.178
Oradebug command 'tracefile_name' console output:
/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30185.trc
[oracle@rh4 sql]$



[oracle@rh4 sql]$ tail -n 4 /u01/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log
Tue Dec 22 10:28:37 2009
SMCO started with pid=19, OS id=9591
Tue Dec 22 12:07:07 2009
=== Elapsed Time: 1 sec CPU: .97 sec