Friday, June 20, 2025

When SQL plan baseline is not used

 Thank you very much for your interest.

Problem Statement:Lets assume you are reported about an application query running slow in one environment but fast in another environment.You found that there is a significant difference in execution stats and query is very complex.As a DBA you have exported the plan from good environment and imported into target envoronment.In spite of that query is slow and you observed that plan section says

Failed to use SQL plan baseline for this statement

This is a very frustrating situation.In this example I will explain how to find the root cause and solution.

First get the sql_handle and plan_name like below

SQL> select sql_handle,plan_name from dba_sql_plan_baselines where plan_name='SQL_PLAN_0f2v0q83vvt4c01f3681b';

select * from table(dbms_xplan.display_sql_plan_baseline(sql_handle=>'SQL_070b60b207bde48c',plan_name => 'SQL_PLAN_0f2v0q83vvt4c01f3681b',format=>'OUTLINE')); 

SQL_HANDLE                     PLAN_NAME

------------------------------ --------------------------------------------------------------------------------------------------------------------------------

SQL_070b60b207bde48c           SQL_PLAN_0f2v0q83vvt4c01f3681b

Then extract execution plan like below

Plan hash value: 3371473312

---------------------------------------------------------------------------------------------------------------
| Id  | Operation                                 | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                          |                   |       |       |    93 (100)|          |
|   1 |  VIEW                                     | VM_NWVW_2         |     1 |    12 |    93   (2)| 00:00:01 |
|   2 |   HASH UNIQUE                             |                   |     1 |   124 |    93   (2)| 00:00:01 |
|   3 |    FILTER                                 |                   |       |       |            |          |
|   4 |     FILTER                                |                   |       |       |            |          |
|   5 |      NESTED LOOPS                         |                   |     1 |   124 |    72   (0)| 00:00:01 |
|   6 |       NESTED LOOPS                        |                   |     1 |    72 |     5   (0)| 00:00:01 |
|   7 |        TABLE ACCESS BY INDEX ROWID BATCHED| CI_WFM_OPT        |     1 |    36 |     4   (0)| 00:00:01 |
|   8 |         INDEX RANGE SCAN                  | XC738P0           |     1 |       |     3   (0)| 00:00:01 |
|   9 |        TABLE ACCESS BY INDEX ROWID        | CI_WFM_OPT        |     1 |    36 |     1   (0)| 00:00:01 |
|  10 |         INDEX UNIQUE SCAN                 | XC738P0           |     1 |       |     0   (0)|          |
|  11 |       TABLE ACCESS BY INDEX ROWID BATCHED | CI_FA             |     4 |   208 |    67   (0)| 00:00:01 |
|  12 |        INDEX SKIP SCAN                    | CM_CI_FA_IDX      |   147 |       |     1   (0)| 00:00:01 |
|  13 |      NESTED LOOPS SEMI                    |                   |     1 |    36 |     3   (0)| 00:00:01 |
|  14 |       TABLE ACCESS FULL                   | CI_WFM            |     1 |    18 |     3   (0)| 00:00:01 |
|  15 |       INDEX RANGE SCAN                    | XC738P0           |     1 |    18 |     0   (0)|          |
|  16 |      NESTED LOOPS SEMI                    |                   |     1 |    50 |     4   (0)| 00:00:01 |
|  17 |       TABLE ACCESS FULL                   | CI_WFM            |     1 |    18 |     3   (0)| 00:00:01 |
|  18 |       TABLE ACCESS BY INDEX ROWID BATCHED | CI_WFM_OPT        |     1 |    32 |     1   (0)| 00:00:01 |
|  19 |        INDEX RANGE SCAN                   | XC738P0           |     1 |       |     0   (0)|          |
|  20 |     NESTED LOOPS SEMI                     |                   |     1 |   222 |    13   (0)| 00:00:01 |
|  21 |      NESTED LOOPS                         |                   |    15 |  2415 |     9   (0)| 00:00:01 |
|  22 |       MERGE JOIN CARTESIAN                |                   |     8 |   792 |     9   (0)| 00:00:01 |
|  23 |        NESTED LOOPS                       |                   |     1 |    50 |     4   (0)| 00:00:01 |
|  24 |         NESTED LOOPS                      |                   |     1 |    50 |     4   (0)| 00:00:01 |
|  25 |          TABLE ACCESS FULL                | CI_WFM            |     1 |    18 |     3   (0)| 00:00:01 |
|  26 |          INLIST ITERATOR                  |                   |       |       |            |          |
|  27 |           INDEX RANGE SCAN                | XC738P0           |     1 |       |     0   (0)|          |
|  28 |         TABLE ACCESS BY INDEX ROWID       | CI_WFM_OPT        |     1 |    32 |     1   (0)| 00:00:01 |
|  29 |        BUFFER SORT                        |                   |   528 | 25872 |     8   (0)| 00:00:01 |
|  30 |         TABLE ACCESS FULL                 | F1_BUS_OBJ_STATUS |   528 | 25872 |     5   (0)| 00:00:01 |
|  31 |       INDEX FULL SCAN                     | FC023S1           |     2 |   124 |     0   (0)|          |
|  32 |      TABLE ACCESS BY INDEX ROWID BATCHED  | F1_SYNC_REQ       |     1 |    61 |     4   (0)| 00:00:01 |
|  33 |       INDEX RANGE SCAN                    | F1T014S1          |     3 |       |     0   (0)|          |
---------------------------------------------------------------------------------------------------------------

