@whoami\n\nSPID SID SERIAL# PID PROCESS DBUSER\n------------------------ ---------- ---------- ---------- ------------------------ --------------------------------------------------------------------------------------------------------------------------------\n1768940 17<\/span> 20768 48 1768938 SYS\n\ncreate table table123 (n number);\n\ninsert into table123<\/span> values (1);<\/code><\/pre>\nVictim:<\/p>\n
SQL> @whoami\n\nSPID SID SERIAL# PID PROCESS DBUSER\n------------------------ ---------- ---------- ---------- ------------------------ --------------------------------------------------------------------------------------------------------------------------------\n1884653 335 14388 51 1884651 SYS\n\n\ntruncate table table123<\/span> ;\n *\nERROR at line 1:\nORA-00054: resource busy and acquire with NOWAIT specified or timeout expired<\/code><\/pre>\nData dictionary<\/h1>\n
As for the first step, I’m checking if the blocker is still holding any locks:<\/p>\n
SELECT session_id\n FROM gv$locked_object v, dba_objects d\n WHERE v.object_id = d.object_id and object_name = 'TABLE123<\/span>' ;\n\nSESSION_ID\n----------\n 17<\/span><\/code><\/pre>\nThat’s all you need to do if the blocker hasn’t released the lock yet.<\/p>\n
Unknown object name<\/h1>\n
In the example above, I knew the name of the locked table because I wrote the SQL statements. But 3rd party applications often obscure this information. In such cases, you can setup the errorstack trace which will provide more information whenever the ORA-00054 occurs:<\/p>\n
ALTER SESSION SET EVENTS '54 trace name errorstack level 3';<\/code><\/pre>\nIn the trace file, we can see the recursive lock statement including the object name for which the error was raised:<\/p>\n
truncate table table123\n *\nERROR at line 1:\nORA-00054: resource busy and acquire with NOWAIT specified or timeout expired\n\n\nORA-00054: resource busy and acquire with NOWAIT specified or timeout expired\n----- Current SQL Statement for this session (sql_id=fmj06n13hfvdh) -----\nLOCK TABLE \"TABLE123<\/span>\" IN EXCLUSIVE MODE NOWAIT<\/code><\/pre>\nWhile the errorstack trace shows the name of the locked object, it doesn’t tell us anything about the blocker. In contrast, system dump provides the full picture.<\/p>\n
System dump<\/h1>\n
The following command configures generating a system dump on the first occurrence of the ORA-00054 error:<\/p>\n
alter system set events '00054 trace name systemstate level 266, lifetime 1';<\/code><\/pre>\nThe grep based on the object name reveals only the information about the victim:<\/p>\n
grep -i table123 \/u00\/oracle\/orabase\/diag\/rdbms\/dkss65c\/DKSS65C\/trace\/DKSS65C_ora_1884653_0001.trc\nObjectName: Name=LOCK TABLE \"TABLE123\" IN EXCLUSIVE MODE NOWAIT\nObjectName: Name=truncate table table123<\/code><\/pre>\nBut with the search based on the object_id we can position ourselves on the entry related to the blocker:<\/p>\n
select object_id from dba_objects where object_name='TABLE123<\/span>' ;\n\n OBJECT_ID\n----------\n 26446<\/span>\n\n1 row selected.<\/code><\/pre>\n!grep -i 26446 DB_ora_1884653_0001.trc\nktubl redo: slt: 15 wrp: 1 flg: 0x0c08 prev dba: 0x00000000 rci: 0 opc: 11.1 [objn: 26446 objd: 26446 tsn: 0]\n DML LOCK: tab=26446<\/span> flg=11 chi=0<\/code><\/pre>\nBy scrolling up, we can find out the address of the process state object that was holding the lock:<\/p>\n
owner: 0x8ff54a00, proc: 0x97e54fc0<\/span><\/code><\/pre>\nBased on the process’ state object address (0x97e54fc0<\/span>), we can get the Oracle process id:<\/p>\nSO: 0x97e54fc0<\/span>, type: process (2), map: 0x9759e9b8\n state: LIVE (0x4532), flags: 0x1\n owner: (nil), proc: 0x97e54fc0\n link: 0x97e54fe0[0x97e54fe0, 0x97e54fe0]\n child list count: 9, link: 0x97e55030[0x94f92630, 0x85d87270]\n conid: 1, conuid: 1, SGA version=(1,0), pg: 0\nSOC: 0x9759e9b8, type: process (2), map: 0x97e54fc0\n state: LIVE (0x99fc), flags: INIT (0x1)\n(process) Oracle pid:48<\/span>, ser:3611, calls cur\/top: (nil)\/0x965bd3f0<\/code><\/pre>\nFinally, we can identify the session id:<\/p>\n
48<\/span>: USER ospid 1821521 sid 17 ser 45047<\/span>, waiting for 'SQL*Net message from client'<\/code><\/pre>\nThe system dump analysis yields the result, but it’s awkward.<\/p>\n
I prefer ASH because the analysis is more user friendly.<\/p>\n
Active session history<\/h1>\n
Luckily, we don’t need to invent the wheel to query ASH. Tanel Poder’s script ash_wait_chains.sql<\/a> displays the relationship between blockers and waiters.<\/p>\nNo information about the blocker, though, was displayed at first.<\/p>\n
@ash_wait_chains \"session_id||' '||sql_opname\" \"session_id=335 and session_serial#=14388\" &hour\n\n-- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http:\/\/blog.tanelpoder.com )\n\n%This SECONDS AAS WAIT_CHAIN FIRST_SEEN LAST_SEEN\n------ ---------- ---------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ ------------------- -------------------\n 100% 4 0 -> 335 TRUNCATE TABLE 2022-06-22 15:04:55 2022-06-22 15:18:57<\/code><\/pre>\nThe reason for the missing blocker information is that the truncate wasn’t waiting on the lock to be released – the error was thrown immediately.<\/p>\n
But if we define a ddl_lock_timeout (default is zero), the blocker information will be recorded:<\/p>\n
alter session set ddl_lock_timeout = 6 ;\n\nSession altered.\n\nSQL> truncate table table123 ;\ntruncate table table123\n *\nERROR at line 1:\nORA-00054: resource busy and acquire with NOWAIT specified or timeout expired\n\n\n@ash_wait_chains \"session_id||' '||sql_opname\" \"session_id=335 and session_serial#=14388\" &hour\n\n-- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http:\/\/blog.tanelpoder.com )\n\n%This SECONDS AAS WAIT_CHAIN FIRST_SEEN LAST_SEEN\n------ ---------- ---------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ ------------------- -------------------\n 60% 6 0 -> 335 TRUNCATE TABLE -> [idle blocker 1,17,45047<\/span> (sqlplus@lsdba04i.vt.ch (TNS V1-V3))] 2022-06-22 15:28:21 2022-06-22 15:28:26<\/code><\/pre>\nConclusion<\/h1>\n
In conclusion, getting the blocker information for the command that failed with “ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired” isn’t trivial. There are several methods to achive this.<\/p>\n
The straightforward way is to query v$locked_object. That will yield the result only if the blocker is still holding the lock. Otherwise, you have to use either ASH or system dump. The former seems more elegant but requires additional licenses.<\/p>\n
The Oracle error message doesn’t show the affected object. If the application hides the failed statement, you can get it from errorstack trace.<\/p>\n
Troubleshooting flow chart<\/h1>\n
![\"\"](\"https:\/\/nenadnoveljic.com\/blog\/wp-content\/uploads\/2022\/06\/ORA-00054-199x300.gif\")
<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"Using system dump, ASH and data dictionary to find the blocker when ORA-00054 was raised Continue Reading