ORA-01013: user requested cancel of current operation

Following OEM alerts are received from databases of 11R2 to 12R2:

...
..
.
Target name=RACTEST
Incident creation time=28/11/2017 9:48:17 PM AEDT 
Last updated time=28/11/2017 9:48:17 PM AEDT 
Message= ORA-01013: user requested cancel of current operation 
Severity=Critical 
Incident ID=294770 
...
..
.

CAUSES

SQL ID 4d43by1zzjfna runs slowly until failed with ‘ORA-01013’ error.

SOLUTION

As per “low Performance Oracle Enterprise Manager SQL Metrics SQL statement (SQL ID: 4d43by1zzjfna) Automatically Run (Doc ID 2266608.1)”, the fololowing actions are taken :

(a) Stopping EM agent monitoring the RAC instance(s).

$AGENT_HOME/bin/emctl stop agent

(b) Test the current execution time ( 36 s ), and record the execution plan via SQL PLUS:

SQL> set timing on
SQL> set autotrace on
SQL> WITH last_run AS
 (
 SELECT all_runs.OWNER ,
 all_runs.JOB_NAME,
 all_runs.STATUS
 FROM DBA_SCHEDULER_JOB_RUN_DETAILS all_runs,
 (
 SELECT OWNER ,
 JOB_NAME,
 MAX(ACTUAL_START_DATE) AS START_DATE
 FROM DBA_SCHEDULER_JOB_RUN_DETAILS
 GROUP BY OWNER,
 JOB_NAME
 )
 latest_runs
 WHERE all_runs.OWNER = latest_runs.OWNER
 AND all_runs.JOB_NAME = latest_runs.JOB_NAME
 AND all_runs.ACTUAL_START_DATE=latest_runs.START_DATE
...
..
.

SUM(BROKEN) SUM(FAILED)
----------- -----------
 0          0

Elapsed: 00:00:36.49

Execution Plan
----------------------------------------------------------
Plan hash value: 204035645
...
..
.
Statistics
----------------------------------------------------------
 338   recursive calls
 0     db block gets
 58842 consistent gets
 0     physical reads
 0     redo size
 603   bytes sent via SQL*Net to client
 524   bytes received via SQL*Net from client
 2     SQL*Net roundtrips to/from client
 8671  sorts (memory)
 0     sorts (disk)
 1 rows processed

c)Purge any job history that is no longer needed to reduce the size of job related tables:

SQL> exec DBMS_SCHEDULER.PURGE_LOG(7,which_log=>'JOB_LOG');

PL/SQL procedure successfully completed.
Elapsed: 00:00:04.95

SQL> exec DBMS_SCHEDULER.PURGE_LOG(7,which_log=>'WINDOW_LOG');

PL/SQL procedure successfully completed.
Elapsed: 00:00:00.03

SQL> exec DBMS_SCHEDULER.PURGE_LOG(log_history => 7, job_name => 'job1, sys.class2');

PL/SQL procedure successfully completed.
Elapsed: 00:00:00.04

SQL> exec DBMS_SCHEDULER.SET_SCHEDULER_ATTRIBUTE('log_history','7');

PL/SQL procedure successfully completed.
Elapsed: 00:00:00.02

d) Regather statistics to ensure that the CBO has the right understanding of cardinality/cost for execution plans involving JOB related tables:

SQL> EXEC DBMS_STATS.GATHER_FIXED_OBJECTS_STATS;

PL/SQL procedure successfully completed.
Elapsed: 00:01:26.37

SQL> EXEC DBMS_STATS.GATHER_DICTIONARY_STATS;

PL/SQL procedure successfully completed.
Elapsed: 00:01:35.82

SQL> EXEC DBMS_STATS.GATHER_SCHEMA_STATS ('SYS');

PL/SQL procedure successfully completed.
Elapsed: 00:10:53.24

e) rerun the same sql_id=’4d43by1zzjfna’. We can see there is a new execution plan. The running time is shorted from 36 seconds from 1 second.

SQL> WITH last_run AS
 2 (
 3 SELECT all_runs.OWNER ,
 4 all_runs.JOB_NAME,
 5 all_runs.STATUS
 6 FROM DBA_SCHEDULER_JOB_RUN_DETAILS all_runs,
 7 (
 8 SELECT OWNER ,
 9 JOB_NAME,
 10 MAX(ACTUAL_START_DATE) AS START_DATE
 11 FROM DBA_SCHEDULER_JOB_RUN_DETAILS
 12 GROUP BY OWNER,
 13 JOB_NAME
 14 )
 15 latest_runs
 16 WHERE all_runs.OWNER = latest_runs.OWNER
 17 AND all_runs.JOB_NAME = latest_runs.JOB_NAME
 18 AND all_runs.ACTUAL_START_DATE=latest_runs.START_DATE
 19 )
 20 SELECT SUM(broken),
 21 SUM(failed)
 22 FROM
 23 (
 24 SELECT DECODE(broken, 'N', 0, 1) broken,
 25 DECODE(NVL(failures,0), 0, 0, 1) failed
 26 FROM dba_jobs
 27 UNION ALL
 28 SELECT DECODE(STATE,'BROKEN',1,0) broken,
 29 DECODE(STATUS ,'FAILED',DECODE(STATE,'BROKEN',0,'DISABLED',0,1),0) failed
 30 FROM
 31 (
 32 SELECT all_jobs.OWNER ,
 33 all_jobs.JOB_NAME,
 34 last_run.STATUS ,
 35 all_jobs.STATE
 36 FROM last_run,
 37 DBA_SCHEDULER_JOBS all_jobs
 38 WHERE last_run.OWNER =all_jobs.OWNER
 39 AND last_run.JOB_NAME=all_jobs.JOB_NAME
 40 )
 41 )
 42 /

SUM(BROKEN) SUM(FAILED)
----------- -----------
 0           0

Elapsed: 00:00:01.00

Execution Plan
----------------------------------------------------------
Plan hash value: 2148836375
...
..
.
Statistics
----------------------------------------------------------
 50   recursive calls
 0    db block gets
 3585 consistent gets
 0    physical reads
 0    redo size
 603  bytes sent via SQL*Net to client
 524  bytes received via SQL*Net from client
 2    SQL*Net roundtrips to/from client
 51   sorts (memory)
 0    sorts (disk)
 1 rows processed

(f) Re-enable EM Agents monitoring the RAC instance(s):