How to Determine which First Rows OPTIMIZER_MODE was Specified

16 02 2010

February 16, 2010

As you are probably aware, recent releases of Oracle (10.1 and above) support several variants of the first rows OPTIMIZER_MODE, in addition to ALL_ROWS, RULE, CHOOSE, and the original FIRST_ROWS (RULE and CHOOSE are now deprecated, and generally FIRST_ROWS should not be used).  When a 10046 trace is generated for a session, the trace file includes a reference (og=) that indicates the optimizer mode in effect for that SQL statement, as described in this article.  Unfortunately, 10046 extended trace files do not make a distinction between the original FIRST_ROWS optimizer mode and the newer variants FIRST_ROWS_1, FIRST_ROWS_10, FIRST_ROWS_100, and FIRST_ROWS_1000 – all will show og=2 in the 10046 trace file.  When the OPTIMIZER_MODE is set to FIRST_ROWS_10, for instance, the optimizer assumes that the client will only read the first 10 rows, and the client will discard the rest of the rows in the result set.  If the optimizer predicts that only eight rows will be returned (or a number less than or equal to 10), the optimizer will likely generate an execution plan similar to what would be generated with the OPTIMIZER_MODE set to ALL_ROWS.  As such, a different execution plan could be generated if the OPTIMIZER_MODE is set to FIRST_ROWS_10 rather than FIRST_ROWS_1000 when the result set is predicted to include, for instance, 120 rows.

Last year a question appeared on the OTN forums asking how to determine which of the FIRST_ROWS optimizer modes was in use based on the contents of a raw 10046 trace file.  Sounds like an interesting request.  If a simultaneous 10053 trace was enabled, or a 10132 trace (as suggested by Jonathan Lewis in the thread), the optimizer mode will be written directly to the same trace file that includes the 10046 trace information, if the SQL statement is hard parsed.  What else can you do?  A trace file generated on Oracle 11.1 and above includes the SQL_ID for the SQL statement in the raw 10046 trace file, while earlier versions include the HASH_VALUE which can be used to determine the SQL_ID.  Unfortunately, there could be multiple child cursors for the same SQL_ID, each potentially using a different value for the OPTIMIZER_MODE.

As a test, we could use a script like the following (using the sample table from this blog article):

ALTER SESSION SET TRACEFILE_IDENTIFIER = 'SQL_OP_MODE_TEST';
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 8';
ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_10';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_100';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1000';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF';

The resulting trace file might contain entries like ths following (when executed on Oracle 10.2.0.4):

PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1934865102 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=1474,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1934865097
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS FULL T1 (cr=3323 pr=0 pw=0 time=50079 us)'
...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1943577683 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=1694,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=2,tim=1943577677
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150071 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=333 us)'

...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1952576477 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=100,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=1952576474
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150075 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=285 us)'
...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1961574186 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=58,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=1961574184
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150075 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=298 us)'
...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1970536100 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=1970536097
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150075 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=294 us)'

If you are able to determine the SQL_ID based on the contents of the trace file, you could do something like this:

SELECT
  CHILD_NUMBER CN,
  NAME,
  VALUE,
  ISDEFAULT DEF
FROM
  V$SQL_OPTIMIZER_ENV
WHERE
  SQL_ID='fnk3z1j7c2zf3'
ORDER BY
  CHILD_NUMBER,
  NAME;

 CN NAME                          VALUE           DEF
--- ----------------------------- --------------- ---
  0 active_instance_count         1               YES
  0 bitmap_merge_area_size        1048576         YES
...

Unfortunately, the 10.2.0.4 trace file lacks the SQL_ID, so we need an extra trip into V$SQL:

SELECT
  SE.SQL_ID,
  SE.CHILD_NUMBER CN,
  SE.ADDRESS,
  SE.NAME,
  SE.VALUE,
  SE.ISDEFAULT DEF
FROM
  V$SQL_OPTIMIZER_ENV SE,
  V$SQL S
WHERE
  S.HASH_VALUE=1321303491
  AND S.SQL_ID=SE.SQL_ID
  AND S.CHILD_NUMBER=SE.CHILD_NUMBER
  AND S.ADDRESS=SE.ADDRESS
ORDER BY
  SE.CHILD_NUMBER,
  SE.NAME;

