Tuning Oracle Queries with an Optimizer Trace

Query tuning is a combination of art, science and intuition. Elegant tuning solutions are art, based on science, that science using two of Oracle’s events, 10046 and 10053. Which one is more beneficial depends on the query and the ‘bad’ execution plan. A 10046 trace can show what Oracle is waiting on and where time is being spent in the execution phase of running a query. Sometimes, however, the waits and elapsed time breakdowns aren’t enough, which is where the 10053 trace can be extremely helpful. Note that this article takes one particular situation and gives abbreviated steps in solving it; it’s not meant to be a treatise on the subject nor a detailed case study. With that in mind let’s look at a plan where that event can provide much-needed information.

Queries using nested subqueries can take a number of paths to return data; one possibility involves what Oracle calls ‘subquery unnesting’, a process where Oracle re-writes the nested query into an unnested join with the intent that this will improve data access and thus query performance. This can be done for several nested subqueries, resulting in one or more NESTED LOOP joins in the execution plan. This is where the road can take a less than desirable turn; joins consume time, making the query execution longer than it probably should be. If the query in question is a ‘one-off’, run once, maybe twice in a day, this may not be a real problem as a few seconds here and there won’t throw off the regular day’s work. If on the other hand, this is a regularly run statement, the longer run times can stack up on each other and cause delays in processing, and as the old addage states: “Time is money.” Since the query plan won’t give details on how Oracle eventually generated it, one course of action is setting the 10053 event in the current session and executing the problem statement.

The first step in tuning is to obtain the current execution plan and see if it makes ‘sense’. A query with joins will likely produce NESTED LOOP JOIN or HASH JOIN steps. In this case the plan produced a NESTED LOOPS SEMI step that on the face of it, made no sense as the query contained no join conditions as originally written. This could be a clue that the optimizer did something different and possibly unexpected with the plan. That is exactly what prompted this investigation, which used a 10053 event trace to ‘track down’ what the optimizer chose to do. This in turn, caused a slight rewrite of the query to include the necessary hints to ‘nudge’ the optimizer toward a more efficient plan.

Setting event 10053 is not a difficult task; let’s look at a script that does this and then executes several SELECT statements before turning the 10053 ‘switch’ off (unfortunately the actual queries can’t be published as they are proprietary so placeholders will be used):

alter session set tracefile_identifier='MAILQUEUE';
alter system set events = '10053 trace name context forever, level 2';

[First query statement here]

[Second query statement here]

[Third query statement here]

[Fourth query statement here]

alter system set events = '10053 trace name context off';

The important parts of the above example are the lines prior to any query statements, which turn on the 10053 event and set a trace file identifier so the generated trace file can be easily identified, and the statement after the queries have run, which stops the 10053 event. Unlike the 10046 event, which is more easily read after processing through the tkprof utility, the 10053 trace file needs no additional processing. It can be a bit daunting at first since it’s like no other trace file most DBAs have seen. Let’s go through the example, using the actual trace file generated by the unobfuscated script, and see what it reveals.

The beginning of the trace file provides some basic information on the environment and provides query ‘signatures’ that the optimizer uses to identify query and subquery blocks:

Trace file ....
Oracle Database 12c Enterprise Edition Release - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
System name:	SunOS
Node name:	...
Release:	5.10
Version:	Generic_150400-61
Machine:	sun4v
Instance name: ...
Redo thread mounted by this instance: 1
Oracle process number: 1134
Unix process pid: 22631, image: oracle@... (TNS V1-V3)

Query Block Registry:
SEL$2 0x77a10ca0 (PARSER)
  SEL$F5BB74E1 0x77a198b0 (VIEW MERGE SEL$1; SEL$2) [FINAL]
SEL$1 0x77a198b0 (PARSER)
  SEL$F5BB74E1 0x77a198b0 (VIEW MERGE SEL$1; SEL$2) [FINAL]

    call(in-use=12456, alloc=347568), compile(in-use=95008, alloc=158520), execution(in-use=15312, alloc=16200)

End of Optimizer State Dump
Dumping Hints
====================== END SQL Statement Dump ======================
*** SESSION ID:(758.2581) 2018-08-21 09:40:23.286
Registered qb: SEL$1 0x77a198b0 (PARSER)
  signature (): qb_name=SEL$1 nbfros=1 flg=0
    fro(0): flg=4 objn=68513 hint_alias="DQ"@"SEL$1"

Registered qb: SEL$2 0x7751be68 (PARSER)
  signature (): qb_name=SEL$2 nbfros=1 flg=0
    fro(0): flg=4 objn=69663 hint_alias="WPV"@"SEL$2"

Registered qb: SEL$3 0x7751b188 (PARSER)
  signature (): qb_name=SEL$3 nbfros=1 flg=0
    fro(0): flg=4 objn=10290765 hint_alias="MRE"@"SEL$3"

SPM: statement not found in SMB
SPM: capture of plan baseline is OFF

This begins the portion of the trace file of interest, including the query [not posted due to confidentiality concerns] and the legend of abbreviations:

Automatic degree of parallelism (AUTODOP)
Automatic degree of parallelism is disabled: Parameter.
kkopqSetForceParallelProperties: Hint:no
Query: compute:yes forced:no forceDop:0
kkopqSetDopReason: Reason why we chose this DOP is: table property.
table property forces parallelism

