Oracle Scratchpad

September 2, 2012

Bugs

Filed under: Bugs,Oracle — Jonathan Lewis @ 8:06 pm BST Sep 2,2012

Last week I published some code that demonstrated how a fast refresh of an aggregate materialized view could fail because of the internal use of the sys_op_map_nonnull() function. In some ways it was an easy problem to explain because all you had to do was trace the call to refresh and see what was going on. Today’s bug is completely different – it’s virtually impossible to see the connection between the failure and its cause. Here (as a cut-n-paste) is an example of what happens when the bug appears:

execute dbms_stats.gather_schema_stats(user)
*
ERROR at line 1:
ORA-01760: illegal argument for function
ORA-06512: at "SYS.DBMS_STATS", line 13336
ORA-06512: at "SYS.DBMS_STATS", line 13682
ORA-06512: at "SYS.DBMS_STATS", line 13760
ORA-06512: at "SYS.DBMS_STATS", line 13719
ORA-06512: at line 1


Now, when a called to dbms_stats fails, where are you supposed to look ? Since I had very few objects in the schema I tried collecting table stats for each object in turn (with cascade set to true) and found that the call to gather_table_stats() failed for just one of the tables; then I gathered stats on the table with cascade set to false and found that the call succeeded, so I finished off with a simple call to gather_index_stats on the one index on the table – and that failed.

In my case I had a clue about what to try next. I was running a test case for fast refresh of materialized join view. So I dropped the materialized view and all the calls to gather stats succeeded. So – a call to gather index stats on one of the indexes of a table involved in a materialized join view fails, but only after you’ve done a fast refresh on the view !

This was just an oddity that appeared while I was testing the basic options for non-trival fast refreshes, so I never got around to looking into it properly and didn’t send an SR and test case to Oracle, but if anyone wants to examine the problem, here’s a simple test case (with some of my debug code and minor variations stripped out).

create table orders(
	order_id	number(10) not null,
	customer_id	number(10) not null,
	store_id	number(10) not null,
	order_date	date not null,
	sales_rep	number(10) not null,
	total_value	number(8,2),
	total_tax	number(8,2),
	total_discount	number(8,2),
	constraint ord_pk primary key (order_id)
);

create table order_lines(
	order_id	number(10) not null,
	line_id		number(4)  not null,
	stock_code	number(10) not null,
	line_quantity	number(5)  not null,
	line_value	number(8,2),
	line_tax	number(8,2),
	line_discount	number(8,2),
	constraint orl_pk primary key (order_id, line_id),
	constraint orl_fk_ord foreign key (order_id) references orders
);

create materialized view log on orders
with
	rowid, primary key 
	(
		customer_id,
		store_id,
		order_date,
		sales_rep,
		total_value,
		total_tax,
		total_discount
	)
including new values
;

create materialized view log on order_lines
with
	rowid, primary key 
	(
		stock_code,
		line_quantity,
		line_value,
		line_tax,
		line_discount
	)
including new values
;

create materialized view orders_join
refresh fast on demand
enable query rewrite
as
select
	ord.rowid	ord_rowid,
	orl.rowid	orl_rowid,
	ord.order_id,
	orl.line_id,
	ord.store_id,
	ord.customer_id,
	ord.order_date,
	orl.stock_code,
	orl.line_quantity
from
	orders		ord,
	order_lines	orl
where
	orl.order_id = ord.order_id
;

prompt	========================================
prompt	A call to gather schema stats works here
prompt	========================================

execute dbms_stats.gather_schema_stats(user)

prompt	==============
prompt	Load some data
prompt	==============

insert into orders(
	order_id,
	customer_id,
	store_id,
	order_date,
	sales_rep,
	total_value,
	total_tax,
	total_discount
)
select
	rownum,
	trunc(dbms_random.value(1,5)),
	trunc(dbms_random.value(1,3)),
	trunc(sysdate),
	1,1,1,1
from
	all_objects
where
	rownum <= 5
;

insert into order_lines(
	order_id,
	line_id,
	stock_code,
	line_quantity,
	line_value,
	line_tax,
	line_discount
)
with line_ct as (
	select	--+ materialize
		rownum id 
	from dual 
	connect by 
		rownum <= 10
)
select
	ord.order_id,
	lct.id,
	trunc(dbms_random.value(1,10)),
	100 * lct.id,
	100 * lct.id,
	100 * lct.id,
	100 * lct.id
from
	line_ct	lct,
	orders	ord
;

commit;


prompt	========================================
prompt	A call to gather schema stats works here
prompt	========================================

execute dbms_stats.gather_schema_stats(user)

begin
	dbms_stats.gather_table_stats(
		ownname		 => user,
		tabname		 =>'ORDER_LINES',
		method_opt 	 => 'for all columns size 1',
		cascade		 => true
	);
end;
/

prompt	==============================
prompt	Refresh the materialized views
prompt	==============================

