Oracle trace events hunting : KST tracing/ X$TRACE

This  is my third blog post about Oracle trace events hunting.For the previous one please check part1 and part2.

When we take a look at the TRACE event which is the Main event to control the UTS tracing  we notice that it have a memory option which mean activate the tracing in-memory (If possible)

Capture 250

In my Write consistency and DML restart blog post i have described a way to track DML restart using the following code :

alter system set events 'trace[DML] {callstack: fname dmlTrace} disk=high trace("DML restarted sqlid : %\n", sqlid())';

We could modify the code and activate tracing to memory using memory=high clause for example :

alter system set events 'trace[DML] {callstack: fname dmlTrace} disk=high , memory=high trace("DML restarted sqlid : %\n", sqlid())';

We can then extract the result from X$TRACE table :

Capture 251

We can see here that the component that we are tracing is named DML . Several  components support this feature and some of them have tracing enabled by default.

Capture 252

We can notice here that db_trace component have an event number set compared to the other components.

Capture 253

This different event numbers are known as the KST Tracing events which seem to fall under the db_trace component and Tanel Poder already described them a while ago :

This events can be enabled using  (Some of them are enabled by default) :

  • alter system set “_trace_events”=’event#:level:OPID’;

Example :

alter system set “_trace_events”=’10000-10999:1:ALL’; (Enable all events at level 1 for all process)

  • ALTER TRACING ENABLE “event#:level:OPID”;

PS: it seem not possible to enable or disable only a specific KST trace event using the alter system/session set events ‘TRACE[db_trace]  ‘ event syntax.

Using the TRACE event we can manipulate the db_trace component tracing and therefore all the enabled KST trace events  by for example redirecting the trace to disk.

alter system set event= 'trace[db_trace] disk=highest, memory=disable' scope=spfile;

After restarting the instance :

on memory (the db_trace component is no more traced in memory) :

Capture 254

Capture 255

On the disk  (the db_trace component is now traced to disk) :

Capture 256

Capture 257

As the blog post is entitled Oracle trace events hunting i written a prototype script to help extracting checked kst trace event from a target oracle kernel function  event_extractor.sh :

Capture 264

Ok let’s analyze the output (Using http://orafun.info/ for function name and the mapping file dbgdChkEventIntV_event_list_extended.txt created on my previous post) :

The function kslwtectx (kernel service latching & post-wait wait interface end context/wait ?? check for Events (The script is limited so sometimes it cannot determine the value of some register like ECX:0/ECX:ffffffffffffff58)   :

  • Trace (EDX:1160001) for component db_trace (ECX:2050031) and KST event (10005)
  • wait_event(EDX:2160002)
  • sql_trace (EDX:216000e)

The function kslwtbctx ( kernel service latching & post-wait wait interface begin context/wait ?? check for Events

  • EVENT : 10808
  • Trace (EDX:1160001) for component db_trace (ECX:2050031) and KST event (10005)

Capture 261

The function ksonfy  (kernel service operations ?? ) check for Events

  • Trace (EDX:1160001) for component db_trace (ECX:2050031) and KST event (10420)

Capture 260

The function kccwbp (kernel cache controlfile write block physically ) check for Events

  • EVENT : 10209,10213,10214,10461,10463
  • Trace (EDX:1160001) for component db_trace (ECX:2050031) and KST event (10021)

Capture 259

That’s it 🙂

Download : event_extractor.sh

One thought on “Oracle trace events hunting : KST tracing/ X$TRACE

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s