Global Manual DOP: 1 - Rounded?: no
PM: Considering predicate move-around in query block SEL$1 (#0)
Predicate Move-Around (PM)

----- Current SQL Statement for this session (sql_id=*************) -----
[ Removed for confidentiality reasons ]
The following abbreviations are used by optimizer trace.
CBQT - cost-based query transformation
JPPD - join predicate push-down
OJPPD - old-style (non-cost-based) JPPD
FPD - filter push-down
PM - predicate move-around
CVM - complex view merging
SPJ - select-project-join
SJC - set join conversion
SU - subquery unnesting
OBYE - order by elimination
OST - old style star transformation
ST - new (cbqt) star transformation
CNT - count(col) to count(*) transformation
JE - Join Elimination
JF - join factorization
CBY - connect by
SLP - select list pruning
DP - distinct placement
VT - vector transformation
qb - query block
LB - leaf blocks
DK - distinct keys
LB/K - average number of leaf blocks per key
DB/K - average number of data blocks per key
CLUF - clustering factor
NDV - number of distinct values
Resp - response cost
Card - cardinality
Resc - resource cost
NL - nested loops (join)
SM - sort merge (join)
HA - hash (join)
IOTFRSPEED - I/O transfer speed
IOSEEKTIM - I/O seek time
SREADTIM - average single block read time
MREADTIM - average multiblock read time
MBRC - average multiblock read count
MAXTHR - maximum I/O system throughput
SLAVETHR - average slave I/O throughput
dmeth - distribution method
  1: no partitioning required
  2: value partitioned
  4: right is random (round-robin)
  128: left is random (round-robin)
  8: broadcast right and partition left
  16: broadcast left and partition right
  32: partition left using partitioning of right
  64: partition right using partitioning of left
  256: run the join in serial
  0: invalid distribution method
sel - selectivity
ptn - partition
AP - adaptive plans

Other areas of the trace file provide environment information that is not necessary for this discussion. Because the execution plan includes a NESTED LOOPS SEMI step the reason for this should be ascertained since the original query had no join conditions. Looking through the trace file doesn’t reveal anything that looks unusual to the modestly trained eye until the section provided below is examined. Searching through the trace file for indications of join activity allowed the DBA to eventually ‘zero in’ on the offending optimizer step. Subquery unnesting isn’t usually an issue but in this case, it involved two similar nested subqueries that Oracle thought would perform better as joins. Unfortunately, this optimizer decision ended up as the more costly alternative:

Cost-Based Subquery Unnesting
SU: Unnesting query blocks in query block SEL$1 (#1) that are valid to unnest.
Subquery removal for query block SEL$3 (#3)
RSW: Not valid for subquery removal SEL$3 (#3)
Subquery unchanged.
Subquery Unnesting on query block SEL$2 (#2)SU: Performing unnesting that does not require costing.
SU: Considering subquery unnest on query block SEL$2 (#2).
SU:   Checking validity of unnesting subquery SEL$3 (#3)
SU:   Passed validity checks.
SU:   Transforming ANY subquery to a join.
Registered qb: SEL$BE5C8E5F 0x755990f8 (SUBQUERY UNNEST SEL$2; SEL$3)

The query unnesting results in performance degradation because Oracle now must process a nested loop join; hinting the subqueries altered the nested loops path into two filter operations, speeding up the execution time considerably. Having this information allows the DBA to use the proper hint (no_unnest) on each of the nested subqueries to eliminate this behavior.

Sometimes query tuning can require a considerable amount of time, especially when searching a trace file for a cause with little more than an execution plan and the fact that the plan doesn’t match how the query was constructed. Even DBAs experienced with the oddities of the optimizer may miss the cause when it’s buried in a section that doesn’t appear to apply at first glance.

No article on any aspect of query tuning can provide an absolute, foolproof method for improving performance. There are simply too many variables and too many optimizer possibilities to consider. Hopefully this article has provided a starting point for query and statement tuning; remember that each query is different, and that performance tuning is statement-specific. Consider each query on its own and major improvements may not be guaranteed, but sometimes even the smallest change can produce measurable results.

See all articles by David Fitzjarrell

David Fitzjarrell
David Fitzjarrell
David Fitzjarrell has more than 20 years of administration experience with various releases of the Oracle DBMS. He has installed the Oracle software on many platforms, including UNIX, Windows and Linux, and monitored and tuned performance in those environments. He is knowledgeable in the traditional tools for performance tuning – the Oracle Wait Interface, Statspack, event 10046 and 10053 traces, tkprof, explain plan and autotrace – and has used these to great advantage at the U.S. Postal Service, American Airlines/SABRE, ConocoPhilips and SiriusXM Radio, among others, to increase throughput and improve the quality of the production system. He has also set up scripts to regularly monitor available space and set thresholds to notify DBAs of impending space shortages before they affect the production environment. These scripts generate data which can also used to trend database growth over time, aiding in capacity planning. He has used RMAN, Streams, RAC and Data Guard in Oracle installations to ensure full recoverability and failover capabilities as well as high availability, and has configured a 'cascading' set of DR databases using the primary DR databases as the source, managing the archivelog transfers manually and montoring, through scripts, the health of these secondary DR databases. He has also used ASM, ASMM and ASSM to improve performance and manage storage and shared memory.

Get the Free Newsletter!

Subscribe to Cloud Insider for top news, trends & analysis

Latest Articles