Extracting Query Block Information from Optimizer Trace

opt_qb.awk

The entries related to query blocks (QB) are normally scattered across the whole optimizer trace file. Therefore, it requires a lot of tedious searching, copying and pasting as well as scrolling back and forth just to get some basic information about a QB. This becomes even more awkward with large trace files containing hundreds of thousands of lines.

For this reason, I wrote opt_qb.awk, a gawk script that parses the optimizer trace and extracts the information about QBs, such as the best join order, cost, cardinality and applied query transformations (QT). It comes in handy, because it neatly displays all the QB related information on one place. Besides that, it prints the line numbers, so you can quickly position yourself within the trace file when looking for more detailed information.

Among others, the script has proven invaluable for analyzing QTs and, for example, quickly getting a clue why a QT was (or wasn’t) performed.

The usage is as follows:

opt_qb.awk [-v qb='qb_name'] optimizer_trace_file

Without the qb option, the script will display all of the QBs. For larger queries with multiple QBs, I usually focus on a single QB at a time.

The single quotation marks are optional when the QB doesn’t contain any special characters.

Simple case

A very simple sample output looks as follows:

opt_qb.awk -v qb=QB_MAIN DB_ora_640_NOJPPD58.trc              
---------------
27 Registered qb: QB_MAIN 0x93fcb108 (HINT QB_MAIN)

2830 Final cost for query block QB_MAIN (#1) - All Rows Plan:
2831   Best join order: 1
2832   Cost: 874.989877  Degree: 1  Card: 123159.000000  Bytes: 1354749.000000
---------------

I disabled the join predicate pushdown transformation (JPPD) here, so the QB_MAIN was costed only once.

JPPD

In contrast, the QB_MAIN appears three times in the trace after enabling JPPD:

opt_qb.awk -v qb=QB_MAIN AVAR99_ora_640_JPPD58.trc
---------------
27 Registered qb: QB_MAIN 0xa2780858 (HINT QB_MAIN)
3231 JPPD: Performing join predicate push-down (final phase) from query block QB_MIDDLE (#3) to query block QB_INNER (#4)
3236 JPPD: Performing join predicate push-down (no transformation phase) from query block QB_MAIN (#1) to query block QB_MIDDLE (#3)
4412 Final cost for query block QB_MAIN (#1) - All Rows Plan:
4413   Best join order: 1
4414   Cost: 873.989676  Degree: 1  Card: 123159.000000  Bytes: 1354749.000000
---------------
27 Registered qb: QB_MAIN 0xa2780858 (HINT QB_MAIN)
4426 JPPD: Performing join predicate push-down (final phase) from query block QB_MIDDLE (#3) to query block QB_INNER (#4)
4431 JPPD: Performing join predicate push-down (candidate phase) from query block QB_MAIN (#1) to query block QB_MIDDLE (#3)
5515 Final cost for query block QB_MAIN (#1) - All Rows Plan:
5516   Best join order: 1
5517   Cost: 1239149.505827  Degree: 1  Card: 123159.000000  Bytes: 1231590.000000
---------------
27 Registered qb: QB_MAIN 0xa2780858 (HINT QB_MAIN)
5539 JPPD: Performing join predicate push-down (final phase) from query block QB_MIDDLE (#3) to query block QB_INNER (#4)
5547 JPPD: Performing join predicate push-down (no transformation phase) from query block QB_MAIN (#1) to query block QB_MIDDLE (#3)
6805 Final cost for query block QB_MAIN (#1) - All Rows Plan:
6806   Best join order: 1
6807   Cost: 873.989676  Degree: 1  Card: 123159.000000  Bytes: 1354749.000000
---------------

The information is presented in such a way, that we can immediately recognize that QB_MAIN contains two nested QBs, both of which can receive the pushed predicate. We can clearly see that two JPPDs were considered. One is from QB_MAIN to QB_MIDDLE. The other is from QB_MIDDLE to QB_INNER.

By the way, notice how dispersed was the information for the first section:
– line 27: QB
– lines 3231-3236: JPPD
– lines 4412-4414: Summary

And this was only a small trace file containing not more than 10000 lines.

In the first section, the cost calculation was done without performing JPPD from QB_MAIN to QB_MIDDLE (“no transformation phase“).

The second section contains the result of the cost calculation with JPPD (“candidate phase“).

In the third section, the optimizer compares both scenarios and finally decides not to do JPPD, because of the lower cost.

Before costing QB_MAIN, it was already decided that the other JPPD, that is from QB_MIDDLE to QB_INNER, will be performed (“final phase“), but the details of this JPPD costing are omitted because of invoking opt_qb.awk with -v qb=QB_MAIN.

Transformed QBs

In the previous examples, the QB names were provided by a hint, for instance:

---------------
44 Registered qb: QB_INNER 0x93fb9a78 (HINT QB_INNER)
1963 Final cost for query block QB_INNER (#4) - All Rows Plan:
1964   Best join order: 1
1965   Cost: 6.002355  Degree: 1  Card: 10.000000  Bytes: 90.000000
---------------

But a QB can be transformed and renamed, like in the example below:

opt_qb.awk DB_ora_640_JPPD58.trc
...
---------------
2393 Registered qb: SEL$7B95B515 0x8c970b80 (PUSHED PREDICATE QB_INNER; QB_MIDDLE; "V_INNER"@"QB_MIDDLE" 2)
5547 JPPD: Performing join predicate push-down (no transformation phase) from query block QB_MAIN (#1) to query block QB_MIDDLE (#3)
5539 JPPD: Performing join predicate push-down (final phase) from query block QB_MIDDLE (#3) to query block QB_INNER (#4)
6122 Final cost for query block SEL$7B95B515 (#4) - All Rows Plan:
6123   Best join order: 1
6124   Cost: 5.027187  Degree: 1  Card: 1.000000  Bytes: 9.000000
---------------

This is the reason for displaying the QB origin – the information which might be hidden somewhere thousands of lines before the cost calculation.

Future plans

I wrote this script for my own use when analyzing optimizer issues. It has helped me to quickly understand some optimizer decisions and even discover new optimizer bugs.

It’s still work in progress and I’ll keep enhancing it as I go.

For the sake of convenience, I wrote it in gawk, which is installed on every Solaris and Linux server. I tested it, though, only on Solaris x64.

If it grows more complex and hence more difficult to maintain, I’ll consider rewriting it in Python.

Thanks for sharing

Nenad Noveljic

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.