9i

Mview Complete Refresh and Atomic_refresh parameter

This post discusses issue faced by me while working on Materialized view (mview) creation at new site(database). Starting Oracle 10g, how atomic_refresh works with complete refresh has undergone a change.
Atomic_refresh parameter is to allow either all of the tasks of a transaction are performed or none of them (Atomicity). If set to TRUE, then all refreshes are done in one transaction. If set to FALSE, then the refresh of each specified materialized view is done in a separate transaction.
In case of 9i if a single mview was refreshed , it used to be truncated and then refreshed (which actually was not atomic). In case of multiple mviews being refreshed (part of refresh group), rows were deleted and then the insert was done.
As part of change in 10g, if atomic_refresh is set to true (By defualt) , rows will be deleted one by one and then insert will take place for both single mview or multiple mviews in refresh group. So if you need to truncate the mview before then set atomic_refresh =>false (default True) while doing a complete refresh.
Due to this change you will find many issues like high redo generation and longer time for complete refresh of mviews using dbms_mview.refresh as now in 10g it will go for deleting the rows and not truncate.
In our case a DBA issued a complete refresh for  mview with size of 195Gb (having around 8 indexes ). After 16 hours of running, refresh job was still deleting the rows and had not started inserting the rows. At this moment we decided to kill the refresh session. As this session had generated a lot of undo, smon kicked in to recover the transaction.
On checking the V$FAST_START_TRANSACTION , it reported that it will take around 2 months to perform the rollback.

This post discusses issue faced by me while working on Materialized view (mview) creation at new site(database). Starting Oracle 10g, how atomic_refresh works with complete refresh has undergone a change.

Atomic_refresh parameter is to allow either all of the tasks of a transaction are performed or none of them (Atomicity). If set to TRUE, then all refreshes are done in one transaction. If set to FALSE, then the refresh of each specified materialized view is done in a separate transaction.If set to FALSE, Oracle can optimize refresh by using parallel DML and truncate DDL on a materialized views.

In case of 9i  (atomic_refresh =>true), if a single mview was refreshed , it used to be truncated and then refreshed (which actually was not atomic). In case of multiple mviews being refreshed (part of refresh group), rows were deleted and then the insert was done.

As part of change in 10g, if atomic_refresh is set to true (By defualt) , rows will be deleted one by one and then insert will take place for both single mview or multiple mviews in refresh group. So if you need to truncate the mview before then set atomic_refresh =>false (default True) while doing a complete refresh.

Due to this change you will find many issues like high redo generation and longer time for complete refresh of mviews using dbms_mview.refresh as now in 10g it will go for deleting the rows and not truncate.

In our case a DBA issued a complete refresh without setting atomic_refresh to false for  mview with size of 195Gb (plus 8 indexes ). After 16 hours of running, refresh job was still deleting the rows and had not started inserting the rows. At this moment we decided to kill the refresh session. As this session had generated a lot of undo, smon kicked in to recover the transaction.

On checking the V$FAST_START_TRANSACTION , it reported that it will take around 2 months to perform the rollback.

SQL> select usn, state, undoblockstotal "Total", undoblocksdone "Done", undoblockstotal-undoblocksdone "ToDo",   decode(cputime,0,'unknown',sysdate+(((undoblockstotal-undoblocksdone) / (undoblocksdone / cputime)) / 86400))   "Estimated time to complete"
  2     from v$fast_start_transactions;

       USN STATE                 Total       Done       ToDo Estimated time to co
---------- ---------------- ---------- ---------- ---------- --------------------
        51 RECOVERING          3514498        354    3514144 12-SEP-2009 02:52:36

SQL> select * from V$fast_start_servers;

STATE       UNDOBLOCKSDONE        PID XID
----------- -------------- ---------- ----------------
RECOVERING             354         32 0033000200001C81
RECOVERING               0         33 0033000200001C81
RECOVERING               0         85 0033000200001C81
RECOVERING               0         38 0033000200001C81
RECOVERING               0         39 0033000200001C81
RECOVERING               0         40 0033000200001C81
RECOVERING               0         42 0033000200001C81
RECOVERING               0         43 0033000200001C81
RECOVERING               0         44 0033000200001C81
RECOVERING               0         45 0033000200001C81
RECOVERING               0         46 0033000200001C81
---- some output truncated -------
RECOVERING               0         68 0033000200001C81
RECOVERING               0         69 0033000200001C81
RECOVERING               0         53 0033000200001C81
RECOVERING               0         78 0033000200001C81
RECOVERING               0         79 0033000200001C81
RECOVERING               0         80 0033000200001C81
RECOVERING               0         81 0033000200001C81
RECOVERING               0         82 0033000200001C81
RECOVERING               0         83 0033000200001C81

