In the previous post I wrote about strangely behaving V$SQL. For some reason there were duplicate rows leading to wrong results issue when running DBMS_XPLAN.DISPLAY_CURSOR for a particular child cursor. I tried to reproduce the issue using simple test case – and it was reproduced.
Here it is. I’m starting to execute a simple query against DUAL while constantly changing optimizer environment, forcing Oracle to build a new child cursor for each execution:
alter session set workarea_size_policy=manual; col curr_date new_value curr_date select to_char(sysdate, 'HH24MISS') curr_date from dual; set define on verify off begin for i in 1..100 loop execute immediate 'alter session set sort_area_size=' || to_char(100000 + i*1024); execute immediate 'select /* &&curr_date */ count(*) from dual'; end loop; end; / col sql_id new_value sql_id select sql_id, address from v$sqlarea where sql_text = 'select /* &&curr_date */ count(*) from dual'; clear columns select count(*) from v$sql_shared_cursor where sql_id = '&&sql_id'; @unshared &&sql_id
As expected, I’ve got 100 child cursors and 99 of them were created due to OPTIMIZER_MISMATCH:
SQL> select sql_id, address from v$sqlarea where sql_text = 'select /* &&curr_date */ count(*) from dual'; SQL_ID ADDRESS ------------- ---------------- 8ugq0vhq0z7pb 000007FF5D45C0B0 SQL> clear columns columns cleared SQL> select count(*) from v$sql_shared_cursor where sql_id = '&&sql_id'; COUNT(*) -------------------- 100 SQL> @unshared &&sql_id SQL_ID NONSHARED_REASON COUNT(*) ------------- ----------------------------- -------------------- 8ugq0vhq0z7pb OPTIMIZER_MISMATCH 99
Now let’s continue and see what will happen:
begin for i in 101..250 loop execute immediate 'alter session set sort_area_size=' || to_char(100000 + i*1024); execute immediate 'select /* &&curr_date */ count(*) from dual'; end loop; end; / select count(*) from v$sql_shared_cursor where sql_id = '&&sql_id'; select sum(cnt), avg(cnt), min(child_number), max(child_number) from (select child_number, count(*) cnt from v$sql where sql_id = '&&sql_id' group by child_number); select address, count(*) from v$sql where sql_id='&&sql_id' group by address; select sql_id, address from v$sqlarea where sql_text = 'select /* &&curr_date */ count(*) from dual'; @unshared &&sql_id select * from table(dbms_xplan.display_cursor('&&sql_id', 1));
SQL> select count(*) from v$sql_shared_cursor where sql_id = '&&sql_id'; COUNT(*) -------------------- 250 SQL> SQL> select sum(cnt), avg(cnt), min(child_number), max(child_number) 2 from (select child_number, count(*) cnt 3 from v$sql 4 where sql_id = '&&sql_id' 5 group by child_number); SUM(CNT) AVG(CNT) MIN(CHILD_NUMBER) MAX(CHILD_NUMBER) -------------------- -------------------- -------------------- -------------------- 250 2.5 0 99 SQL> SQL> select address, count(*) from v$sql where sql_id='&&sql_id' group by address; ADDRESS COUNT(*) ---------------- -------------------- 000007FF5D1E18A8 50 000007FF5D45C0B0 100 000007FF5D5BA268 100 SQL> select sql_id, address from v$sqlarea where sql_text = 'select /* &&curr_date */ count(*) from dual'; SQL_ID ADDRESS ------------- ---------------- 8ugq0vhq0z7pb 000007FF5D1E18A8 SQL> @unshared &&sql_id SQL_ID NONSHARED_REASON COUNT(*) ------------- ----------------------------- -------------------- 8ugq0vhq0z7pb OPTIMIZER_MISMATCH 249 SQL> select * from table(dbms_xplan.display_cursor('&&sql_id', 1)); PLAN_TABLE_OUTPUT ----------------------------------------------------------------------------------------------------------------------- SQL_ID 8ugq0vhq0z7pb, child number 1 ------------------------------------- An uncaught error happened in prepare_sql_statement : ORA-01422: exact fetch returns more than requested number of rows Plan hash value: 3910148636 ----------------------------------------------------------------- | Id | Operation | Name | Rows | Cost (%CPU)| Time | ----------------------------------------------------------------- | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | ----------------------------------------------------------------- SQL_ID 8ugq0vhq0z7pb, child number 1 ------------------------------------- An uncaught error happened in prepare_sql_statement : ORA-01422: exact fetch returns more than requested number of rows Plan hash value: 3910148636 ----------------------------------------------------------------- | Id | Operation | Name | Rows | Cost (%CPU)| Time | ----------------------------------------------------------------- | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | ----------------------------------------------------------------- SQL_ID 8ugq0vhq0z7pb, child number 1 ------------------------------------- An uncaught error happened in prepare_sql_statement : ORA-01422: exact fetch returns more than requested number of rows Plan hash value: 3910148636 ----------------------------------------------------------------- | Id | Operation | Name | Rows | Cost (%CPU)| Time | ----------------------------------------------------------------- | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 0 | SELECT STATEMENT | | | 2 (100)| | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 1 | SORT AGGREGATE | | 1 | | | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 2 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | ----------------------------------------------------------------- 114 rows selected.
Bingo. After the point of 100 child cursors per parent, Oracle builds a new parent (V$SQL.ADDRESS holds its address) cursor, marking old parent and child cursors as obsolete. V$SQLAREA handles the situation well, but V$SQL doesn’t and that’s clearly a bug. The threshold point of when to build a new parent cursor is 100 by default and is controlled with a new hidden parameter _cursor_obsolete_threshold. I’ve tested setting this parameter to 150 and it worked as expected. Note that this bug-fix-improvement-again-bugs 10187168 claimed to be included into Patch Set Update 11.2.0.2.2 (and higher). I’ve tested 11.2.0.2.3 & 11.2.0.2.5 and it seems the improvement is not enabled by default and they act the old, pre-11.2.0.3 way; most likely the bug-fix have to be enabled explicitly with event 106001 in the 11.2.0.2 PSUs. I haven’t tested it though.
PS. If you have time and desire, please file a bug to Oracle.
11 Comments
Dear Timur-san,
I tried the solution of this symptom.
I wanna thank you so much for your good testcase.
This problem was fixed.
BUG:14585499 PSR11.2.0.4
Dear Masaaki-san
thanks a lot for the bug number.
Hi Timur-san,
Additional information.
Individual patch 14585499 for 11.2.0.3.X Generic was shown, now.
Ciao,
Hi Masaaki-san
Thank you for the update. I’ve downloaded the one-off patch and discovered that they fix DBMS_XPLAN code, which will fix the exception, but the fix to the package is not what I would like to see in the patch. They are fixing consequences and not the root cause. They have to fix V$SQL to exclude these obsoleted entries (this is exception root cause), otherwise there’ll be more bugs coming.
Sad.
Hello Timur-san,
I understood my argument was off the point.
My customer sometimes got a huge garbage plan and was troubled.
Therefore I hurried a fix of ORA-1422 error and have forgotten a root problem.
Now I intend to register SR which assigned a focus to a problem of remaining V$SQL.IS_OBSOLETE=’N’ records.
Thank you for good advice.
Masaaki Yoshikawa(Mr.)
Hello Masaaki-san
thank you very much for your consistency!
One more bug related to obsolete cursors in 11.2.0.3: Bug 14127231 dbms_shared_pool.purge raised ora-6570 on obsoleted child cursors. Fixed in 11.2.0.4, one-off patches exists for 11.2.0.3 for some platforms. This bug-fix could address the real issue (obsolete v$sql entries) – I didn’t test it though.
Thank you for good information! I will confirm the details later.
Happy Holidays! Timur-san,
I applied 14127231 one-off patch.
However, the problem of remaining V$SQL.IS_OBSOLETE=’Y’ records occurred.
Sad.;-<
I want to continue my SR.
Hi guy, how are you ?
Did you fix this problem ?
regards
Wellington Prado
FYI, in 11.2.0.4 the default for _cursor_obsolete_threshold has been bumped to 1024. Was a nasty surprise for us (a lot of mview refreshes with unsharable cursors ), might also be unwanted for others.
3 Trackbacks
[…] it causes hundreds of child cursors to appear in Oracle versions before 11.2.0.3 (this version limits number of child cursors to 100 by default). Of course they should be purged from shared pool […]
[…] there was an even distribution of 23 or 24 rows per CHILD_NUMBER. I read about a similar situation here. In summary, 11gR2 has a limit of 100 children per statement, but also keeps invalidated rows in […]
[…] – интересным было только ярко выраженное верхнее ограничение количества дочерних курсоров на запрос, определяемое параметром _cursor_obsolete_threshold – см. Timur Akhmadeev. Obsolete cursors: […]