begin
	dbms_mview.refresh(
		list	=> 'test_user.orders_join',
		method	=> 'F'
	);
end;
/

prompt	=========================================
prompt	A call to gather schema stats fails here
prompt	on many versions of Oracle up to 11.2.0.3
prompt	=========================================

execute dbms_stats.gather_schema_stats(user)

begin
	dbms_stats.gather_table_stats(
		ownname		 => user,
		tabname		 =>'ORDER_LINES',
		method_opt 	 => 'for all columns size 1',
		cascade		 => true
	);
end;
/

begin
	dbms_stats.gather_table_stats(
		ownname		 => user,
		tabname		 =>'ORDER_LINES',
		method_opt 	 => 'for all columns size 1',
		cascade		 => false
	);
end;
/

begin
	dbms_stats.gather_index_stats(
		ownname		 => user,
		indname		 =>'ORL_PK'
	);
end;
/

I got the same behaviour on 10.2.0.3, 11.1.0.7 and 11.2.0.3 (although the line numbers in the PL/SQL error stack vary with version, of course).

Resolution of this problem is left as an exercise to the reader, but if I had to investigate further I think I’d start by checking MOS for anything similar, then sending in an SR with the demo, then run the code with sql_trace set to level 4 to see if any unexpected values were being passed in as bind variables to the various bits of recursive SQL called by dbms_stats.

