ORA-12751: cpu time or run time policy violation

There is an overnight auto-purge job failure every day by throwing “ORA-12751: cpu time or run time policy violation” error.

Extracted trace file from slave process ( m001 ) of  Manageability Monitor Process ( MMON) :

*** 2017-02-01 01:11:39.393
*** SESSION ID:(9.3069) 2017-02-01 01:11:39.393
*** CLIENT ID:() 2017-02-01 01:11:39.393
*** SERVICE NAME:(SYS$BACKGROUND) 2017-02-01 01:11:39.393
*** MODULE NAME:(MMON_SLAVE) 2017-02-01 01:11:39.393
*** ACTION NAME:(Auto-Purge Slave Action) 2017-02-01 01:11:39.393
...
..
----- START DDE Action: 'ORA_12751_DUMP' (Sync) -----
CPU time exceeded 300 seconds
Time limit violation detected at:
ksedsts()+465<-kspol_12751_dump()+145<-dbgdaExecuteAction()+1065<-dbgerRunAction()+109<-dbgerRunActions()+4134<-dbgexPhaseII()+1873<-dbgexProcessError()+2680<-dbgeExecuteForError()+88<-dbgePostErrorKGE()+2136<-dbkePostKGE_kgsf()+71<-kgeselv()+276<-ksesecl0()+162
<-ksucin()+147<-delrow()+13790<-qerdlFetch()+1822<-delexe()+1001<-opiexe()+10315<-kpoal8()+2380<-opiodr()+917<-kpoodrc()+36<-rpiswu2()+1776<-kpoodr()+636<-upirtrc()+2436<-kpurcsc()+98<-kpuexec()+10790<-OCIStmtExecute()+39<-kewrose_oci_stmt_exec()+55<-kewrgwxf1_gwrsql_exft_1()+317
<-kewrgwxf_gwrsql_exft()+496<-kewrdsr1_delete_snaprange_1()+476<-kewrdsr_delete_snapshot_range()+133<-kewrpanp_purge_all_nonpts()+923<-kewrpdc_periodic_cleanup()+41<-kewrsnrm_snapshot_removal()+169<-kewrpsr_purge_snapshot_range()+116<-kewrapad_auto_purge_all_dbids()+682
<-kewraps_auto_purge_slave()+942<-kebm_slave_main()+586<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253Current Wait Stack:
...
..
.
*** 2017-02-01 01:15:05.083
*** KEWROCISTMTEXEC - encountered error: (ORA-12751: cpu time or run time policy violation
)
 *** SQLSTR: total-len=351, dump-len=240,
 STR={delete from WRH$_SYSMETRIC_HISTORY tab where (:beg_snap <= tab.snap_id and tab.snap_id <= :end_snap and dbid = :dbid) and not exists (select 1 from WRM$_BASELINE b where (tab.dbid = b.dbid) and }

We can see there is a 300 seconds ( 5 minutes ) CPU time  limitation resource violation.

Checking the problem query execution plan, we can see there are two tables and  indexes are involved respectively:

-------------------------------------------------------------------
| Id | Operation                    | Name 
------------------------------------------------------------------
| 0  | DELETE STATEMENT 
| 1  | DELETE                       | WRH$_SYSMETRIC_HISTORY 
|* 2 | FILTER 
|* 3 | INDEX RANGE SCAN             | WRH$_SYSMETRIC_HISTORY_INDEX 
|* 4 | TABLE ACCESS BY INDEX ROWID  | WRM$_BASELINE 
|* 5 | INDEX RANGE SCAN             | WRM$_BASELINE_PK 
-----------------------------------------------------------------

Checking the size of above four segments size, it looks like table WRH$_SYSMETRIC_HISTORY is fragmented.

 MB         SEGMENT_NAME                 SEGMENT_TYPE
---------- ----------------------------- ------------------
 1458.4    WRH$_SYSMETRIC_HISTORY_INDEX  INDEX
 1644.9    WRH$_SYSMETRIC_HISTORY        TABLE
...
..
.
     .0625 WRM$_BASELINE                 TABLE
     .0625 WRM$_BASELINE_PK              INDEX

Checking WRH$_ tables and found some table’s statistics are locked :

SQL> select STATTYPE_LOCKED,owner, table_Name,PARTITION_NAME,NUM_ROWS,SAMPLE_SIZE,LAST_ANALYZED from dba_tab_statistics where STATTYPE_LOCKED is not null and table_name like 'WRH$_%';

STATT OWNER TABLE_NAME PARTITION_NAME NUM_ROWS SAMPLE_SIZE LAST_ANAL
----- ------------------------------ ------------------------------ ------------------------------ ---------- ----------- ---------
ALL SYS WRH$_SEG_STAT WRH$_SEG_ST_1383987976_2740 9678 9678 05-MAY-12
ALL SYS WRH$_MVPARAMETER WRH$_MVPARA_1383987976_2668 7770 7770 05-MAY-12
ALL SYS WRH$_INTERCONNECT_PINGS WRH$_INTERC_1383987976_2668 333 333 05-MAY-12
ALL SYS WRH$_EVENT_HISTOGRAM WRH$_EVENT__1383987976_2668 69646 69646 05-MAY-12
ALL SYS WRH$_INST_CACHE_TRANSFER WRH$_INST_C_1383987976_2668 860 860 05-MAY-12
ALL SYS WRH$_SERVICE_WAIT_CLASS WRH$_SERVIC_1383987976_2668 2583 2583 05-MAY-12
ALL SYS WRH$_SYS_TIME_MODEL WRH$_SYS_TI_1383987976_2668 2109 2109 05-MAY-12
ALL SYS WRH$_OSSTAT WRH$_OSSTAT_1383987976_2668 2442 2442 05-MAY-12
ALL SYS WRH$_TABLESPACE_STAT WRH$_TABLES_1383987976_2668 295 295 05-MAY-12
ALL SYS WRH$_ACTIVE_SESSION_HISTORY WRH$_ACTIVE_1383987976_2668 3517 3517 05-MAY-12
ALL SYS WRH$_SERVICE_STAT WRH$_SERVIC_1383987976_2668 12432 12432 05-MAY-12
ALL SYS WRH$_DLM_MISC WRH$_DLM_MI_1383987976_2668 11766 11766 05-MAY-12
ALL SYS WRH$_LATCH WRH$_LATCH_1383987976_3076 61383 61383 05-MAY-12
ALL SYS WRH$_SQLSTAT WRH$_SQLSTA_1383987976_3412 9304 9304 05-MAY-12
ALL SYS WRH$_DB_CACHE_ADVICE WRH$_DB_CAC_1383987976_3004 2331 2331 05-MAY-12
ALL SYS WRH$_LATCH_MISSES_SUMMARY WRH$_LATCH__1383987976_3004 1399 1399 05-MAY-12
ALL SYS WRH$_WAITSTAT WRH$_WAITST_1383987976_3340 1998 1998 05-MAY-12
ALL SYS WRH$_SYSTEM_EVENT WRH$_SYSTEM_1383987976_3340 20960 20960 05-MAY-12
ALL SYS WRH$_PARAMETER WRH$_PARAME_1383987976_2956 39627 39627 05-MAY-12
ALL SYS WRH$_SYSSTAT WRH$_SYSSTA_1383987976_2956 70818 70818 05-MAY-12
ALL SYS WRH$_SGASTAT WRH$_SGASTA_1383987976_2956 2510 2510 05-MAY-12
ALL SYS WRH$_ROWCACHE_SUMMARY WRH$_ROWCAC_1383987976_2956 6327 6327 05-MAY-12

22 rows selected.

Unlocking the tables and partitions stats by :

SQL>exec dbms_stats.gather_table_stats(ownname=>'SYS',tabname=>'WRH$_EVENT_HISTOGRAM');
PL/SQL procedure successfully completed.

SQL> exec DBMS_STATS.UNLOCK_PARTITION_STATS ('SYS','WRH$_MVPARAMETER','WRH$_MVPARA_1383987976_2668');
PL/SQL procedure successfully completed.

...
..
.

Manually collect the stats of WRH$_tables by running the below script , and then execute every statement as SYS user.

SQL> select 'exec dbms_stats.gather_table_stats('||''''||owner||''''||','||''''||TABLE_NAME||''''||', cascade => TRUE );' FROM dba_tables where owner='SYS' and TABLE_NAME like 'WRH$_%' and TABLESPACE_NAME='SYSAUX' order by LAST_ANALYZED;