Now I am giving you the execution plan where highlighted index is not used


Plan hash value: 212030488

------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                    | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                             |                   |       |       |  1979 (100)|          |
|   1 |  VIEW                                        | VM_NWVW_2         |     1 |    12 |  1979   (1)| 00:00:01 |
|   2 |   HASH UNIQUE                                |                   |     1 |   124 |  1979   (1)| 00:00:01 |
|*  3 |    FILTER                                    |                   |       |       |            |          |
|   4 |     NESTED LOOPS                             |                   |     1 |   124 |  1960   (1)| 00:00:01 |
|   5 |      NESTED LOOPS                            |                   |     1 |   124 |  1960   (1)| 00:00:01 |
|   6 |       NESTED LOOPS                           |                   |     1 |    88 |  1959   (1)| 00:00:01 |
|   7 |        TABLE ACCESS BY INDEX ROWID BATCHED   | CI_WFM_OPT        |     1 |    36 |     4   (0)| 00:00:01 |
|*  8 |         INDEX RANGE SCAN                     | XC738P0           |     1 |       |     3   (0)| 00:00:01 |
|*  9 |        TABLE ACCESS BY INDEX ROWID BATCHED   | CI_FA             |    20 |  1040 |  1955   (1)| 00:00:01 |
|* 10 |         INDEX RANGE SCAN                     | XT094S3           |  2024 |       |     0   (0)|          |
|  11 |          NESTED LOOPS SEMI                   |                   |     1 |   222 |    11   (0)| 00:00:01 |
|  12 |           NESTED LOOPS                       |                   |    18 |  2898 |     9   (0)| 00:00:01 |
|  13 |            MERGE JOIN CARTESIAN              |                   |    11 |  1089 |     9   (0)| 00:00:01 |
|  14 |             NESTED LOOPS                     |                   |     1 |    50 |     4   (0)| 00:00:01 |
|  15 |              NESTED LOOPS                    |                   |     1 |    50 |     4   (0)| 00:00:01 |
|* 16 |               TABLE ACCESS FULL              | CI_WFM            |     1 |    18 |     3   (0)| 00:00:01 |
|  17 |               INLIST ITERATOR                |                   |       |       |            |          |
|* 18 |                INDEX RANGE SCAN              | XC738P0           |     1 |       |     0   (0)|          |
|  19 |              TABLE ACCESS BY INDEX ROWID     | CI_WFM_OPT        |     1 |    32 |     1   (0)| 00:00:01 |
|  20 |             BUFFER SORT                      |                   |   730 | 35770 |     8   (0)| 00:00:01 |
|* 21 |              TABLE ACCESS FULL               | F1_BUS_OBJ_STATUS |   730 | 35770 |     5   (0)| 00:00:01 |
|* 22 |            INDEX FULL SCAN                   | FC023S1           |     2 |   124 |     0   (0)|          |
|* 23 |           TABLE ACCESS BY INDEX ROWID BATCHED| F1_SYNC_REQ       |     1 |    61 |     2   (0)| 00:00:01 |
|* 24 |            INDEX RANGE SCAN                  | F1T014S1          |     2 |       |     0   (0)|          |
|* 25 |       INDEX UNIQUE SCAN                      | XC738P0           |     1 |       |     0   (0)|          |
|* 26 |      TABLE ACCESS BY INDEX ROWID             | CI_WFM_OPT        |     1 |    36 |     1   (0)| 00:00:01 |
|  27 |     NESTED LOOPS SEMI                        |                   |     1 |    36 |     3   (0)| 00:00:01 |
|* 28 |      TABLE ACCESS FULL                       | CI_WFM            |     1 |    18 |     3   (0)| 00:00:01 |
|* 29 |      INDEX RANGE SCAN                        | XC738P0           |     1 |    18 |     0   (0)|          |
|  30 |     NESTED LOOPS SEMI                        |                   |     1 |    50 |     4   (0)| 00:00:01 |
|* 31 |      TABLE ACCESS FULL                       | CI_WFM            |     1 |    18 |     3   (0)| 00:00:01 |
|* 32 |      TABLE ACCESS BY INDEX ROWID BATCHED     | CI_WFM_OPT        |     1 |    32 |     1   (0)| 00:00:01 |
|* 33 |       INDEX RANGE SCAN                       | XC738P0           |     1 |       |     0   (0)|          |
------------------------------------------------------------------------------------------------------------------