SQL_ID         CN ADDRESS          NAME                          VALUE           DEF
------------- --- ---------------- ----------------------------- --------------- ---
fnk3z1j7c2zf3   0 000007FF94EC5058 active_instance_count         1               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 bitmap_merge_area_size        1048576         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 cpu_count                     4               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 cursor_sharing                exact           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 hash_area_size                131072          NO
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_dynamic_sampling    2               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_features_enable     10.2.0.4        NO
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_index_caching       0               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_index_cost_adj      100             YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_mode                all_rows        YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_secure_view_merging true            YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_ddl_mode             enabled         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_dml_mode             disabled        YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_execution_enabled    false           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_query_mode           enabled         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_threads_per_cpu      2               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 pga_aggregate_target          204800 KB       YES
fnk3z1j7c2zf3   0 000007FF94EC5058 query_rewrite_enabled         true            YES
fnk3z1j7c2zf3   0 000007FF94EC5058 query_rewrite_integrity       enforced        YES
fnk3z1j7c2zf3   0 000007FF94EC5058 skip_unusable_indexes         true            YES
fnk3z1j7c2zf3   0 000007FF94EC5058 sort_area_retained_size       0               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 sort_area_size                65536           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 sqlstat_enabled               true            NO
fnk3z1j7c2zf3   0 000007FF94EC5058 star_transformation_enabled   false           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 statistics_level              typical         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 workarea_size_policy          auto            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 active_instance_count         1               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 bitmap_merge_area_size        1048576         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 cpu_count                     4               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 cursor_sharing                exact           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 hash_area_size                131072          NO
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_dynamic_sampling    2               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_features_enable     10.2.0.4        NO
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_index_caching       0               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_index_cost_adj      100             YES
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_mode                first_rows_1    NO
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_secure_view_merging true            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_ddl_mode             enabled         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_dml_mode             disabled        YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_execution_enabled    false           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_query_mode           enabled         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_threads_per_cpu      2               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 pga_aggregate_target          204800 KB       YES
fnk3z1j7c2zf3   1 000007FF94EC5058 query_rewrite_enabled         true            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 query_rewrite_integrity       enforced        YES
fnk3z1j7c2zf3   1 000007FF94EC5058 skip_unusable_indexes         true            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 sort_area_retained_size       0               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 sort_area_size                65536           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 sqlstat_enabled               true            NO
fnk3z1j7c2zf3   1 000007FF94EC5058 star_transformation_enabled   false           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 statistics_level              typical         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 workarea_size_policy          auto            YES

From the above, we see that there were only two child cursors in the library cache for our SQL statement.  Changing the OPTIMIZER_MODE between the various first rows modes did not trigger the generation of a new child cursor (this same behavior is present on Oracle 11.1.0.7 also), so the OPTIMIZER_MODE recorded in V$SQL_OPTIMIZER_ENV is first_rows_1.

A 10046 trace file captured with Oracle 11.1.0.7, executing the SQL statement with just the ALL_ROWS and FIRST_ROWS_1000 OPTIMIZER_MODEs, included the following:

PARSING IN CURSOR #14 len=51 dep=0 uid=60 oct=3 lid=60 tim=5884684690220 hv=1321303491 ad='23b698b8' sqlid='fnk3z1j7c2zf3'
...
PARSE #14:c=31250,e=43048,p=0,cr=140,cu=0,mis=1,r=0,dep=0,og=1,plh=3617692013,tim=5884684690220
...
STAT #14 id=1 cnt=50000 pid=0 pos=1 obj=86190 op='TABLE ACCESS FULL T1 (cr=6497 pr=3268 pw=0 time=0 us cost=890 size=700000 card=50000)'
...
PARSING IN CURSOR #17 len=51 dep=0 uid=60 oct=3 lid=60 tim=5884708721111 hv=1321303491 ad='23b698b8' sqlid='fnk3z1j7c2zf3'
...
PARSE #17:c=15625,e=31248,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=2,plh=4259601085,tim=5884708721111
...
STAT #17 id=1 cnt=50000 pid=0 pos=1 obj=86190 op='TABLE ACCESS BY INDEX ROWID T1 (cr=8260 pr=0 pw=0 time=0 us cost=37 size=14028 card=1002)'
STAT #17 id=2 cnt=50000 pid=1 pos=1 obj=86191 op='INDEX RANGE SCAN SYS_C0015323 (cr=3422 pr=0 pw=0 time=0 us cost=4 size=0 card=0)'

Since the SQL_ID was written to the 10046 trace file, we are able to see the optimizer parameters in effect for the query with the following SQL statement:

SELECT
  CHILD_NUMBER CN,
  NAME,
  VALUE,
  ISDEFAULT DEF
FROM
  V$SQL_OPTIMIZER_ENV
WHERE
  SQL_ID='fnk3z1j7c2zf3'
ORDER BY
  CHILD_NUMBER,
  NAME;

 CN NAME                                  VALUE           DEF