'EXECDBMS_STATS.GATHER_TABLE_STATS('||''''||OWNER||''''||','||''''||TABLE_NAME||''''||',CASCADE=>TRUE);'
------------------------------------------------------------------------------------------------------------------------
exec dbms_stats.gather_table_stats('SYS','WRH$_LATCH_NAME', cascade => TRUE );
exec dbms_stats.gather_table_stats('SYS','WRH$_PARAMETER_NAME', cascade => TRUE );
exec dbms_stats.gather_table_stats('SYS','WRH$_STAT_NAME', cascade => TRUE );
...
..
.
SQL> exec dbms_stats.gather_table_stats('SYS','WRH$_LATCH_NAME', cascade => TRUE );
PL/SQL procedure successfully completed.
...
..
.

Manually re-organize the big tables and their indexes, for example table “WRH$_SYSMETRIC_HISTORY” and its index “WRH$_SYSMETRIC_HISTORY_INDEX”.

SQL> alter table WRH$_SYSMETRIC_SUMMARY move tablespace SYSAUX;
Table altered.

SQL> select index_name,status from dba_indexes where table_name='WRH$_SYSMETRIC_SUMMARY';
INDEX_NAME                     STATUS
------------------------------ --------
WRH$_SYSMETRIC_SUMMARY_INDEX   UNUSABLE

