Obsolete cursors

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.

About these ads

11 Comments

  1. Posted October 29, 2012 at 09:04 | Permalink | Reply

    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

    • Posted October 29, 2012 at 11:37 | Permalink | Reply

      Dear Masaaki-san

      thanks a lot for the bug number.

      • Posted December 11, 2012 at 09:54 | Permalink | Reply

        Hi Timur-san,
        Additional information.
        Individual patch 14585499 for 11.2.0.3.X Generic was shown, now.

        Ciao,

        • Posted December 12, 2012 at 13:54 | Permalink | Reply

          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.

          • Posted December 13, 2012 at 08:56 | Permalink | Reply

            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.)

  2. Posted December 21, 2012 at 10:36 | Permalink | Reply

    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.

    • Posted December 21, 2012 at 10:58 | Permalink | Reply

      Thank you for good information! I will confirm the details later.

    • Posted December 25, 2012 at 10:25 | Permalink | Reply

      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.

  3. Posted August 20, 2013 at 21:25 | Permalink | Reply

    Hi guy, how are you ?
    Did you fix this problem ?

    regards

    Wellington Prado

  4. MZ
    Posted May 14, 2014 at 23:50 | Permalink | Reply

    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

  1. [...] 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 [...]

  2. [...] 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 [...]

  3. [...] – интересным было только ярко выраженное верхнее ограничение количества дочерних курсоров на запрос, определяемое параметром _cursor_obsolete_threshold – см. Timur Akhmadeev. Obsolete cursors: [...]

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

Follow

Get every new post delivered to your Inbox.

Join 288 other followers