ORA-04021: timeout occurred while waiting to lock object

Products

• Autosys Workload Automation

Issue/Introduction

Customer's scheduler logs showed odd errors like ORA-04021: timeout occurred while waiting to lock object

It seems to have recovered later, any reason why this might happen?

Environment

Release : 11.3.6

Component : CA Workload Automation AE (AutoSys)

Cause

 

[01/24/2022 22:01:10]      CAUAJM_E_18416 Event Server: <ORCL19C1>  Failed Query: <BEGIN :RetVal := ujo_set2act (9,201286013,329033,1643079640); END;>
[01/24/2022 22:01:10]      CAUAJM_E_18402 ORA-04021: timeout occurred while waiting to lock object 
[01/24/2022 22:01:10]      ORA-06512: at "AEDBADMIN.UJO_SET2ACT", line 299
[01/24/2022 22:01:10]      ORA-06512: at line 1
[01/24/2022 22:01:10]      CAUAJM_I_18403 Processing OCI function ODEFIN(34)
[01/24/2022 22:01:10]      CAUAJM_E_18400 An error has occurred while interfacing with ORACLE.
[01/24/2022 22:01:10]      CAUAJM_E_18401 Function <doExecute> invoked from <execute> failed <892>
[01/24/2022 22:01:10]      CAUAJM_E_18416 Event Server: <ORCL19C1>  Failed Query: <BEGIN :RetVal := ujo_post_runtime_info (:I_joid, :I_run_num, :I_ntry, :I_type, :I_seq_num, :I_has_runinfo, :I_run_info); END; <<198750,201286033,1,1,1,7,'WobId(198750.201286033_1/WAAE_WF0.1/MAIN) Jobno(23428) JobLogId(A90469A237A80CB2161E6B674D26F7AE1DCE0C03)'>>>
[01/24/2022 22:01:10]      CAUAJM_E_18402 ORA-04021: timeout occurred while waiting to lock object 
[01/24/2022 22:01:10]      ORA-06512: at "AEDBADMIN.UJO_POST_RUNTIME_INFO", line 66
[01/24/2022 22:01:10]      ORA-06512: at line 1
[01/24/2022 22:01:10]      CAUAJM_I_18403 Processing OCI function ODEFIN(34)
[01/24/2022 22:01:10]      CAUAJM_E_18400 An error has occurred while interfacing with ORACLE.
[01/24/2022 22:01:10]      CAUAJM_E_18401 Function <doExecute> invoked from <execute> failed <892>
[01/24/2022 22:01:10]      CAUAJM_E_18416 Event Server: <ORCL19C1>  Failed Query: <BEGIN :RetVal := ujo_post_runtime_info (:I_joid, :I_run_num, :I_ntry, :I_type, :I_seq_num, :I_has_runinfo, :I_run_info); END; <<274792,201286027,1,1,1,5,'WobId(274792.201286027_1/WAAE_WF0.1/MAIN) Jobno(48692)'>>>
[01/24/2022 22:01:10]      CAUAJM_E_18402 ORA-04021: timeout occurred while waiting to lock object 
[01/24/2022 22:01:10]      ORA-06512: at "AEDBADMIN.UJO_POST_RUNTIME_INFO", line 66
[01/24/2022 22:01:10]      ORA-06512: at line 1
[01/24/2022 22:01:10]      CAUAJM_I_18403 Processing OCI function ODEFIN(34)
[01/24/2022 22:01:10]      CAUAJM_E_18400 An error has occurred while interfacing with ORACLE.
[01/24/2022 22:01:10]      CAUAJM_E_18401 Function <doExecute> invoked from <execute> failed <892>
[01/24/2022 22:01:10]      CAUAJM_E_10619 Return values from dual database writes disagree.  Databases may no longer be synchronized. ID[35] ESA[0] ESB[1]
[01/24/2022 22:01:10]      CAUAJM_E_10160 The execution of the below query experienced an unrecoverable error and will not be retried:
[01/24/2022 22:01:10]      CAUAJM_I_18030 Event Server: <ORCL19C1>  Completed Stored Procedure: <BEGIN :RetVal := ujo_set2act (9,201286013,329033,1643079640); END;>
[01/24/2022 22:01:10]      CAUAJM_I_18030 Event Server: <ORCL19C2>  Completed Stored Procedure: <BEGIN :RetVal := ujo_set2act (9,201286013,329033,1643079640); END;>
[01/24/2022 22:01:10]      CAUAJM_E_10619 Return values from dual database writes disagree.  Databases may no longer be synchronized. ID[87] ESA[0] ESB[1]

 

Resolution

Oracle support identified an issue with Bug 30751171   "ORA-4021 and "qsmqChkOCMV : Timeout while locking object" in alert log while running commit ( Doc ID 30751171.8 ) "

This bug fix is already part of Oracle 19.11 and above.

To check if the above bug fix is enabled / disabled in your environment, please do the following:
----------------------
sqlplus / as sysdba
-- To check current state of bug fix, if below query VALUE returned is 0 (zero), then it's disabled
select value, is_default from v$system_fix_control where bugno = 30751171;

-- If disabled, enable it at SYSTEM level using below statement
alter system set "_fix_control"='30751171:1' scope=both;

-- Verifying after changes, below query returned VALUE should be 1
select bugno, value, is_default from v$system_fix_control where bugno = 30751171;