Bug 2784796: ORA-00001:UNIQUE CONSTRAINT

 相關產品

Hdr: 2784796 9.2.0.2.0 RDBMS 9.2.0.2.0 DICTIONARY PRODID-5 PORTID-38 ORA-1
Abstract: ORA-1:UNIQUE CONSTRAINT (PERFSTAT.STATS$SQL_SUMMARY_PK) VIOLATED

*** 02/04/03 07:09 am ***
TAR:
----

PROBLEM:
--------
Running statspack on multiple nodes in a RAC environment can intermittently 
cause:

ORA-12012: error on auto execute of job 81
ORA-1: unique constraint (PERFSTAT.STATS$SQL_SUMMARY_PK) violated
ORA-6512: at "PERFSTAT.STATSPACK", line 1361
ORA-6512: at "PERFSTAT.STATSPACK", line 2442
ORA-6512: at "PERFSTAT.STATSPACK", line 91
ORA-6512: at line 1

Error can occur when issuing:

SQL > EXECUTE statspack.snap;

NODE   SNAP_LEVEL
=====  ==========
DB1       5
DB2       5
Using DBMS_JOB to schedule the job
JOB    LOG_USER   SCHEMA_USER    INTERVAL                         INSTANCE
=====  =========  =============  ==========                       ==========
81     PERFSTAT   PERFSTAT       TRUNC(SYSDATE+1/24,'HH')+1/1440     1
61     PERFSTAT   PERFSTAT       TRUNC(SYSDATE+1/24,'HH')+2/1440     2

Customer recently changed CURSOR_SHARING parameter from EXACT to SIMILAR.  
They can not go back to EXACT because this is a production database.  Once the 
customer gets the error, they can not run SNAP LEVEL 5 at all(only bouncing 
database will fix).  The job runs fine with SNAP LEVEL 0.

DIAGNOSTIC ANALYSIS:
--------------------
Traced with 10046 and queried v$sqlarea at the time of the error:

PARSING IN CURSOR #35 len=1603 dep=1 uid=69 ct=2 lid=69 tim=1019304277966186 
hv=553222570 ad='76a7aec8'
INSERT into stats$sql_summary
            ( snap_id
            , dbid
            , instance_number
            , text_subset
            , sharable_mem
            , sorts
            , module
            , loaded_versions
            , fetches
            , executions
            , loads
            , invalidations
            , parse_calls
            , disk_reads
            , buffer_gets
            , rows_processed
            , command_type
            , address
            , hash_value
            , version_count
            , cpu_time
            , elapsed_time
            , outline_sid
            , outline_category
            , child_latch
            )
       select :b9
            , :b8
            , :b7
            , substrb(sql_text,1,31)
            , sharable_mem
            , sorts
            , module
            , loaded_versions
            , fetches
            , executions
            , loads
            , invalidations
            , parse_calls
            , disk_reads
            , buffer_gets
            , rows_processed
            , command_type
            , address
            , hash_value
            , version_count
            , cpu_time
            , elapsed_time
            , outline_sid
            , outline_category
            , child_latch
         from stats$v$sqlxs
        where is_obsolete = 'N'
          and (   buffer_gets   > :b6
               or disk_reads    > :b5
               or parse_calls   > :b4
               or executions    > :b3
               or sharable_mem  > :b2
               or version_count > :b1
              )
END OF STMT
EXEC 
#35:c=20640000,e=26067137,p=334,cr=11,cu=24,mis=0,r=0,dep=1,og=4,tim=1019304277
966179
ERROR #35:err=1 tim=1297542959
EXEC 
#1:c=42770000,e=49903989,p=871,cr=301,cu=776,mis=0,r=0,dep=0,og=4,tim=101930427
7970178
ERROR #1:err=1 tim=1297542960

Bind variables were not shown.

hv=553222570

Found the hash value in the query output:

   INST_ID HASH_VALUE VERSION_COUNT SQL_TEXT                                   
 
---------- ---------- ------------- ---------------------------------------- 
         1  553222570             1 INSERT into stats$sql_summary              
 
         2  553222570             1 INSERT into stats$sql_summary  

WORKAROUND:
-----------
Bounce instance or run snap at level 0.

RELATED BUGS:
-------------

REPRODUCIBILITY:
----------------
Intermittent

TEST CASE:
----------

STACK TRACE:
------------

SUPPORTING INFORMATION:
-----------------------

24 HOUR CONTACT INFORMATION FOR P1 BUGS:
----------------------------------------

DIAL-IN INFORMATION:
--------------------

IMPACT DATE:
------------

*** 02/04/03 07:09 am *** (CHG: Sta->16)
*** 02/04/03 07:36 am ***
*** 02/04/03 02:43 pm *** 
*** 02/04/03 03:57 pm *** (CHG: Sta->11 Asg->NEW OWNER)
*** 02/04/03 03:57 pm ***
*** 02/13/03 07:15 am ***
Customer is requesting status... do we have any?  thanks.
*** 02/14/03 10:49 am *** 
*** 02/14/03 10:49 am ***

*** 02/14/03 11:42 am *** (CHG: Sta->30)
*** 02/14/03 11:42 am ***
This is not the same problem as those fixed in aforementioned bugs.
STATS$SQL_SUMMARY primary key is
snap_id, dbid, instance_number, hash_value, text_subset.
Previous fixed statspack primary key violations happen on tables not having 
snap_id,dbid,instance_number as part of their primary key.
This exposes them to simultaneous snapshots collisions (on same instance or 
another instance in a RAC configuration).