10 Comments »

  1. [...] Jonathan Lewis blogs about the bugs once again. [...]

    Pingback by The Pythian Blog — September 3, 2012 @ 1:00 am BST Sep 3,2012 | Reply

  2. A first quick run through narrows (maybe) down the problem, when query rewrite on the materialized view is disabled, then it all runs through ok.

    I got no more time unfortunately for now, but may be later.

    Comment by Stefan — September 3, 2012 @ 6:04 am BST Sep 3,2012 | Reply

  3. I forgot, this was on a test VM with 11.2.0.1. And alternatively a small step further instead of changing the mview, alter session set QUERY_REWRITE_ENABLED=false; will allow dbms_stats to work without an error, it seems. Maybe Oracle tries to be a little bit too clever on the rewrite part during dbms_stats…, but maybe I am also wrong.

    Comment by Stefan — September 3, 2012 @ 6:10 am BST Sep 3,2012 | Reply

    • Stefan,

      Nice bit of research – which leads to all sorts of clues: and also shows why the problem can also appear “randomly”. If it’s about query rewrite then (with default settings for the query_rewrite_integrity parameter) the error won’t occur unless the stats collection is done AFTER a refresh but BEFORE the next change to the underlying tables.

      (Add an insert to the demo code after the refresh and before stats collection, and you should find that the collection suddenly works.)

      Comment by Jonathan Lewis — September 3, 2012 @ 5:26 pm BST Sep 3,2012 | Reply

  4. This error happens when following SQL is executed (of course you have to put your index object_id instead of 62727).
    The disabling of QUERY_REWRITE_ENABLED prevents from fail.

    select /*+ no_parallel_index(t, "ORL_PK")
               dbms_stats 
               cursor_sharing_exact 
               use_weak_name_resl 
               dynamic_sampling(0) 
               no_monitoring 
               no_substrb_pad  
               no_expand 
               index(t,"ORL_PK") */
           count(*) as nrw,
           count(distinct sys_op_lbid(62727, 'L', t.rowid)) as nlb,
           null as ndk,
           sys_op_countchg(substrb(t.rowid, 1, 15), 1) as clf
    from "U"."ORDER_LINES" t
    where "ORDER_ID" is not null or "LINE_ID" is not null;
    

    Comment by Valentin Nikotin — September 3, 2012 @ 9:09 am BST Sep 3,2012 | Reply

    • Actually it’s “Gathering Index Stats Fails with ORA-1760 when MVIEW is Present on the Table [ID 317254.1]“

      Comment by Valentin Nikotin — September 3, 2012 @ 9:21 am BST Sep 3,2012 | Reply

      • The root of this bug is specific of sys_op_lbid function which checks it’s arguments during the parse.
        Although the resulted plan won’t contain MV if we remove sys_op_lbid, it is still discussed by CBO.
        This is quote of the end of 10053 trace with failure:

        Copy query block qb# -1 (<unnamed>) : SELECT * FROM "U"."ORDERS_JOIN"
        Registered qb: SEL$4D0E67CD 0xaa7bb0 (PARSER)
        ---------------------
        QUERY BLOCK SIGNATURE
        ---------------------
          signature (): qb_name=SEL$4D0E67CD nbfros=1 flg=0
            fro(0): flg=4 objn=62795 hint_alias="ORDERS_JOIN"@"SEL$4D0E67CD"
        
        Registered qb: SEL$AD2C33E0 0xc46a80 (MV REWRITE SEL$1; SEL$1; ORDERS_JOIN)
        ---------------------
        QUERY BLOCK SIGNATURE
        ---------------------
          signature (): qb_name=SEL$AD2C33E0 nbfros=1 flg=0
            fro(0): flg=0 objn=62795 hint_alias="ORDERS_JOIN"@"SEL$4D0E67CD"
        
        CVM: Considering view merge in query block SEL$AD2C33E0 (#0)
        OJE: Begin: find best directive for query block SEL$AD2C33E0 (#0)
        OJE: End: finding best directive for query block SEL$AD2C33E0 (#0)
        CNT:   Considering count(col) to count(*) on query block SEL$AD2C33E0 (#0)
        *************************
        Count(col) to Count(*) (CNT)
        *************************
        CNT:     COUNT() to COUNT(*) not done.
        query block SEL$1 transformed to SEL$AD2C33E0 (#0)

        And this is the quote from 10053 with commented sys_op_lbid :

        Copy query block qb# -1 (<unnamed>) : SELECT * FROM "U"."ORDERS_JOIN"
        Registered qb: SEL$4D0E67CD 0xcdb8cf30 (PARSER)
        ---------------------
        QUERY BLOCK SIGNATURE
        ---------------------
          signature (): qb_name=SEL$4D0E67CD nbfros=1 flg=0
            fro(0): flg=4 objn=62795 hint_alias="ORDERS_JOIN"@"SEL$4D0E67CD"
        
        Registered qb: SEL$AD2C33E0 0xcdb26a80 (MV REWRITE SEL$1; SEL$1; ORDERS_JOIN)
        ---------------------
        QUERY BLOCK SIGNATURE
        ---------------------
          signature (): qb_name=SEL$AD2C33E0 nbfros=1 flg=0
            fro(0): flg=0 objn=62795 hint_alias="ORDERS_JOIN"@"SEL$4D0E67CD"
        
        CVM: Considering view merge in query block SEL$AD2C33E0 (#0)
        OJE: Begin: find best directive for query block SEL$AD2C33E0 (#0)
        OJE: End: finding best directive for query block SEL$AD2C33E0 (#0)
        CNT:   Considering count(col) to count(*) on query block SEL$AD2C33E0 (#0)
        *************************
        Count(col) to Count(*) (CNT)
        *************************
        CNT:     COUNT() to COUNT(*) not done.
        query block SEL$1 transformed to SEL$AD2C33E0 (#0)
        FPD: Considering simple filter push in query block SEL$AD2C33E0 (#0)
        "ORDERS_JOIN"."ORDER_ID" IS NOT NULL OR "ORDERS_JOIN"."LINE_ID" IS NOT NULL
        try to generate transitive predicate from check constraints for query block SEL$AD2C33E0 (#0)
        finally: "ORDERS_JOIN"."ORDER_ID" IS NOT NULL OR "ORDERS_JOIN"."LINE_ID" IS NOT NULL
        
        apadrv-start sqlid=5681247571542508886
          :
            call(in-use=21384, alloc=32712), compile(in-use=79560, alloc=85400), execution(in-use=4664, alloc=8088)
        
        *******************************************
        Peeked values of the binds in SQL statement
        *******************************************
        
        Final query after transformations:******* UNPARSED QUERY IS *******
        SELECT /*+ NO_EXPAND */
         COUNT(*) "NRW",
         NULL "NDK",
         SYS_OP_COUNTCHG(SUBSTRB(ROWIDTOCHAR("ORDERS_JOIN"."ORL_ROWID"), 1, 15), 1) "CLF"
          FROM "U"."ORDERS_JOIN" "ORDERS_JOIN"
         WHERE "ORDERS_JOIN"."ORDER_ID" IS NOT NULL
            OR "ORDERS_JOIN"."LINE_ID" IS NOT NULL
        ...
        

        Comment by Valentin Nikotin — September 3, 2012 @ 10:27 am BST Sep 3,2012 | Reply

      • Valentin,

        Thanks for that reference – it’s not very impressive that the problem was first reported in 9.2, and the Oracle developers still haven’t got around to adding the no_rewrite() hint to the code in 11.2.

        Comment by Jonathan Lewis — September 3, 2012 @ 5:23 pm BST Sep 3,2012 | Reply

    • Valentin,

      Thanks for pinning that down – I love the way that a small group with shared interests can sort out a problem so much faster than an individual.

      Lookng at the trace file I generated the SQL statement never gets into the file – was this a guess based on the normal code that you expected to see for index stats collection, or did you have a version of the SQL that actually dumped this before crashing ?

      Comment by Jonathan Lewis — September 3, 2012 @ 5:30 pm BST Sep 3,2012 | Reply

      • I just compared 10046 trace with and without refreshed MV. Then I checked query causing the issue, found that error happens even for explain plan and ran 10053 to get details.

        Comment by Valentin Nikotin — September 3, 2012 @ 9:34 pm BST Sep 3,2012 | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

The Rubric Theme Blog at WordPress.com.

Follow

Get every new post delivered to your Inbox.

Join 3,508 other followers