fast_start_parallel_rollback was set to value of low. We see 50 processes were spawned and only one of the parallel server was doing the recovery indicating that the parallel servers might be interfering with each other. Metalink Note 144332.1 (- Parallel Rollback may hang database, Parallel query servers get 100% cpu) discusses this behavior. Now I decided to use the serial recovery by changing fast_start_parallel_rollback to false. But to do this , we had to disable the SMON to do transaction recovery using event 10513 at level 2.

SQL> oradebug setorapid  22
Unix process pid: 2728024, image: oracle@ods1 (SMON)
SQL> oradebug Event 10513 trace name context forever, level 2
Statement processed.
SQL> select 'kill -9 '||spid||' ' from V$process where pid in (select pid from V$FAST_START_SERVERS);

'KILL-9'||SPID||''
---------------------
kill -9 3014818
kill -9 3010772
kill -9 2916434
kill -9 2887716
kill -9 2678958
kill -9 2511030
kill -9 2224314
kill -9 2142210
kill -9 2822282
kill -9 2625696
kill -9 2506808
kill -9 2486520
kill -9 2314492
kill -9 2310186
kill -9 2752764
kill -9 2445478
kill -9 2326692
kill -9 2457716
kill -9 2654394
kill -9 2621630
kill -9 2580502
kill -9 2633960
kill -9 2412686

alter system set fast_start_parallel_rollback=false;

SQL>   select usn, state, undoblockstotal "Total", undoblocksdone "Done", undoblockstotal-undoblocksdone "ToDo",   decode(cputime,0,'unknown',sysdate+(((undoblockstotal-undoblocksdone) / (undoblocksdone / cputime)) / 86400))   "Estimated time to complete"
  2     from v$fast_start_transactions;

       USN STATE                 Total       Done       ToDo Estimated time to co
---------- ---------------- ---------- ---------- ---------- --------------------
        51 RECOVERING          3513444       6002    3507442 06-JUL-2009 17:58:03

SQL> select * from V$FAST_START_SERVERS;

no rows selected

Using serial recovery reduced estimated time to 5 hours.

To summarize, if you are still in process of upgrading 9i database to 10g database, then revisit your shell scripts and oracle dbms_jobs used for performing complete refresh of mviews and set atomic_refresh =>false explicitly to truncate the mview before refresh.

CleanUp Temporary Segments Occupying Permanent Tablespace

There are situations when we see “temporary segments” in permanent tablespaces hanging around and not getting cleaned up.
These temporary segments in permanent tablespace can be created by DDL operations like CTAS and “alter index..rebuild” because
the new object is created as a temporary segment in the target tablespace and when the DDL action finishes it will be changed to permanent type.
These temporary segments take actual disk space when SMON fails to perform its assigned job to cleanup stray temporary segments.
Following query finds out these segments:

 SQL > select tablespace_name, owner, sum(bytes/1024/1024) from dba_segments
where segment_type = 'TEMPORARY' group by tablespace_name, owner;

TABLESPACE_NAME     OWNER          SEGMENT_NAME     SUM(BYTES/1024/1024)
------------------- ------------   ------------     --------------------
xxxx_DATA           SYS              123.8365          137706
BDEPST_INDEX        SYS              345.8756            8910
KMRPT_DATA          SYS                345.87       25284.875
BILL_INDEX          SYS                                   .25
DSS_DATA            SYS                                   798
MRKT_INDEX          SYS                                   208
SPCT_DATA           SYS                              69642.25
SPCT_INDEX          SYS                              956.4375

Here we can see that tablespace KMRPT_DATA, SPCT_INDEX and SPCT_DATA have large temporary segments.

To know if any DDL is active which can create temporary segments we can use the following:

SQL> conn / as sysdba
SQL> select owner FROM dba_segments WHERE segment_name='345.87';
SQL> select pid from v$process where username='owner from above query';
SQL> alter session set tracefile_identifier='TEMPORARY_SEGMENTS';
SQL> oradebug setorapid <pid obtained>
SQL> oradebug dump errorstack 3
SQL > oradebug tracefile_name

It will give you the tracefile name, open that file and check for the “current sql”
If it is a DDL like CTAS or index rebuild, then wait for the operation to complete. If there is no pid
returned then these segments are “stray segements” and needs to cleaned up manually.