So I was curious why it has not used that plan.To find the root cause you should gather optimizer trace like below

alter session set events 'trace[sql_optimizer.*]';

Now concentrate below snippet from optimzer trace


 ****** Costing Index CM_CI_FA_IDX

  SPD: Directive valid: dirid = 9191480872420513097, state = 1, flags = 1, loc = 1, forDS = NO, forCG = YES {EC(4537974)[8]}

  SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_SKIP_SCAN

  SPD: Directive valid: dirid = 9191480872420513097, state = 1, flags = 1, loc = 1, forDS = NO, forCG = YES {EC(4537974)[8]}

  SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_FILTER

  Access Path: index (FullScan)

    Index: CM_CI_FA_IDX

    resc_io: 159206.000000  resc_cpu: 1134282088

    ix_sel: 1.000000  ix_sel_with_filters: 0.004000

    Cost: 159288.851243  Resp: 159288.851243  Degree: 1

 ****** Costing Index XT094S3

  SPD: Directive valid: dirid = 9191480872420513097, state = 1, flags = 1, loc = 1, forDS = NO, forCG = YES {EC(4537974)[8]}

  SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_SCAN

  SPD: Directive valid: dirid = 9191480872420513097, state = 1, flags = 1, loc = 1, forDS = NO, forCG = YES {EC(4537974)[8]}

  SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_FILTER

  Access Path: index (RangeScan)

    Index: XT094S3

    resc_io: 1277.000000  resc_cpu: 9094882

    ix_sel: 2.5075e-04  ix_sel_with_filters: 2.5075e-04

    Cost: 1277.303511  Resp: 1277.303511  Degree: 1

  ****** trying bitmap/domain indexes ******

  ****** finished trying bitmap/domain indexes ******

  Best:: AccessPath: IndexRange

  Index: XT094S3

         Cost: 1277.303511  Degree: 1  Resp: 1277.303511  Card: 13484.064317  Bytes: 0.000000


