Re: FGAC predicate - problem with plan/execution time (LONG)

Niall Litchfield wrote:
>
> "dnh" <nigel.hurst_at_ds-s.maps.com> wrote in message
> news:3eb1def1$1_at_cpns1.saic.com...
> >
> > "Connor McDonald" <connor_mcdonald_at_yahoo.com> wrote in message
> > news:3EB1D404.7A25_at_yahoo.com...
> > > dnh wrote:
> > >><snip>
> > >
> > > you can dump out some info with event 10530 which may assist in tracking
> > > this down
> > >
> > > hth
> > > connor
> >
> > Connor,
> >
> > sorry, but I don't know what you mean, can you expand?
>
> I'm almost sure that Connor means in a session run
>
> alter session set events '10053 trace name context forever, level 12'; ---
> set the event
> run your sql statement
> alter session set events '10053 trace name context off'; --- unset the event
>
> This will produce a trace file in the UDUMP directory containing a list of
> the decisions that optimiser made when parsing the statement, and the
> information it used to do so. Doing this twice, once for each of your
> statements, will give you some places to look.
>
> So for example the following session,
>
> SQL> create table t1
> 2 as select * from all_objects;
>
> Table created.
>
> SQL> create table t2
> 2 as select * from user_objects;
>
> Table created.
>
> SQL> alter table t1 add constraint pk_t1 primary key(object_id);
>
> Table altered.
>
> SQL> alter table t2 add constraint pk_t2 primary key(object_id);
>
> Table altered.
>
> SQL> analyze table t1 compute statistics;
>
> Table analyzed.
>
> SQL> analyze table t2 compute statistics;
>
> Table analyzed.
>
> SQL> alter session set events '10053 trace name context forever, level 1';
>
> Session altered.
>
> SQL> select t1.owner,t1.object_type,t2.object_name
> 2 from t1,t2
> 3 where t1.object_id=t2.object_id;
>
> OWNER OBJECT_TYPE OBJECT_NAME
> ------------------------------ ------------------------------ --------------
> ----------------
> NIALL PROCEDURE CLOB_TO_FILE
> <snip>
>
> 370 rows selected.
>
> SQL> alter session set events '10053 trace name context off';
>
> Session altered.
>
> Gives the following trace which shows the costings and decisions taken by
> the optimiser as well as the plan chosen
>
> Dump file c:\oracle\admin\nl9iwk\udump\nl9iwk_ora_3440.trc
>
> Fri May 02 12:48:16 2003
>
> ORACLE V9.2.0.3.0 - Production vsnsta=0
>
> vsnsql=12 vsnxtr=3
>
> Windows 2000 Version 5.1 Service Pack 1, CPU type 586
>
> Oracle9i Enterprise Edition Release 9.2.0.3.0 - Production
>
> With the Partitioning, OLAP and Oracle Data Mining options
>
> JServer Release 9.2.0.3.0 - Production
>
> Windows 2000 Version 5.1 Service Pack 1, CPU type 586
>
> Instance name: nl9iwk
>
> Redo thread mounted by this instance: 1
>
> Oracle process number: 12
>
> Windows thread id: 3440, image: ORACLE.EXE
>
> *** 2003-05-02 12:48:16.000
>
> *** SESSION ID:(9.5) 2003-05-02 12:48:16.000
>
> QUERY
>
> select t1.owner,t1.object_type,t2.object_name
>
> from t1,t2
>
> where t1.object_id=t2.object_id
>
> ***************************************
>
> PARAMETERS USED BY THE OPTIMIZER
>
> ********************************
>
> OPTIMIZER_FEATURES_ENABLE = 9.2.0
>
> OPTIMIZER_MODE/GOAL = Choose
>
> _OPTIMIZER_PERCENT_PARALLEL = 101
>
> HASH_AREA_SIZE = 1048576
>
> HASH_JOIN_ENABLED = TRUE
>
> HASH_MULTIBLOCK_IO_COUNT = 0
>
> SORT_AREA_SIZE = 524288
>
> OPTIMIZER_SEARCH_LIMIT = 5
>
> PARTITION_VIEW_ENABLED = FALSE
>
> _ALWAYS_STAR_TRANSFORMATION = FALSE
>
> _B_TREE_BITMAP_PLANS = TRUE
>
> STAR_TRANSFORMATION_ENABLED = FALSE
>
> _COMPLEX_VIEW_MERGING = TRUE
>
> _PUSH_JOIN_PREDICATE = TRUE
>
> PARALLEL_BROADCAST_ENABLED = TRUE
>
> OPTIMIZER_MAX_PERMUTATIONS = 2000
>
> OPTIMIZER_INDEX_CACHING = 0
>
> _SYSTEM_INDEX_CACHING = 0
>
> OPTIMIZER_INDEX_COST_ADJ = 100
>
> OPTIMIZER_DYNAMIC_SAMPLING = 1
>
> _OPTIMIZER_DYN_SMP_BLKS = 32
>
> QUERY_REWRITE_ENABLED = TRUE
>
> QUERY_REWRITE_INTEGRITY = ENFORCED
>
> _INDEX_JOIN_ENABLED = TRUE
>
> _SORT_ELIMINATION_COST_RATIO = 0
>
> _OR_EXPAND_NVL_PREDICATE = TRUE
>
> _NEW_INITIAL_JOIN_ORDERS = TRUE
>
> ALWAYS_ANTI_JOIN = CHOOSE
>
> ALWAYS_SEMI_JOIN = CHOOSE
>
> _OPTIMIZER_MODE_FORCE = TRUE
>
> _OPTIMIZER_UNDO_CHANGES = FALSE
>
> _UNNEST_SUBQUERY = TRUE
>
> _PUSH_JOIN_UNION_VIEW = TRUE
>
> _FAST_FULL_SCAN_ENABLED = TRUE
>
> _OPTIM_ENHANCE_NNULL_DETECTION = TRUE
>
> _ORDERED_NESTED_LOOP = TRUE
>
> _NESTED_LOOP_FUDGE = 100
>
> _NO_OR_EXPANSION = FALSE
>
> _QUERY_COST_REWRITE = TRUE
>
> QUERY_REWRITE_EXPRESSION = TRUE
>
> _IMPROVED_ROW_LENGTH_ENABLED = TRUE
>
> _USE_NOSEGMENT_INDEXES = FALSE
>
> _ENABLE_TYPE_DEP_SELECTIVITY = TRUE
>
> _IMPROVED_OUTERJOIN_CARD = TRUE
>
> _OPTIMIZER_ADJUST_FOR_NULLS = TRUE
>
> _OPTIMIZER_CHOOSE_PERMUTATION = 0
>
> _USE_COLUMN_STATS_FOR_FUNCTION = TRUE
>
> _SUBQUERY_PRUNING_ENABLED = TRUE
>
> _SUBQUERY_PRUNING_REDUCTION_FACTOR = 50
>
> _SUBQUERY_PRUNING_COST_FACTOR = 20
>
> _LIKE_WITH_BIND_AS_EQUALITY = FALSE
>
> _TABLE_SCAN_COST_PLUS_ONE = TRUE
>
> _SORTMERGE_INEQUALITY_JOIN_OFF = FALSE
>
> _DEFAULT_NON_EQUALITY_SEL_CHECK = TRUE
>
> _ONESIDE_COLSTAT_FOR_EQUIJOINS = TRUE
>
> _OPTIMIZER_COST_MODEL = CHOOSE
>
> _GSETS_ALWAYS_USE_TEMPTABLES = FALSE
>
> DB_FILE_MULTIBLOCK_READ_COUNT = 16
>
> _NEW_SORT_COST_ESTIMATE = TRUE
>
> _GS_ANTI_SEMI_JOIN_ALLOWED = TRUE
>
> _CPU_TO_IO = 0
>
> _PRED_MOVE_AROUND = TRUE
>
> ***************************************
>
> BASE STATISTICAL INFORMATION
>
> ***********************
>
> Table stats Table: T2 Alias: T2
>
> TOTAL :: CDN: 370 NBLKS: 5 AVG_ROW_LEN: 86
>
> Column: OBJECT_ID Col#: 3 Table: T2 Alias: T2
>
> NDV: 370 NULLS: 0 DENS: 2.7027e-003 LO: 30714 HI: 31628
>
> NO HISTOGRAM: #BKT: 1 #VAL: 2
>
> -- Index stats
>
> INDEX NAME: PK_T2 COL#: 3
>
> TOTAL :: LVLS: 0 #LB: 1 #DK: 370 LB/K: 1 DB/K: 1 CLUF: 167
>
> ***********************
>
> Table stats Table: T1 Alias: T1
>
> TOTAL :: CDN: 30382 NBLKS: 415 AVG_ROW_LEN: 96
>
> Column: OBJECT_ID Col#: 4 Table: T1 Alias: T1
>
> NDV: 30382 NULLS: 0 DENS: 3.2914e-005 LO: 2 HI: 31631
>
> NO HISTOGRAM: #BKT: 1 #VAL: 2
>
> -- Index stats
>
> INDEX NAME: PK_T1 COL#: 4
>
> TOTAL :: LVLS: 1 #LB: 63 #DK: 30382 LB/K: 1 DB/K: 1 CLUF: 25496
>
> _OPTIMIZER_PERCENT_PARALLEL = 0
>
> ***************************************
>
> SINGLE TABLE ACCESS PATH
>
> TABLE: T1 ORIG CDN: 30382 ROUNDED CDN: 30382 CMPTD CDN: 30382
>
> Access path: tsc Resc: 42 Resp: 42
>
> BEST_CST: 42.00 PATH: 2 Degree: 1
>
> ***************************************
>
> SINGLE TABLE ACCESS PATH
>
> TABLE: T2 ORIG CDN: 370 ROUNDED CDN: 370 CMPTD CDN: 370
>
> Access path: tsc Resc: 2 Resp: 2
>
> BEST_CST: 2.00 PATH: 2 Degree: 1
>
> ***************************************
>
> OPTIMIZER STATISTICS AND COMPUTATIONS
>
> ***************************************
>
> GENERAL PLANS
>
> ***********************
>
> Join order[1]: T2 [T2] T1 [T1]
>
> Now joining: T1 [T1] *******
>
> NL Join
>
> Outer table: cost: 2 cdn: 370 rcz: 22 resp: 2
>
> Inner table: T1
>
> Access path: tsc Resc: 42
>
> Join: Resc: 15542 Resp: 15542
>
> Access path: index (unique)
>
> Index: PK_T1
>
> TABLE: T1
>
> RSC_CPU: 0 RSC_IO: 1
>
> IX_SEL: 3.2914e-005 TB_SEL: 3.2914e-005
>
> Join: resc: 372 resp: 372
>
> Access path: index (eq-unique)
>
> Index: PK_T1
>
> TABLE: T1
>
> RSC_CPU: 0 RSC_IO: 1
>
> IX_SEL: 0.0000e+000 TB_SEL: 0.0000e+000
>
> Join: resc: 372 resp: 372
>
> Join cardinality: 370 = outer (370) * inner (30382) * sel (3.2914e-005)
> [flag=0]
>
> Best NL cost: 372 resp: 372
>
> SM Join
>
> Outer table:
>
> resc: 2 cdn: 370 rcz: 22 deg: 1 resp: 2
>
> Inner table: T1
>
> resc: 42 cdn: 30382 rcz: 17 deg: 1 resp: 42
>
> using join:1 distribution:2 #groups:1
>
> SORT resource Sort statistics
>
> Sort width: 2 Area size: 131072 Max Area size: 1257472 Degree: 1
>
> Blocks to Sort: 2 Row size: 35 Rows: 370
>
> Initial runs: 1 Merge passes: 1 IO Cost / pass: 3
>
> Total IO sort cost: 3
>
> Total CPU sort cost: 0
>
> Total Temp space used: 0
>
> SORT resource Sort statistics
>
> Sort width: 2 Area size: 131072 Max Area size: 1257472 Degree: 1
>
> Blocks to Sort: 108 Row size: 29 Rows: 30382
>
> Initial runs: 2 Merge passes: 1 IO Cost / pass: 162
>
> Total IO sort cost: 135
>
> Total CPU sort cost: 0
>
> Total Temp space used: 1729000
>
> Merge join Cost: 182 Resp: 182
>
> SM Join (with index on outer)
>
> Access path: index (no sta/stp keys)
>
> Index: PK_T2
>
> TABLE: T2
>
> RSC_CPU: 0 RSC_IO: 168
>
> IX_SEL: 1.0000e+000 TB_SEL: 1.0000e+000
>
> Outer table:
>
> resc: 168 cdn: 370 rcz: 22 deg: 1 resp: 168
>
> Inner table: T1
>
> resc: 42 cdn: 30382 rcz: 17 deg: 1 resp: 42
>
> using join:1 distribution:2 #groups:1
>
> SORT resource Sort statistics
>
> Sort width: 2 Area size: 131072 Max Area size: 1257472 Degree: 1
>
> Blocks to Sort: 108 Row size: 29 Rows: 30382
>
> Initial runs: 2 Merge passes: 1 IO Cost / pass: 162
>
> Total IO sort cost: 135
>
> Total CPU sort cost: 0
>
> Total Temp space used: 1729000
>
> Merge join Cost: 345 Resp: 345
>
> HA Join
>
> Outer table:
>
> resc: 2 cdn: 370 rcz: 22 deg: 1 resp: 2
>
> Inner table: T1
>
> resc: 42 cdn: 30382 rcz: 17 deg: 1 resp: 42
>
> using join:8 distribution:2 #groups:1
>
> Hash join one ptn Resc: 1 Deg: 1
>
> hash_area: 60 (max=307) buildfrag: 2 probefrag: 108 ppasses: 1
>
> Hash join Resc: 45 Resp: 45
>
> Join result: cost: 45 cdn: 370 rcz: 39
>
> Best so far: TABLE#: 0 CST: 2 CDN: 370 BYTES: 8140
>
> Best so far: TABLE#: 1 CST: 45 CDN: 370 BYTES: 14430
>
> ***********************
>
> Join order[2]: T1 [T1] T2 [T2]
>
> Now joining: T2 [T2] *******
>
> NL Join
>
> Outer table: cost: 42 cdn: 30382 rcz: 17 resp: 42
>
> Inner table: T2
>
> Access path: tsc Resc: 2
>
> Join: Resc: 60806 Resp: 60806
>
> Access path: index (unique)
>
> Index: PK_T2
>
> TABLE: T2
>
> RSC_CPU: 0 RSC_IO: 1
>
> IX_SEL: 2.7027e-003 TB_SEL: 2.7027e-003
>
> Join: resc: 30424 resp: 30424
>
> Access path: index (eq-unique)
>
> Index: PK_T2
>
> TABLE: T2
>
> RSC_CPU: 0 RSC_IO: 1
>
> IX_SEL: 0.0000e+000 TB_SEL: 0.0000e+000
>
> Join: resc: 30424 resp: 30424
>
> Join cardinality: 370 = outer (30382) * inner (370) * sel (3.2914e-005)
> [flag=0]
>
> Best NL cost: 30424 resp: 30424
>
> SM Join
>
> Outer table:
>
> resc: 42 cdn: 30382 rcz: 17 deg: 1 resp: 42
>
> Inner table: T2
>
> resc: 2 cdn: 370 rcz: 22 deg: 1 resp: 2
>
> using join:1 distribution:2 #groups:1
>
> SORT resource Sort statistics
>
> Sort width: 2 Area size: 131072 Max Area size: 1257472 Degree: 1
>
> Blocks to Sort: 108 Row size: 29 Rows: 30382
>
> Initial runs: 2 Merge passes: 1 IO Cost / pass: 162
>
> Total IO sort cost: 135
>
> Total CPU sort cost: 0
>
> Total Temp space used: 1729000
>
> SORT resource Sort statistics
>
> Sort width: 2 Area size: 131072 Max Area size: 1257472 Degree: 1
>
> Blocks to Sort: 2 Row size: 35 Rows: 370
>
> Initial runs: 1 Merge passes: 1 IO Cost / pass: 3
>
> Total IO sort cost: 3
>
> Total CPU sort cost: 0
>
> Total Temp space used: 0
>
> Merge join Cost: 182 Resp: 182
>
> SM Join (with index on outer)
>
> Access path: index (no sta/stp keys)
>
> Index: PK_T1
>
> TABLE: T1
>
> RSC_CPU: 0 RSC_IO: 25560
>
> IX_SEL: 1.0000e+000 TB_SEL: 1.0000e+000
>
> Outer table:
>
> resc: 25560 cdn: 30382 rcz: 17 deg: 1 resp: 25560
>
> Inner table: T2
>
> resc: 2 cdn: 370 rcz: 22 deg: 1 resp: 2
>
> using join:1 distribution:2 #groups:1
>
> SORT resource Sort statistics
>
> Sort width: 2 Area size: 131072 Max Area size: 1257472 Degree: 1
>
> Blocks to Sort: 2 Row size: 35 Rows: 370
>
> Initial runs: 1 Merge passes: 1 IO Cost / pass: 3
>
> Total IO sort cost: 3
>
> Total CPU sort cost: 0
>
> Total Temp space used: 0
>
> Merge join Cost: 25565 Resp: 25565
>
> HA Join
>
> Outer table:
>
> resc: 42 cdn: 30382 rcz: 17 deg: 1 resp: 42
>
> Inner table: T2
>
> resc: 2 cdn: 370 rcz: 22 deg: 1 resp: 2
>
> using join:8 distribution:2 #groups:1
>
> Hash join one ptn Resc: 23 Deg: 1 (sides swapped)
>
> hash_area: 60 (max=307) buildfrag: 108 probefrag: 2 ppasses: 1
>
> Hash join Resc: 67 Resp: 67
>
> Outer table:
>
> resc: 2 cdn: 370 rcz: 22 deg: 1 resp: 2
>
> Inner table: T1
>
> resc: 42 cdn: 30382 rcz: 17 deg: 1 resp: 42
>
> using join:8 distribution:2 #groups:1
>
> Hash join one ptn Resc: 1 Deg: 1
>
> hash_area: 60 (max=307) buildfrag: 2 probefrag: 108 ppasses: 1
>
> Hash join Resc: 45 Resp: 45
>
> Final:
>
> CST: 45 CDN: 370 RSC: 45 RSP: 45 BYTES: 14430
>
> IO-RSC: 45 IO-RSP: 45 CPU-RSC: 0 CPU-RSP: 0
>
> *** 2003-05-02 12:48:34.000
>
> QUERY
>
> alter session set events '10053 trace name context off'

Yes in principle :-)

But I didn't typo my event. Event 10530 (or is 10350?) dumps information about row level security predicates.

hth
connor

-- 
=========================
Connor McDonald
http://www.oracledba.co.uk

"Some days you're the pigeon, some days you're the statue"