There are two ways to force the drop of temporary segments:

1. Using event DROP_SEGMENTS
2. Corrupting the segments and dropping these corrupted segments.

1. Using DROP_segments:

Find out the tablespace number (ts#) which contains temporary segments:
SQL> select ts# from sys.ts$ where name = 'tablespace name';

Suppose it comes out to be 10, use the following command to cleanup temporary segments:

SQL> alter session set events 'immediate trace name DROP_SEGMENTS level 11';

level is ts#+1 i.e 10+1=11 in this case.

2. Corrupting temporary segments for drop:
For this following procedures are used:
– DBMS_SPACE_ADMIN.TABLESPACE_VERIFY
– DBMS_SPACE_ADMIN.SEGMENT_CORRUPT
– DBMS_SPACE_ADMIN.SEGMENT_DROP_CORRUPT

— Verify the tablespace that contains temporary segments (In this case it is KMRPT_DATA)

SQL>DBMS_SPACE_ADMIN.TABLESPACE_VERIFY('KMRPT_DATA');

— Corrupt the temporary segments in tablespace KMRPT_DATA

SQL>DBMS_SPACE_ADMIN.SEGMENT_CORRUPT(' || chr(39) || tablespace_name || chr(39) || ',' || HEADER_FILE || ',' || HEADER_BLOCK || ');'  from dba_segments where SEGMENT_TYPE like 'TEMP%' and tablespace_name = 'KMRPT_DATA';

— Drop the corrupted temporary segments

SQL> select 'exec DBMS_SPACE_ADMIN.SEGMENT_DROP_CORRUPT (' || chr(39) || tablespace_name || chr(39) || ',' || HEADER_FILE || ',' || HEADER_BLOCK || ');' from dba_segments where SEGMENT_TYPE like 'TEMP%' and tablespace_name = 'KMRPT_DATA';

— Verify the tablespace again to update the new dictionary information:

SQL>DBMS_SPACE_ADMIN.TABLESPACE_VERIFY('KMRPT_DATA');

This will remove temporary segments from permanent tablespace.

Cheers!!!

Saurabh Sood

Index Access best approach?? Not Always…

There is a common misconception that Index access is the best access method for query execution. This approach leads to people concentrate on removing Full Table Scans (FTS) from the Query execution plan. I recently worked on a performance tuning issue where I found such scenario. Basically customer was trying to generate report for 3 years and query was running for more then 8 hours without producing any results. We were asked to look into this problem.

Following diagnostic data was collected to diagnose the issue.
1)    10046 trace at level 12
2)    Execution plan from V$SQL_PLAN (Database version is 9.2)
3)    Explain plan for offending query

From 10046 trace and V$session_wait, I found out query was waiting on  “db file sequential read” wait event for table SCOTT_BILL. This indicated that we were reading this table using index rowid’s. Please find below explain plan for the problematic query.

SQL> @?/rdbms/admin/utlxpls.sql
PLAN_TABLE_OUTPUT

