SQL Trace Without Storage Worries

I’ve recently been involved in working on a SR with Oracle that involved a request for SQL Trace to be provided for a session that was affect by the reported issue. Clearly not an unreasonable request, but the problem was that we did not have a reproducible test case. I’m not going to cover the details of the actual problem, as that’s not the point of the post, but if you don’t know under what conditions you are going to generate a particular Oracle error (which you believe to be incorrectly raised) then you either trace every application session that could hit the problem or you limit your scope and hope you get lucky. I try to keep “hoping to get lucky” out of my daily work, but the option of tracing every session was simply not viable as it would generate too much data for us to manage at a file system level. What we needed was “flashback tracing” in order to retrospectively enable tracing for a session once it hit the error… In steps SQL Trace Buffering.

I first became aware of this functionality when attending Tanel Poder’s hacking session at Oracle Closed World in 2010, but have since discovered that Julian Dyke covered it in his Oracle Diagnostics presentation which Julian’s website shows as first given back in 2002 at UKOUG Conference!

I suppose that fact that it’s taken nearly two years since I became aware of the functionality for me to use it in anger could point to it not needing to be on the list of things every Oracle DBA needs to know, but it is a really cool feature and hence I want to spread the word.

Buffered SQL Trace allows you to allocate some memory to holding SQL Trace data for a session. The memory buffer will be written to in a circular fashion until such time as the buffering is turned off and at which point the contents will be written to disk.

Taking directly from Julian’s presentation:

Turn on the buffering

ALTER SESSION SET EVENTS 'immediate trace name trace_buffer_on level <level>';

*Where <level> is the size in bytes of the buffer

Turn off the buffering and flush to disk

ALTER SESSION SET EVENTS 'immediate trace name trace_buffer_off';

You can also set up the buffered tracing via ORADEBUG, which is the approach I used and will be shown later.

That was half the problem solved, we had a way of having the SQL Trace data captured, but not actually written to disk for all application session, and therefore we were not in danger of filling the DIAGNOSTIC_DEST.

The second half of the problem was trigging Oracle to flush the buffered SQL Trace data to disk when we hit one of the errors that was believed to be falsely raised. This is pretty straightforward as you can instruct Oracle to perform a “diagnostic action” when a particular error is encountered. There were 4 errors that we want to dump the trace data for so the approach was as shown below:

SQL> oradebug setorapid <process id for session we wanted to trace>
SQL> oradebug session_event sql_trace wait=true, bind=true trace_buffer_on(256000)
SQL> oradebug session_event <error number> trace name trace_buffer_off; name errorstack level 3
SQL> oradebug session_event <error number> trace name trace_buffer_off; name errorstack level 3
SQL> oradebug session_event <error number> trace name trace_buffer_off; name errorstack level 3
SQL> oradebug session_event <error number> trace name trace_buffer_off; name errorstack level 3

As we wanted this for every application session it was just a case of writing a statement that would generated the above for all the relevant sessions and spooling the commands to a file that could then be run.

As a final note, if you’ve not read Tanel’s posts on the new (at 11g) diagnostic framework then have a read of these two:

The full power of Oracle’s diagnostic events, part 1: Syntax for KSD debug event handling
The full power of Oracle’s diagnostic events, part 2: ORADEBUG DOC and 11g improvements