Access to Trace files in Oracle 12c

 

With the advent of the tools like SQL Monitor and gather plan statistics hint to diagnosis the performance issue, the need to access the trace file got reduced with the latest version of Oracle database.

 

However there are still few cases where we need to access the trace files, not to investigate for the performance related activity, but for few error stack in the execution.

 

Here is a quick demo of that from a recent application, were we worked on.

 

demo@ORA12C> create or replace procedure monthly_load

  2  as

  3     l_activity_from varchar2(8);

  4     l_activity_to   varchar2(10);

  5     c sys_refcursor;

  6     r emp%rowtype;

  7  begin

  8     open c for select * from emp ;

  9     loop

 10             fetch c into r;

 11             exit when c%notfound;

 12             l_activity_from := to_char( r.hiredate,'mm/dd/yyyy' );

 13     end loop;

 14     close c;

 15  end;

 16  /

 

Procedure created.

 

demo@ORA12C>

 

 

The above procedure is to process the data from EMP table, let’s have that scheduled as a Job in the database.

 

 

demo@ORA12C> variable n number

demo@ORA12C> exec dbms_job.submit( :n , 'begin monthly_load; end;' );

 

PL/SQL procedure successfully completed.

 

demo@ORA12C> print n

 

         N

----------

       241

 

demo@ORA12C> commit;

 

Commit complete.

 

demo@ORA12C> select job,next_date,total_time,broken,failures

  2  from dba_jobs

  3  where job = 241 ;

 

       JOB NEXT_DATE   TOTAL_TIME B   FAILURES

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

       241 05-FEB-2019          1 N          1

 

The job has failed once, since it got started. But we don’t have any clue about why that got failed.

 

The right place to look into these kind of failures would be the default Trace file location mapped to this instance, which is available through V$DIAG_INFO (a new dictionary introduced in Oracle 11g)

 

demo@ORA12C> select value

  2  from v$diag_info

  3  where name ='Diag Trace' ;

 

VALUE

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

D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c\trace

 

 

Now we are able to get the location, but we don’t have the access to the Database server to look into the trace file.

 

Starting with Oracle 12c that got simplified, we don’t even need the access to server, the trace file and its contents are available through two new V$ tables.

 

·         V$DIAG_TRACE_FILE – will list out all the trace file names that got generated over the period of time in above identified location, along with its ADR home.

 

·         V$DIAG_TRACE_FILE_CONTENTS – will list out the contents for the specified trace file name and its ADR home.

 

Now we get into V$DIAG_TRACE_FILE to see those recently generated trace files on this database server.

 

 

demo@ORA12C> select adr_home,trace_filename,change_time

  2  from v$diag_trace_file

  3  order by change_time desc

  4  fetch first 5 rows only

  5  /

 

ADR_HOME                                           TRACE_FILENAME                 CHANGE_TIME

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

D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c    ora12c_j000_10412.trc          05-FEB-19 01.18.59.000 PM +05:30

D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c    ora12c_j000_7988.trc           05-FEB-19 01.16.54.000 PM +05:30

D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c    ora12c_m000_12908.trc          05-FEB-19 01.15.16.000 PM +05:30

D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c    ora12c_m000_4824.trc           05-FEB-19 01.05.13.000 PM +05:30

D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c    ora12c_m000_12420.trc          05-FEB-19 01.03.12.000 PM +05:30

 

 

The trace file name are usually of this format <Instance_name>_<process_name/ORA>_<Server_process_id>.Trc, Since we ran the stored procedure from Jobs, the trace file name will have Job queue id’s in there (like J000 or J001 as such), so we will go with the first listed trace file name(since that got the change time very close to our job execution timing).

 

 

Reading the first trace file from V$DIAG_TRACE_FILE_CONTENTS will produce an output like this

 

 

demo@ORA12C> col payload format a100

demo@ORA12C> select payload

  2  from v$diag_trace_file_contents

  3  where trace_filename ='ora12c_j000_10412.trc'

  4  and adr_home ='D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c'

  5  order by line_number

  6  /

 

PAYLOAD

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

Trace file D:\APP\VNAMEIT\VIRTUAL\diag\rdbms\ora12c\ora12c\trace\ora12c_j000_10412.trc

Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

Build label:    RDBMS_12.2.0.1.0_WINDOWS.X64_170210.4

Windows NT Version V6.1 Service Pack 1

ORACLE_HOME =  D:\app\Vnameit\virtual\product\12.2.0\dbhome_1

Node name           : LT035221

CPU                 : 4 - type 8664, 2 Physical Cores

Process Affinity    : 0x0x0000000000000000

Memory (Avail/Total): Ph

Instance name: ora12c

Redo thread mounted by this instance: 1

Oracle process number: 33

Windows thread id: 10412, image: ORACLE.EXE (J000)

 

 

*** 2019-02-05T13:18:59.475721+05:30

 

*** SESSION ID:(133.52274) 2019-02-05T13:18:59.475721+05:30

*** CLIENT ID:() 2019-02-05T13:18:59.475721+05:30

*** SERVICE NAME:(SYS$USERS) 2019-02-05T13:18:59.475721+05:30

*** MODULE NAME:() 2019-02-05T13:18:59.475721+05:30

*** ACTION NAME:() 2019-02-05T13:18:59.475721+05:30

*** CLIENT DRIVER:() 2019-02-05T13:18:59.475721+05:30

 

ORA-12012: error on auto execute of job 241

ORA-06502: PL/SQL: numeric or value error: character string buffer too small

ORA-06512: at "DEMO.MONTHLY_LOAD", line 12

ORA-06512: at line 1

 

26 rows selected.

 

The highlighted piece of contents, give us the clue about where and what the error is about along with its line no.

 

Now fixing that error in the stored procedure.

 

 

demo@ORA12C> create or replace procedure monthly_load

  2  as

  3     l_activity_from varchar2(20);

  4     l_activity_to   varchar2(10);

  5     c sys_refcursor;

  6     r emp%rowtype;

  7  begin

  8     open c for select * from emp ;

  9     loop

 10             fetch c into r;

 11             exit when c%notfound;

 12             l_activity_from := to_char( r.hiredate,'mm/dd/yyyy' );

 13     end loop;

 14     close c;

 15  end;

 16  /

 

Procedure created.

 

And now re-running the job explicitly, got completed successfully.

 

demo@ORA12C> select job,next_date,total_time,broken,failures,last_date

  2  from dba_jobs

  3  where job = 241 ;

 

       JOB NEXT_DATE   TOTAL_TIME B   FAILURES LAST_DATE

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

       241 05-FEB-2019          2 N          6

 

demo@ORA12C> exec dbms_job.run(241);

 

PL/SQL procedure successfully completed.

 

demo@ORA12C> select job,next_date,total_time,broken,failures,last_date

  2  from dba_jobs

  3  where job = 241 ;

 

no rows selected

 

demo@ORA12C>