What is happening here is that we have cursors with same sql text (at least 31 
first characters), same hash_value but a different parent cursor.
This is certainly more a shared cursor or library cache issue (or "feature") 
maybe related to cursor_sharing.

Please spool the output of the following sqlplus script. at the time the 
problem occurs:
--
set pages 1000
-- child cursors with same hash value and sql_text but not same parent
select SQL_TEXT
     , LOADED_VERSIONS
     , OPEN_VERSIONS
     , USERS_OPENING
     , EXECUTIONS
     , LOADS
     , FIRST_LOAD_TIME
     , INVALIDATIONS
     , OPTIMIZER_MODE
     , OPTIMIZER_COST
     , KEPT_VERSIONS
     , ADDRESS
     , TYPE_CHK_HEAP
     , HASH_VALUE
     , PLAN_HASH_VALUE
     , CHILD_NUMBER
     , CHILD_ADDRESS
     , OBJECT_STATUS
     , LITERAL_HASH_VALUE
     , LAST_LOAD_TIME
     , IS_OBSOLETE
from v$sql
where hash_value in ( select max(hash_value)
                        from v$sql
                       group by hash_value
                           , substrb(sql_text,1,31)
                      having count(*) > 1
                         and min(address) != max(address));
-- complete sql_text for these cursors
select sql_text
  from v$sqltext
 where hash_value in (select max(hash_value)
                        from v$sql
                       group by hash_value
                           , substrb(sql_text,1,31)
                      having count(*) > 1
                         and min(address) != max(address))
 order by address, hash_value
     , piece asc;
*** 02/17/03 08:03 am ***

*** 02/17/03 08:04 am *** (CHG: Sta->11)
*** 02/17/03 07:05 pm *** (CHG: Sta->30)
*** 02/17/03 07:05 pm ***
1)Have you applied any rdbms patch in addition to patchsets?
2)Was the problem observed before upgrading to 9014|9202?

The gathered information is very interesting
The following sql is executed twice every 10 seconds:

select x.id, x.classid, x.POLICYBUNDLE, x.ACTIVE, x.PROPERTYBUNDLE, 
x.LOCKTIMEOUT, x.LOCKSTATE, x.LOCKEDFORSESSION, x.LOCKHOLDER from 
odmv_lockobject x where LOCKTIMEOUT <> :"SYS_B_0" and LOCKTIMEOUT <:>
Each time it executes, it generates a distinct child cursor.
There are 75 parent cursors with 1026 invalid child cursors each!
All these child cursors have optimizer_node=NONE, object_status NULL but 
is_obsolete=N .
There is one parent (00000003D1BA2550)with 981 invalid child cursors and 
is_obsolete=N.
The first of these child cursors was loaded at 2003-02-17/07:51:46.
This same parent has 45 valid child cursors with is_obsolete=Y.
The first of these valid/obsolete child was last loaded at 2003-02-17/09:13:40
and the last at 2003-02-17/09:17:20.
Finally there is one "current" parent cursor (00000003CD8107B0) with 583 valid 
cursors and is_obsolete=N.
The first child was last loaded at 2003-02-17/09:17:21 and the last at 
2003-02-17/10:06:23.


The next step would be to generate a library cache dump and run the first query
above (the one on v$sql) .

*** 02/18/03 10:20 am *** (CHG: Sta->11)
*** 02/18/03 10:20 am ***
*** 02/18/03 12:06 pm ***
*** 02/19/03 04:27 am ***
*** 02/27/03 12:26 pm *** (CHG: Sta->16 Asg->NEW OWNER)
*** 02/27/03 12:26 pm ***
*** 02/28/03 03:25 pm *** (CHG: Sta->11 Asg->NEW OWNER)
*** 02/28/03 03:25 pm ***
*** 03/08/03 08:02 pm ***
*** 03/11/03 02:03 pm *** 
*** 03/18/03 01:45 pm *** 
*** 03/19/03 09:45 pm ***
*** 03/25/03 01:03 pm *** 
*** 03/25/03 01:03 pm ***
*** 04/03/03 12:33 pm *** (CHG: Sta->16)
*** 04/03/03 12:33 pm ***
*** 04/03/03 12:34 pm *** 
*** 04/03/03 01:41 pm *** (CHG: Sta->11 Asg->NEW OWNER)
*** 04/03/03 01:42 pm ***
*** 04/03/03 01:42 pm ***
*** 04/04/03 12:25 pm ***
*** 04/15/03 01:57 pm ***
*** 05/05/03 11:08 am *** ESCALATED
*** 05/13/03 06:33 pm *** (CHG: Sta->30)
*** 05/13/03 06:33 pm ***
*** 05/30/03 09:21 am *** (CHG: Sta->11)
*** 05/30/03 09:21 am ***
*** 06/03/03 01:53 pm *** 
*** 06/03/03 01:53 pm ***
*** 06/05/03 10:31 am ***
*** 07/29/03 02:19 pm *** 
*** 07/30/03 11:11 am ***
*** 07/31/03 12:13 pm *** 
*** 07/31/03 12:13 pm ***
*** 07/31/03 12:17 pm *** 
*** 08/12/03 01:22 pm ***
*** 08/27/03 01:36 pm ***
*** 09/02/03 01:52 pm ***
*** 09/03/03 04:43 pm *** (CHG: Sta->80)
*** 09/03/03 04:43 pm *** 
*** 09/03/03 05:31 pm ***
*** 09/04/03 08:09 am *** -> CLOSED