SQL> alter index WRH$_SYSMETRIC_SUMMARY_INDEX rebuild online;
Index altered.

Checking the table and its index size after rebuilding, we can see the size is significantly reduced from around 1.5GB to 50MB only.

SQL> select owner,segment_name, bytes/1024/1024 from dba_segments where segment_name like 'WRH$_SYSMETRIC_HISTOR%';

OWNER SEGMENT_NAME               BYTES/1024/1024
------------------------------   ----------------
SYS  WRH$_SYSMETRIC_HISTORY      54
SYS WRH$_SYSMETRIC_HISTORY_INDEX 46

Manually purge the snapshots from old database :

SQL> select dbid from v$database;

DB Id
-----------
3550044136

SQL> select DBID,min(SNAP_ID),max(SNAP_ID), count(*) from WRH$_SYSMETRIC_HISTORY group by DBID;

 DB Id      MIN(SNAP_ID) MAX(SNAP_ID) COUNT(*)
----------- ------------ ------------ ----------
 1383987976 8000         13444        19582440
 3550044136 2292          2710        1005380 <------------ CURRENT DB


SQL>EXECUTE DBMS_WORKLOAD_REPOSITORY.DROP_SNAPSHOT_RANGE( 8000, 13444,1383987976       );

After manually purging, checking again and all looks good:

SQL> select DBID,min(SNAP_ID),max(SNAP_ID), count(*) from WRH$_SYSMETRIC_HISTORY group by DBID;

 3550044136 2292          2710        1005380 <------------ CURRENT DB

SQL> select distinct DBID,INSTANCE_NUMBER from WRH$_SYSMETRIC_HISTORY ;

 DBID        INSTANCE_NUMBER
----------   ---------------
3550044136   1
3550044136   2

Run “awrinfo.sql” to review all the information:

SQL> @$ORACLE_HOME/rdbms/admin/awrinfo.sql

APPENDIX   —  Reorganize Table Partitions and Index Partitions

SQL>  select owner, segment_name, partition_name, segment_type, bytes/1024/1024  from dba_segments where tablespace_name='SYSAUX' and bytes/1024/1024>200 order by 1,2;


OWNER    SEGMENT_NAME                   SEGMENT_TYPE        BYTES/1024/1024
-------- ------------------------------ ----------------- ---------------
SYS      WRH$_PARAMETER_PK              INDEX PARTITION    860
SYS      WRH$_SYSSTAT                   TABLE PARTITION    998
SYS      WRH$_LATCH_PK                  INDEX PARTITION   1283
SYS      WRH$_LATCH_MISSES_SUMMARY      TABLE PARTITION   1474
SYS      WRH$_SYSSTAT_PK                INDEX PARTITION   1477
SYS      WRH$_LATCH                     TABLE PARTITION   1611
SYS      WRH$_LATCH_MISSES_SUMMARY_PK   INDEX PARTITION   1985
SYS      WRH$_SQLSTAT                   TABLE PARTITION   2487
SYS      WRH$_EVENT_HISTOGRAM           TABLE PARTITION   3210
SYS      WRH$_ACTIVE_SESSION_HISTORY    TABLE PARTITION   3650
SYS      WRH$_EVENT_HISTOGRAM_PK        INDEX PARTITION   4486

SQL> select partition_name from dba_tab_partitions where table_name='WRH$_SERVICE_STAT';

PARTITION_NAME
------------------------------
WRH$_SERVIC_3132096013_31705
WRH$_SERVICE_STAT_MXDB_MXSN


SQL> alter table WRH$_SERVICE_STAT move partition WRH$_SERVICE_STAT_MXDB_MXSN tablespace SYSAUX;

Table altered.

SQL> alter table WRH$_SERVICE_STAT move partition WRH$_SERVIC_3132096013_31705 tablespace SYSAUX;

Table altered.

SQL> select index_name from dba_indexes where table_name='WRH$_SERVICE_STAT';

INDEX_NAME
------------------------------
WRH$_SERVICE_STAT_PK

SQL> select partition_name from dba_ind_partitions where index_name='WRH$_SERVICE_STAT_PK';

PARTITION_NAME
------------------------------
WRH$_SERVICE_STAT_MXDB_MXSN
WRH$_SERVIC_3132096013_31705

SQL> alter index WRH$_SERVICE_STAT_PK rebuild partition WRH$_SERVICE_STAT_MXDB_MXSN;

Index altered.

SQL> alter index WRH$_SERVICE_STAT_PK rebuild partition WRH$_SERVIC_3132096013_31705;

Index altered.


SQL> select distinct status from dba_indexes;

STATUS
--------
VALID
N/A

SQL> select distinct status from dba_ind_partitions;

STATUS
--------
USABLE

 

Advertisements
This entry was posted in AWR, Performance Tunning and tagged , , , , , , , , . Bookmark the permalink.

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