See optimizer cost is high for CM_CI_FA_IDX so even though you have stored plan baseline optimizer thinks index XT094S3 is cost effective access path.So it ignores plan baseline and use other plan which used index XT904S3.

Now when I analyze index statistics I see that table stats are up to date but not index stats.

So I decided to gather index stats and executed again and this time it has used SQL Plan baselines.

Lesson Learnt:Even though you have plan baseline optimizer can ignore that if your underlying table/index stats are not upto date and evaluate other access path cost effective.



Saturday, June 14, 2025

How to test SQL execution manually using bind variables

Thank you very much for your interest. 

Problem statement:Suppose some developer said one of the application query performance is not consistent. Out of 10 execution lets say 6 executions are slow.You started analyzing and found that there are multiple plan available in cursor cache.You have gatherd plan stats and decided to create a SQL plan baseline out of that.Now, as a DBA how will you test execution manually from sqlplus client.Application using bind variable and if you use literal then your SQL text will change which results change in SQL_ID.

As a result SQL plan baseline will not be attached because plan baseline is specific to a single SQL_ID.So, how will you solve this problem? If you are interested I will walk you through the steps involved in this case.

Test environment:-Oracle database 19c in OEL 7.9

I have created following SQL plan baseline for the below SQL coming from application.Lets capture all these information from v$sql

SELECT FT_ID, FT_TYPE_FLG, CUR_AMT, TOT_AMT, ARS_DT, SIBLING_ID, VERSION
FROM CI_FT
WHERE SA_ID = :1 AND FREEZE_SW = :2 AND ARS_DT IS NOT NULL AND ARS_DT < :3 AND REDUNDANT_SW = :4 AND NOT_IN_ARS_SW = :5 ORDER BY ARS_DT , SIBLING_ID , FT_TYPE_FLG 

SQL_Plan_BASELINE :SQL_PLAN_dpfk7jn4r397y612e1e29


Please see that all variables are bind here using :1,:2  respectively

You can find SQL text from SQL_TEXT column of v$sql if the query still presents in cursor cache.

If it is aged out you can search in dba_hist_sqltext dictionary.

Now you may be aware that bind variables can be captured during extract of execution plan like below