--- ------------------------------------- --------------- ---
  0 _optim_peek_user_binds                false           NO
  0 _optimizer_adaptive_cursor_sharing    false           NO
  0 active_instance_count                 1               YES
  0 bitmap_merge_area_size                1048576         YES
  0 cell_offload_compaction               ADAPTIVE        YES
  0 cell_offload_plan_display             AUTO            YES
  0 cell_offload_processing               true            YES
  0 cpu_count                             2               YES
  0 cursor_sharing                        exact           YES
  0 db_file_multiblock_read_count         32              YES
  0 hash_area_size                        131072          YES
  0 is_recur_flags                        0               YES
  0 optimizer_capture_sql_plan_baselines  false           YES
  0 optimizer_dynamic_sampling            2               YES
  0 optimizer_features_enable             11.1.0.7        YES
  0 optimizer_index_caching               0               YES
  0 optimizer_index_cost_adj              100             YES
  0 optimizer_mode                        all_rows        YES
  0 optimizer_secure_view_merging         true            YES
  0 optimizer_use_invisible_indexes       false           YES
  0 optimizer_use_pending_statistics      false           YES
  0 optimizer_use_sql_plan_baselines      true            YES
  0 parallel_ddl_mode                     enabled         YES
  0 parallel_degree                       0               YES
  0 parallel_dml_mode                     disabled        YES
  0 parallel_execution_enabled            false           YES
  0 parallel_query_default_dop            0               YES
  0 parallel_query_mode                   enabled         YES
  0 parallel_threads_per_cpu              2               YES
  0 pga_aggregate_target                  143360 KB       YES
  0 query_rewrite_enabled                 true            YES
  0 query_rewrite_integrity               enforced        YES
  0 result_cache_mode                     MANUAL          YES
  0 skip_unusable_indexes                 true            YES
  0 sort_area_retained_size               0               YES
  0 sort_area_size                        65536           YES
  0 sqlstat_enabled                       true            NO
  0 star_transformation_enabled           false           YES
  0 statistics_level                      typical         YES
  0 transaction_isolation_level           read_commited   YES
  0 workarea_size_policy                  auto            YES
  1 _optim_peek_user_binds                false           NO
  1 _optimizer_adaptive_cursor_sharing    false           NO
  1 active_instance_count                 1               YES
  1 bitmap_merge_area_size                1048576         YES
  1 cell_offload_compaction               ADAPTIVE        YES
  1 cell_offload_plan_display             AUTO            YES
  1 cell_offload_processing               true            YES
  1 cpu_count                             2               YES
  1 cursor_sharing                        exact           YES
  1 db_file_multiblock_read_count         32              YES
  1 hash_area_size                        131072          YES
  1 is_recur_flags                        0               YES
  1 optimizer_capture_sql_plan_baselines  false           YES
  1 optimizer_dynamic_sampling            2               YES
  1 optimizer_features_enable             11.1.0.7        YES
  1 optimizer_index_caching               0               YES
  1 optimizer_index_cost_adj              100             YES
  1 optimizer_mode                        first_rows_1000 NO
  1 optimizer_secure_view_merging         true            YES
  1 optimizer_use_invisible_indexes       false           YES
  1 optimizer_use_pending_statistics      false           YES
  1 optimizer_use_sql_plan_baselines      true            YES
  1 parallel_ddl_mode                     enabled         YES
  1 parallel_degree                       0               YES
  1 parallel_dml_mode                     disabled        YES
  1 parallel_execution_enabled            false           YES
  1 parallel_query_default_dop            0               YES
  1 parallel_query_mode                   enabled         YES
  1 parallel_threads_per_cpu              2               YES
  1 pga_aggregate_target                  143360 KB       YES
  1 query_rewrite_enabled                 true            YES
  1 query_rewrite_integrity               enforced        YES
  1 result_cache_mode                     MANUAL          YES
  1 skip_unusable_indexes                 true            YES
  1 sort_area_retained_size               0               YES
  1 sort_area_size                        65536           YES
  1 sqlstat_enabled                       true            NO
  1 star_transformation_enabled           false           YES
  1 statistics_level                      typical         YES
  1 transaction_isolation_level           read_commited   YES
  1 workarea_size_policy                  auto            YES

As long as someone did not use more than one of the first rows OPTIMIZER_MODEs, the above query will show the OPTIMIZER_MODE that was in effect at the time of the hard parse.  Of course, if another of the above parameters was also changed when the OPTIMIZER_MODE changed, there is a very good chance that a new child cursor would have been generated.


Comments : 1 Comment »

Categories : General Administration