Tracing Tip #JoelKallmanDay

I don’t really do tips because I often see simple tips that have a specific purpose being abused; but it’s a special day in the Oracle community so here’s a quick tip in tribute to a great sharer.

I’ve been doing some work with datapump recently and needed to get a better picture of how various processes were hanging together. But when you call expdp or impdp you don’t have direct control over all the processes that might start running – and that covers a DMxx (datapump master) process, multiple DWxx (datapump worker) processes and Pnnn (parallel execution) processes.

As a quick, dirty, and brutal starting point (on a dedicated test system) I just enabled tracing for all the processes I wanted to follow using a variant of the new(er) syntax, specifying process naming patterns:

Here’s what I did for 11g (see Footnote):

alter system set events 'sql_trace {process:pname = p00 | dw | dm } level=8';

This enabled tracing whenever a process with a name (v$process.pname) starting with ‘P00’, ‘DM’ or ‘DW’ started running. (I restricted myself to parallel processes p000 – p009 because I had set a very small value for parallel_max_servers.)

I was a little surprised to discover that this didn’t work when I tried to use it in a 19c PDB:

SQL> alter system set events 'sql_trace {process:pname = dw | dm | p0} level=8';
alter system set events 'sql_trace {process:pname = dw | dm | p0} level=8'
*
ERROR at line 1:
ORA-49100: Failed to process event statement [sql_trace {process:pname = dw | dm | p0} level=8]
ORA-49601: syntax error: found "|": expecting one of: ":" etc..

So I read the detail in the error message and changed the statement (after two wrong guesses) to:

alter system set events 'sql_trace {process:pname = dw | process:pname=dm | process:pname=p00} level=8';

This worked.

Footnote

I’ve updated the SQL I used for the 11g trace – the process parameter used to look like this: “process:pname = dw | dm | p00”, but this didn’t actually work and only appeared to work because (I assume) of an earlier trace call I had done.

Strangely – and I haven’t tested this idea to destruction – there seems to be some way in which the ordering of the lengths of the pname values affect which ones are used. When I did some repeat tests (by which time I’d restarted the instance) I found two options in 11g that would trace the processes I wanted traced:

• “process:pname = p00 | dw | dm”
• “process:pname = dw | dm | p”

You’ll notice that in both cases the process name “templates” are in order of descending length. The second option is highly undesirable, of course, since this also enables tracing of pmon.

There’s room for further investigation, but I’ve done what I wanted to do, got a note of the anomaly, and don’t expect to do something like this again on 11g.

I will point out, however, that I got the original basic form for the process parameter by descending through the oradebug doc tree in 11g and 12cR1; but the content reported from oradebug doc in 12cR2 shows the form that I reported for 19c. If you check through MOS, though you’ll find a third form which works in 11g (and, possibly, later):

alter system set events 'sql_trace {process : pname = dw | pname = dm | pname = p00} level=8';