select * from table(dbmsx_xplan.display(cursor('SQL_ID','CURSOR_CHILD_NO','OUTLINE PEEKED_BINDS'));

but I would recommend you to use below SQL to construct variables which can be used later.

if query is still in cursor cache

select replace(name,':','v'||substr(name,2,0))||' '||datatype_string||' :='''||value_string||''';' from v$sql_bind_capture a where sql_id='7dxj4xw55cra4'

else

select replace(name,':','v'||substr(name,2,0))||' '||datatype_string||' :='''||value_string||''';' from dba_hist_sqlbind a where sql_id='7dxj4xw55cra4' and  snap_id = (select max(snap_id) from dba_hist_sqlbind b where b.sql_id='7dxj4xw55cra4')

REPLACE(NAME,':','V'||SUBSTR(NAME,2,0))||''||DATATYPE_STRING||':='''||VALUE_STRI
--------------------------------------------------------------------------------
v1 CHAR(32) :='7983757218'                                                      
v2 CHAR(32) :='Y'                                                               
v3 DATE :='01/17/2025 00:00:00'                                                 
v4 CHAR(32) :='N'                                                               
v5 CHAR(32) :='N'     

Now construct below anonymous PL/SQL code like below
Use SQL_FULL TEXT of v$sql to get exact SQL text and put it in the variable vSQL.
DO NOT MAKE ANY CHANGES otherwise it will create a new SQL_ID

set serverout on
alter session set current_schema=<Valid Schema for tables>; --This is required 
alter session set nls_date_format='/mm/dd/yyyy HH24:MI:SS';
declare
v1 CHAR(32) :='7983757218' ;                                                     
v2 CHAR(32) :='Y';                                                               
v3 DATE :=to_date('01/17/2025 00:00:00','/mm/dd/yyyy HH24:MI:SS')  ;                                               
v4 CHAR(32) :='N'    ;                                                           
v5 CHAR(32) :='N'   ;
vSQL varchar2(4000);
begin
                                                        
vSQL :='SELECT                    FT_ID,                    FT_TYPE_FLG,                    CUR_AMT,                    TOT_AMT,                    ARS_DT,                    SIBLING_ID,                    VERSION                 FROM                    CI_FT                 WHERE                    SA_ID = :1                      AND FREEZE_SW = :2                      AND ARS_DT IS NOT NULL                     AND ARS_DT < :3                      AND REDUNDANT_SW = :4                      AND NOT_IN_ARS_SW = :5                      ORDER BY ARS_DT                    , SIBLING_ID                    , FT_TYPE_FLG ';
dbms_output.put_line(vSQL);
execute immediate vSQL using v1,v2,v3,v4,v5;
end;
/
Use below query to find out last execution like below
set line 200
col SQL_PLAN_BASELINE format a30
select last_load_time,plan_hash_value,sql_plan_baseline,elapsed_time from v$sql where sql_id='7dxj4xw55cra4'


LAST_LOAD_TIME      PLAN_HASH_VALUE SQL_PLAN_BASELINE              ELAPSED_TIME
------------------- --------------- ------------------------------ ------------
2025-06-14/14:45:41      1243860814 SQL_PLAN_dpfk7jn4r397y612e1e29        11147                                                                                         
1 row selected.

This proves that you have successfully tested the SQL with same SQL_ID which is using your created plan baseline with expected elapsed time

Saturday, June 7, 2025

Rman backup based duplication without target and recovery catalog db connection

 Thank you very much for your interest.

In this post I will show you how does rman clone work and some important consideration before you choose this option.

Problem statement:Assume you are requested to clone using rman backupset and due to some security restriction you can not connect source database using sys schema.Your backupsets have been mounted in a NFS filesystem.One more challenge is source database backup is not done using catalog connection.

Yes, this is the ideal use case for this feature.

This feature has been present since 11gR2 and you can find below MOS note

RMAN 11GR2 : DUPLICATE Without Target And Recovery Catalog Connection (Doc ID 874352.1)

Lets understand steps involved in this rman clone.

  1.  start an auxiliary instance in nomount mode.
  2. execute duplicate command like below
run
{
allocate auxiliary channel aux1 device type disk;
allocate auxiliary channel aux2 device type disk;
allocate auxiliary channel aux3 device type disk;
allocate auxiliary channel aux4 device type disk;
duplicate database 'sourcedb' dbid 933269695 to targetdb
spfile
set control_files='+DATA/targetdb/control01.ctl'
set db_file_name_convert='DBNAME','targetdb'
set log_file_name_convert='DBNAME','targetdb'
set diagnostic_dest='/u01/app/oracle'
set log_archive_dest_1='LOCATION=+RECO/targetdb/'
backup location '/Absolute NFS path';
}
Note:you can add until  until time "to_date('2025-06-07 06:35:00','YYYY-MM-DD HH24:MI:SS')"
just before spfile.In that case rman will try to macth controlfile/spfile backup slightly greater than your choosen timestamp

Lets explore this command...

  • First rman will search for DBID in the backup location we have mentioned.To do that it will search for the deafult unique file name for controlfile backupset which starts with c-DBID-YYYYMMDD.
So if that backup location contains backup of other database then your rman clone will fail to decide which dbid to consider and fail.
RMAN-03002: failure of Duplicate Db command at 06/06/2025 12:02:44
RMAN-05501: aborting duplication of target database
RMAN-05657: There are multiple database IDs present.
  • Now rman will restore SPFILE from the controlfile autobackupset which includes spfilebackup also.
  • After SPFILE restoration it will bring up instance with SPFILE and execute our set statements mentioned in the script like   alter system set control_files='+DATA/targetdb/control01.ctl' 
  • In this step 2 important changes are happening. It will try to restore control file and before controlfile restoration it will change parameter db_name as sourcedb and db_unique_name as targetdb
  • At this stage database is mounted using restored control file
  • Now,this is an interesting step where it finds scn number from the control file and try to recover until that scn.So rman internally creates script like below set until scn XXXXXXXX  --> This scn is same as checkpoint_change# column in v$database.Convert this scn to timestamp in source database and capture the timestamp                          
        SQL> select scn_to_timestamp(39262372810498) from dual;

        SCN_TO_TIMESTAMP(39262372810498)
        ---------------------------------------------------------------------------
        06-JUN-25 05.31.01.000000000 PM

        Similary capture checkpoint scn of last controlfile backup using rman command list backup of                 controlfile 
        Control File Included: Ckp SCN: 39262372814562   Ckp time: 2025-06-06 19:48:56
        So we see there is a difference.Basically during recovery it will find last archivelog backup which             is close to  controlfile checkpoint scn 39262372814562  and roll forward upro that scn.
        We shall also see below command
          set newname for datafile  1 to  "+DATA";
        Basically in this step controlfile is updated with new path where datafile needs to be restored
  • In the next step Datafiles will be restored from Level 0 backupsets
  • After successful restoration we can see below command where RMAN will recover the database in 2 phases.In first phase it will apply all incremental backups and then apply archivelog backups until last scn is close to last controlfile backup. 
           set until scn  39262372810498;
           recover
           clone database
           delete archivelog
  •  After recovery db_name is updated using alter system set DB_NAME=<targetdb>
  • Controlfile is recreated to change the database name using resetlogs option.
  • All the datafiles are cataloged to resgister in control file
  • Database is now opened cleaned.

Important points to be considered:-
  • If you dont mention log_archive_dest_1 parameter correctly you will end up restoring archivelog in $ORACLE_HOME/dbs and filling up the file system.It will also delete archivelog files without even applying anything.You can see below kind of message in RMAN log  
channel aux1: restore complete, elapsed time: 00:00:10
archived log file name=/u01/app/oracle/product/19.0.0.0/dbhome_3/dbs/arch1_62_1202746759.dbf thread=1 sequence=62
  • If your source database SPFILE has obsolete parameter rman clone will fail to bring up the instance using that SPFILE.So either you remove that parameter in rman command using set statement or update source SPFILE parameter
  • If you are doing timestamp based duplication then you have to be very careful in timestamp selection.Lets say your last controlfile autobackup completed with checkpoint time as 2025-06-07 07:05:20 and obviously you choose until timestamp less than that.Lets say you choose 2025-06-07 07:04:00. It may or may not be successful based on last archivelog backup.What I mean to say if your highest scn timestamp covered by the arcivelog is greater then your choosen timestmap.To find out what is the highest SCN captured you can use below rman command for example list backup of controlfile completed after "to_date('2025-06-07 07:00:00','YYYY-MM-DD HH24:MI:SS')";
List of Archived Logs in backup set 131567
  Thrd Seq     Low SCN    Low Time            Next SCN   Next Time
  ---- ------- ---------- ------------------- ---------- ---------
  1    85293   39262463706979 2025-06-07 06:05:04 39262464123178 2025-06-07 06:35:03

So you see that your next_time is lower than your choosen timestamp and Rman can not recover beyond this time.So highly likely it will fail.

Same has been explained in MOS note RMAN DUPLICATE FAILURE RMAN-05501 RMAN-06617 (Doc ID 1646262.1)

I hope you have learnt something useful..




When SQL plan baseline is not used

 Thank you very much for your interest. Problem Statement: Lets assume you are reported about an application query running slow in one envir...