------------------------------------------------------------------------------------
| Id  | Operation                         |  Name          | Rows  | Bytes | Cost  |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |                |     1 |   161 | 66436 |
|   1 |  SORT ORDER BY                    |                |     1 |   161 | 66433 |
|*  2 |   FILTER                          |                |       |       |       |
|   3 |    NESTED LOOPS                   |                |     1 |   161 | 66424 |
|   4 |     NESTED LOOPS                  |                |     1 |   141 | 66421 |
|   5 |      NESTED LOOPS                 |                |     1 |   126 | 66419 |
|   6 |       NESTED LOOPS                |                |   391 | 27761 | 65246 |
|*  7 |        TABLE ACCESS FULL          | SCOTT_PO        | 21716 |   254K|    98 |
|   8 |        TABLE ACCESS BY INDEX ROWID| SCOTT_POIC      |     1 |    59 |     3 |
|*  9 |         INDEX RANGE SCAN          | SCOTT_POIC_MK3  |     1 |       |     2 |
|* 10 |       TABLE ACCESS BY INDEX ROWID | SCOTT_BILL      |     1 |    55 |     3 |
|* 11 |        INDEX RANGE SCAN           | SCOTT_BILL_FK7  |     1 |       |     2 |
|* 12 |      TABLE ACCESS BY INDEX ROWID  | SCOTT_CUST      |     1 |    15 |     2 |
|* 13 |       INDEX RANGE SCAN            | SCOTT_CUST_FK1  |     1 |       |     1 |
|  14 |     TABLE ACCESS BY INDEX ROWID   | SCOTT_DSST      |     1 |    20 |     3 |
|* 15 |      INDEX UNIQUE SCAN            | SCOTT_DSST_PK   |     1 |       |     2 |
|  16 |       SORT AGGREGATE              |                |     1 |    17 |       |
|  17 |        FIRST ROW                  |                |     1 |    17 |     4 |
|* 18 |         INDEX RANGE SCAN (MIN/MAX)| SCOTT_DSST_PK   |   166M|       |     4 |
|  19 |    SORT AGGREGATE                 |                |     1 |    36 |       |
|* 20 |     INDEX RANGE SCAN              | SCOTT_POIC_UK1  |     1 |    36 |     3 |
------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("SYS_ALIAS_5"."POIC_SEQ_NO"= (SELECT /*+ */ MAX("B"."POIC_SEQ_NO")
              FROM "MAT"."SCOTT_POIC" "B" WHERE "B"."POIC_PO_SEQ_NO"=:B1 AND "B"."POIC_PO_NO"=:B2
              AND "B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND
              NVL("B"."POIC_RQMT_NO",0)=NVL(:B5,0) AND "B"."POIC_CTRT_TYPE"='BAS'))
   7 - filter(NVL("SCOTT_PO"."PO_COMP_CODE",'01')='01')
   9 - access("SCOTT_PO"."PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
              "SCOTT_PO"."PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO" AND
              "SYS_ALIAS_5"."POIC_CTRT_TYPE"='BAS')
       filter("SYS_ALIAS_5"."POIC_CTRT_TYPE"='BAS')
  10 - filter("SYS_ALIAS_6"."BILL_ASRV_DATE">=TO_DATE('2008-04-01 00:00:00',
              'yyyy-mm-dd hh24:mi:ss') AND "SYS_ALIAS_6"."BILL_ASRV_DATE"<=TO_DATE('2008-11-30
              23:59:59', 'yyyy-mm-dd hh24:mi:ss') AND NVL("SYS_ALIAS_6"."BILL_COMP_CODE",'01')='01
              ' AND "SYS_ALIAS_6"."BILL_SRV_TYPE"='S' AND
              "SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG" IS NULL AND
              NVL("SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG",'X')<>'N' AND
              "SYS_ALIAS_6"."BILL_INER_CODE" IS NULL AND
              "SYS_ALIAS_6"."BILL_ITEM_CODE"="SYS_ALIAS_5"."POIC_ITEM_CODE" AND
              "SYS_ALIAS_6"."BILL_PITM_SEQ_NO"="SYS_ALIAS_5"."POIC_PITM_SEQ_NO")
  11 - access("SYS_ALIAS_6"."BILL_PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
              "SYS_ALIAS_6"."BILL_PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO")
       filter(NVL("SYS_ALIAS_6"."BILL_RQMT_NO",0)=NVL("SYS_ALIAS_5"."POIC_RQMT_NO",0
              ))
  12 - filter(NVL("SCOTT_CUST"."CUST_COMP_CODE",'01')='01' AND
              "SCOTT_CUST"."CUST_INER_CODE" IS NULL)
  13 - access("SCOTT_CUST"."CUST_SRV_NO"="SYS_ALIAS_6"."BILL_SRV_NO")
  15 - access("SYS_ALIAS_6"."BILL_SRV_NO"="C"."DSST_SRV_NO" AND
              "C"."DSST_PROC_GROUP"=1 AND "C"."DSST_PROCESS"='PSRV' AND "C"."DSST_SEQ_NO"=
              (SELECT /*+ */ MAX("D"."DSST_SEQ_NO") FROM "MAT"."SCOTT_DSST" "D" WHERE
              "D"."DSST_PROCESS"='PSRV' AND "D"."DSST_PROC_GROUP"=1 AND "D"."DSST_SRV_NO"=:B1))
  18 - access("D"."DSST_SRV_NO"=:B1 AND "D"."DSST_PROC_GROUP"=1 AND
              "D"."DSST_PROCESS"='PSRV')
  20 - access("B"."POIC_PO_NO"=:B1 AND "B"."POIC_PO_SEQ_NO"=:B2 AND
              "B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND
              "B"."POIC_CTRT_TYPE"='BAS')
       filter("B"."POIC_ITEM_CODE"=:B1 AND "B"."POIC_PITM_SEQ_NO"=:B2 AND
              NVL("B"."POIC_RQMT_NO",0)=NVL(:B3,0) AND "B"."POIC_CTRT_TYPE"='BAS')

Looking at explain plan (and plan from V$SQL_PLAN) confirmed that we were using index SCOTT_BILL_FK7. Plan shows that CBO estimates only 1 row for this operation. But since we have been on this wait even for close to 8 hours, it was clear that we are accessing more then 1 row.Normally this query was run for small range(date column) and used to complete in 10 mins. e.g Below is explain plan for the same query with 4 day’s range.

SQL> @?/rdbms/admin/utlxpls.sql
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------

-----------------------------------------------------------------------------------------
| Id  | Operation                             |  Name           | Rows  | Bytes | Cost  |
-----------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                      |                 |     1 |   161 | 28876 |
|   1 |  SORT ORDER BY                        |                 |     1 |   161 | 28873 |
|*  2 |   FILTER                              |                 |       |       |       |
|*  3 |    TABLE ACCESS BY INDEX ROWID        | SCOTT_CUST       |     1 |    15 |     2 |
|   4 |     NESTED LOOPS                      |                 |     1 |   161 | 28864 |
|   5 |      NESTED LOOPS                     |                 |     1 |   146 | 28862 |
|   6 |       NESTED LOOPS                    |                 |     1 |   134 | 28861 |
|   7 |        NESTED LOOPS                   |                 |    56 |  4200 | 28581 |
|*  8 |         TABLE ACCESS BY INDEX ROWID   | SCOTT_BILL       |  2123 |   114K| 22212 |
|*  9 |          INDEX RANGE SCAN             | SCOTT_BILL_MK10  | 26081 |       |    85 |
|  10 |         TABLE ACCESS BY INDEX ROWID   | SCOTT_DSST       |     1 |    20 |     3 |
|* 11 |          INDEX UNIQUE SCAN            | SCOTT_DSST_PK    |     1 |       |     2 |
|  12 |           SORT AGGREGATE              |                 |     1 |    17 |       |
|  13 |            FIRST ROW                  |                 |     1 |    17 |     4 |
|* 14 |             INDEX RANGE SCAN (MIN/MAX)| SCOTT_DSST_PK    |   166M|       |     4 |
|* 15 |        TABLE ACCESS BY INDEX ROWID    | SCOTT_POIC       |     1 |    59 |     5 |
|* 16 |         INDEX RANGE SCAN              | SCOTT_POIC_MK3   |     1 |       |     2 |
|* 17 |       TABLE ACCESS BY INDEX ROWID     | SCOTT_PO         |     1 |    12 |     1 |
|* 18 |        INDEX UNIQUE SCAN              | SCOTT_PO_PK      |     1 |       |       |
|* 19 |      INDEX RANGE SCAN                 | SCOTT_CUST_FK1   |     1 |       |     1 |
|  20 |    SORT AGGREGATE                     |                 |     1 |    36 |       |
|* 21 |     INDEX RANGE SCAN                  | SCOTT_POIC_UK1   |     1 |    36 |     3 |
-----------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("SYS_ALIAS_5"."POIC_SEQ_NO"= (SELECT /*+ */ MAX("B"."POIC_SEQ_NO") FROM
              "MAT"."SCOTT_POIC" "B" WHERE "B"."POIC_PO_SEQ_NO"=:B1 AND "B"."POIC_PO_NO"=:B2 AND
              "B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND
              NVL("B"."POIC_RQMT_NO",0)=NVL(:B5,0) AND "B"."POIC_CTRT_TYPE"='BAS'))
   3 - filter(NVL("SCOTT_CUST"."CUST_COMP_CODE",'01')='01' AND
              "SCOTT_CUST"."CUST_INER_CODE" IS NULL)
   8 - filter(NVL("SYS_ALIAS_6"."BILL_COMP_CODE",'01')='01' AND
              "SYS_ALIAS_6"."BILL_SRV_TYPE"='S' AND "SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG" IS
              NULL AND NVL("SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG",'X')<>'N' AND
              "SYS_ALIAS_6"."BILL_INER_CODE" IS NULL)
   9 - access("SYS_ALIAS_6"."BILL_ASRV_DATE">=TO_DATE('2008-04-01 00:00:00', 'yyyy-mm-dd
              hh24:mi:ss') AND "SYS_ALIAS_6"."BILL_ASRV_DATE"<=TO_DATE('2008-04-05 23:59:59',
              'yyyy-mm-dd hh24:mi:ss'))
  11 - access("SYS_ALIAS_6"."BILL_SRV_NO"="C"."DSST_SRV_NO" AND "C"."DSST_PROC_GROUP"=1
              AND "C"."DSST_PROCESS"='PSRV' AND "C"."DSST_SEQ_NO"= (SELECT /*+ */
              MAX("D"."DSST_SEQ_NO") FROM "MAT"."SCOTT_DSST" "D" WHERE "D"."DSST_PROCESS"='PSRV' AND
              "D"."DSST_PROC_GROUP"=1 AND "D"."DSST_SRV_NO"=:B1))
  14 - access("D"."DSST_SRV_NO"=:B1 AND "D"."DSST_PROC_GROUP"=1 AND
              "D"."DSST_PROCESS"='PSRV')
  15 - filter("SYS_ALIAS_6"."BILL_PITM_SEQ_NO"="SYS_ALIAS_5"."POIC_PITM_SEQ_NO" AND
              NVL("SYS_ALIAS_6"."BILL_RQMT_NO",0)=NVL("SYS_ALIAS_5"."POIC_RQMT_NO",0))
  16 - access("SYS_ALIAS_6"."BILL_PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
              "SYS_ALIAS_6"."BILL_PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO" AND
              "SYS_ALIAS_6"."BILL_ITEM_CODE"="SYS_ALIAS_5"."POIC_ITEM_CODE" AND
              "SYS_ALIAS_5"."POIC_CTRT_TYPE"='BAS')
  17 - filter(NVL("SCOTT_PO"."PO_COMP_CODE",'01')='01')
  18 - access("SCOTT_PO"."PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
              "SCOTT_PO"."PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO")
  19 - access("SCOTT_CUST"."CUST_SRV_NO"="SYS_ALIAS_6"."BILL_SRV_NO")
  21 - access("B"."POIC_PO_NO"=:B1 AND "B"."POIC_PO_SEQ_NO"=:B2 AND
              "B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND "B"."POIC_CTRT_TYPE"='BAS')
       filter("B"."POIC_ITEM_CODE"=:B1 AND "B"."POIC_PITM_SEQ_NO"=:B2 AND
              NVL("B"."POIC_RQMT_NO",0)=NVL(:B3,0) AND "B"."POIC_CTRT_TYPE"='BAS')

Note: cpu costing is off

We can see that we used SCOTT_BILL_MK10 index here which was on the date column. This is also clear from predicate information available from explain plan.

   9 - access("SYS_ALIAS_6"."BILL_ASRV_DATE">=TO_DATE('2008-04-01 00:00:00', 'yyyy-mm-dd
              hh24:mi:ss') AND "SYS_ALIAS_6"."BILL_ASRV_DATE"<=TO_DATE('2008-04-05 23:59:59',
              'yyyy-mm-dd hh24:mi:ss'))

Coming back to our case, we see that index SCOTT_BILL_FK7 is being used here.This index is created on BILL_PO_NO, BILL_PO_SEQ_NO and BILL_RQMT_NO columns.

From explain plan, we see that following condition is used due to which we access the index

   11 - access("SYS_ALIAS_6"."BILL_PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
              "SYS_ALIAS_6"."BILL_PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO")
       filter(NVL("SYS_ALIAS_6"."BILL_RQMT_NO",0)=NVL("SYS_ALIAS_5"."POIC_RQMT_NO",0
              ))

Checking the column values, we see following

COLUMN_NAME          NUM_DISTINCT  NUM_NULLS
------------------------------ ------------ ----------
BILL_PO_NO             31841        636
BILL_PO_SEQ_NO          4       1296
BILL_RQMT_NO           437   27333280

I believe lot of null records present in the table along with NVL function usage is causing this issue. We can see from above data, that column BILL_RQMT_NO has 27 million null records. As B-Tree index does not index Null columns(B-tree indexes index null columns too if index is a concatenated index and the other column has non-null value. Refer to this article from Richard Foote). CBO assumed that only 1 row will be returned and it choose index SCOTT_BILL_FK7 as best access method. But because of NVL function, this returns more rows instead of just one row. This is my hypothesis and not sure , if its correct 🙂
As a quick fix , I suggested using FULL hint on SCOTT_BILL table so that we can perform a Full table Scan (FTS). This helped and query completed in 28 mins. If we look at long term solution, having a default value of 0 for this column could also be looked at. But all these things need to be decided in consideration with application design.

This is also a reminder to a fact that index access is not always the best access method. It is suitable if we are looking for very small data set and could become problem if data set increases.Whereas Full table Scan (FTS)  perform better in such cases as we perform multiblock I/O.