Application job failed with trace file contents:
*** 2018-06-16 11:03:17.044
*** SESSION ID:(2437.25769) 2018-06-16 11:03:17.044
*** CLIENT ID:() 2018-06-16 11:03:17.044
*** SERVICE NAME:(BATCH) 2018-06-16 11:03:17.044
*** MODULE NAME:(DBMS_SCHEDULER) 2018-06-16 11:03:17.044
*** ACTION NAME:(IMMEDIATE16_06_2018_10_10_01) 2018-06-16 11:03:17.044
ORA-12012: error on auto execute of job "BATCH"."IMMEDIATE16_06_2018_10_10_01"
ORA-04021: timeout occurred while waiting to lock object
ORA-06512: at "BATCH.AP_DATA_PROCESS", line 652
ORA-06512: at line 1
Check the session details from ASH history:
set pagesize 100
set linesize 250
col INSTANCE_NUMBER format 99
col SESSION_ID format 99999
col BLOCKING_INST_ID format 99
col event format a20
col WAIT_CLASS format a15
col PROGRAM format a20
col MODULE format a16
col p3 format 99999999999999999999
select sql_id,to_char(SAMPLE_TIME,'YYYYMMDD-HH24:MI:SS'),
INSTANCE_NUMBER,SESSION_ID,PROGRAM,MODULE,EVENT,
CURRENT_OBJ#,WAIT_CLASS,BLOCKING_INST_ID,
BLOCKING_SESSION, p3
from dba_hist_active_sess_history
where INSTANCE_NUMBER= 3
and SESSION_ID = 2437
and sample_time between to_date('16-06-18 11:00:00','DD-MM-YY HH24:MI:SS')
and to_date('16-06-18 11:04:00','DD-MM-YY HH24:MI:SS')
and event ='library cache lock'
order by sample_id;
SQL_ID TO_CHAR(SAMPLE_TI INSTANCE_NUMBER SESSION_ID PROGRAM MODULE EVENT CURRENT_OBJ# WAIT_CLASS BLOCKING_INST_ID BLOCKING_SESSION P3
------------- ----------------- --------------- ---------- -------------------- ---------------- -------------------- ------------ --------------- ---------------- ---------------- ---------------------
...
..
6cp7dp2xgxr6m 20180616-11:02:52 3 2437 oracle@racnode3 (J001) DBMS_SCHEDULER library cache lock 27307391 Concurrency 2 5205 76355447552016387
6cp7dp2xgxr6m 20180616-11:03:02 3 2437 oracle@racnode3 (J001) DBMS_SCHEDULER library cache lock 27307391 Concurrency 2 5205 76355447552016387
6cp7dp2xgxr6m 20180616-11:03:12 3 2437 oracle@rcanode3 (J001) DBMS_SCHEDULER library cache lock 27307391 Concurrency 2 5205 76355447552016387
20 rows selected.
The OBJ# matches the DDL command:
ALTER INDEX BATCH.CDR_IND REBUILD SUBPARTITION CDR_IND_SUB_213;
SQL>select OWNER,OBJECT_NAME,SUBOBJECT_NAME, OBJECT_TYPE,STATUS,LAST_DDL_TIME from dba_objects where OBJECT_ID=27307391; OWNER OBJECT_NAME SUBOBJECT_NAME OBJECT_TYPE STATUS LAST_DDL_ ----- ----------- -------------- ------------------ ------ -------- BATCH CDR_IND CDR_IND_SUB_213 INDEX SUBPARTITION VALID 20180616-12:39:22
The P3 shows the waiting object details, we can see the session failed because of waiting for object CDR, which is holding by blocking session 5205 on node 2.
SQL> select lpad('Library cache P3 value: ',50,'.')||76355447552016387 from dual; ..........................Library cache P3 value: 76355447552016387
SQL> select lpad('Library cache P3 value HEX: ',50,'.')||to_char(76355447552016387,'xxxxxxxxxxxxxxxxxxxxx') from dual;
.....................Library cache P3 value HEX: 10f44e000010003
SQL> select lpad('Object ID: ',50,'.')||to_number(substr('10f44e000010003',1,length('10f44e000010003')-8 ),'xxxxxxxxxxxxxx') from dual;
...........Object ID: 17777888
SQL> select lpad('Namespace: ',50,'.')||to_number(substr('10f44e000010003',-8,4),'xxxxxxxxxxxxxx') from dual;
.......................................Namespace: 1
SQL> select lpad('RequestMode: ',50,'.')||decode(to_number(substr('10f44e000010003',-4),'xxxxxxxxxxxxxx'),3,'exclusive mode',2,'share mode',1,'null mode',0,'no lock/pin held','unknown') from dual;
.....................................RequestMode: exclusive mode
SQL> SELECT indx,kglstdsc FROM x$kglst WHERE kglsttyp='NAMESPACE' and indx=1;
1 TABLE/PROCEDURE
SQL>select OWNER,OBJECT_NAME,SUBOBJECT_NAME,OBJECT_TYPE,NAMESPACE from dba_objects where object_id=17777888; OWNER OBJECT_NAME SUBOBJECT_NAME OBJECT_TYPE NAMESPACE ---------------- ----------------------- --------------------------------- ------------------------ ----------------- BATCH CDR TABLE 1
Check blocking session details on racnode2, and found it is running DBMS_STATS against waiting object CDR from racnode3 .
b6usrg82hwsa3 20180616-11:02:56 2 5205 oracle@racnode2 (J032) DBMS_SCHEDULER row cache lock 18 Concurrency 0 2999959 GLOBAL
b6usrg82hwsa3 20180616-11:03:06 2 5205 oracle@racnode2 (J032) DBMS_SCHEDULER row cache lock 18 Concurrency 0 0 GLOBAL
b6usrg82hwsa3 20180616-11:03:16 2 5205 oracle@racnode2 (J032) DBMS_SCHEDULER row cache lock 18 Concurrency 0 1953712 GLOBAL
4m477zx25xrgq 20180616-11:03:26 2 5205 oracle@racnode2 (J032) DBMS_SCHEDULER 27307236 321 0 NOT IN WAIT
4m477zx25xrgq 20180616-11:03:36 2 5205 oracle@racnode2 (J032) DBMS_SCHEDULER 27307242 1582 0 NOT IN WAIT
4m477zx25xrgq 20180616-11:03:46 2 5205 oracle@racnode2 (J032) DBMS_SCHEDULER 27307219 1537 0 NOT IN WAIT
SQL> select sql_text from v$sql where sql_id='b6usrg82hwsa3';
SQL_TEXT
-------------------------------------------------------------------
call dbms_stats.gather_database_stats_job_proc ( )
SQL>se long 10000
SQL> select SQL_FULLTEXT from v$sql where sql_id='4m477zx25xrgq';
SQL_FULLTEXT
--------------------------------------------------------------------
/* SQL Analyze(1) */ select /*+ full(t) no_parallel(t) no_parallel_index(t)
dbms_stats cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monito
....
from "BATCH"."CDR" t
where TBL$OR$IDX$PART$NUM("BATCH"."CDR",0,3,0,"ROWID") = :objn /*
NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL
,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV
,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,ACL,NIL,NIL*/
The blocking session ID 5205 on node 2 is running a weekend maintenance job –“Optimizer Statistics Gathering”. it is analysing partition table CDR.
There are a lot of discussions about “library cache lock” from DBMS_STATS gather of stats for a subpartition.
19790972 – “library cache lock” waits due to DBMS_STATS gather of stats for a sub partition
Workaround
Under the approval of Oracle Support, you can try to change below parameter value from 15 mins to longer time.
SQL>alter system set "_kgl_time_to_wait_for_locks'=60 scope=spfile; SQL>shutdown immediate; SQL>startup