Re: Reading resource busy error system trace

It looks really strange which you have pointed in the trace file though. Correct me if wrong, So your blocking session/pid for the 'ALTER' statement in the trace is pointing to the same session. And that session has just ended up doing direct path load by post disabling constraints/indexes and is trying to enable the constraints using ALTER command and is failing with Ora-0054. And that to post committing the direct load data. Just a thought, are you doing any DML on the parent table which is linked to this reference constraint which you are trying to enable here?

On Sat, Jul 2, 2022 at 11:27 PM Pap <oracle.developer35_at_gmail.com> wrote:

> Hello All, I followed the blog below and tried debugging the system trace
> to find the blocking session/sql which caused this resource busy
> error, Ora-0054. But I am encountering strange behaviour. It appears to be
> the same session blocking itself.The session which did the direct path load
> and commit seems not releasing exclusive lock for some duration post
> commit. Below are the details of the behaviour. Has anybody
> encountered such a scenario?
>
>
> https://nenadnoveljic.com/blog/troubleshooting-ora-00054-resource-busy-and-acquire-with-nowait-specified-or-timeout-expired/
>
> So the code which is encountering the error is below. Its disabling all
> constraints + Making index unusable and then does direct path load to that
> table and then after while trying to enable the constraint of the same
> table using 'ALTER' and its failing with Ora-0054. The sample code for data
> load and ALTER table is as below.
>
> ****Sample code *****
> INSERT /*+Append*/ INTO TAB1 (c1,c2.....)
> SELECT (ROWNUM + sqq_key) ,col1, col2, col3..... from....tab2,
> tab3, tab4.....;
> COMMIT;
>
> FOR I IN (SELECT TABLE_NAME, CONSTRAINT_NAME FROM ALL_CONSTRAINTS WHERE
> TABLE_NAME = v_table_nm AND CONSTRAINT_TYPE = 'R' AND STATUS = 'DISABLED')
> LOOP
> EXECUTE IMMEDIATE ('ALTER TABLE ' || v_table_nm || ' ENABLE NOVALIDATE
> CONSTRAINT '|| I.CONSTRAINT_NAME);
> END LOOP I;
>
> ********
>
> When i scan through trace file as per the blog step by step, i see below
>
> *Step- 1 -* I searched through the object_Id(101739) for TAB1 and got the
> section below, i.e pointing towards a DML lock on the table. And the
> process state object is proc: 0x243efffc0.
>
> ----------------------------------------
> SO: 0x233cd8bc8, type: DML lock (83), map: 0x237d28a10
> state: LIVE (0x4532), flags: 0x0
> owner: 0x233b9af60, proc: 0x243efffc0
> link: 0x233cd8be8[0x28acf1e58, 0x1d793c780]
> pg: 0
> SOC: 0x237d28a10, type: *DML lock* (83), map: 0x233cd8bc8
> state: LIVE (0x99fc), flags: INIT (0x1)
> DML LOCK: tab=101739 flg=11 chi=0
> his[0]: mod=4 spn=69302
> 2022-07-01 05:44:10.662*:ksq.c_at_10787:ksqdmc(): Enqueue Dump
> (enqueue) TM-00018D6B-00000000-00000000-00000000 DID: ksqlkdid:
> 0001-00CF-000ACD5C
> lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 res_flag: 0x7
> mode: S, lock_flag: 0x20, lock: 0x237d28a38, res: 0x2499f3798
> own: 0x2488605f8, sess: 0x2488605f8, *proc: 0x2403a4510*, prv:
> 0x2499f37a8
> slk: 0x2530967c8
> ----------------------------------------
>
>
> *STEP - 2:-* Then i searched through the trace for the state object
> address i.e. "*SO: 0x243efffc0*" and got below. its pointing to pid:207
> as below.
>
>
> *** 2022-07-01T05:44:10.538156-04:00
> PROCESS 207:
> ----------------------------------------
> *SO: 0x243efffc0*, type: process (2), map: 0x2403a4510
> state: LIVE (0x4532), flags: 0x1
> owner: (nil), proc: 0x243efffc0
> link: 0x243efffe0[0x243efffe0, 0x243efffe0]
> child list count: 15, link: 0x243f00030[0x243b7f190, 0x1d7903b10]
> pg: 0
> SOC: 0x2403a4510, type: process (2), map: 0x243efffc0
> state: LIVE (0x99fc), flags: INIT (0x1)
> (process) *Oracle pid:207,* ser:3445, calls cur/top:
> 0x1a0372f08/0x1d2ee6c70
> flags : (0x0) - icon_uid:0 logon_pdbid=0
> flags2: (0x1000), flags3: (0x510)
> call error: 0, sess error: 0, txn error 0
> intr queue: empty
> (post info) last post received: 0 0 277
> last post received-location: kcl2.h LINE:5703 ID:kclcget
> last process to post me: 0x24c3b2180 1 6
> last post sent: 0 0 33
> last post sent-location: ksa2.h LINE:298 ID:ksasnd
> last process posted by me: 0x24837eaa0 1 6
> waiter on post event: 0
> (latch info) hold_bits=0x0 ud_influx=0x4101b
> (osp latch info) hold_bits=0x0 ud_influx=0x0
> Process Group: DEFAULT, pseudo proc: 0x2484c5d70
> O/S info: user: grid, term: UNKNOWN, ospid: 383076
> OSD pid info:
> Short stack dump:
>
> ksedsts()+426<-ksdxfstk()+58<-ksdxdocmdmultex()+5961<-ksdxdocmdmult()+55<-ksudmp_proc()+1626<-ksudss_main()+1976<-ksudss_opt()+1544<-dbkdaKsdActDriver()+2484<-dbgdaExecuteAction()+354<-dbgdaRunAction()+770<-dbgdRunActions()+83<-dbgdProcessEventActions()+525<-dbgdChkEventKgErr()+394<-dbkdChkEventRdbmsErr()+65<-dbgePostErrorKGE()+1066<-dbkePostKGE_kgsf()+71<-kgeade()+338<-kgeselv()+89<-ksesecl0()+189<-ktaiam()+1110<-ktagetg0()+929<-ktagetp_internal()+141<-ktagetg_ddlX()+323<-ktagetg_ddl()+30<-kkdllk0()+1551<-kkdcprc()+711<-kkdcmco()+3682<-atbadd()+8770<-atbdrv()+14663<-opiexe()+30061<-opiosq0()+4575<-opipls()+14619<-opiodr()+1202<-rpidrus()+198<-skgmstack()+65<-rpidru()+132<-rpiswu2()+614<-rpidrv()+1494<-psddr0()+467<-psdnal()+646<-pevm_EXIM()+276<-pfrinstr_EXIM()+43<-pfrrun_no_tool()+52<-pfrrun()+902<-plsql_run()+755<-peicnt()+279<-kkxexe()+720<-opiexe()+24762<-kpoal8()+2226<-opiodr()+1202<-ttcpip()+1239<-opitsk()+1897<-opiino()+936<-opiodr()+1202<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
>
> KGL-UOL (Process state object)
> KGX Atomic Operation Log 0x2403a5690
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a56f8
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a5760
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a57c8
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a5830
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a5898
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a5900
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a5968
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> KGX Atomic Operation Log 0x2403a59d0
> Mutex (nil)(0, 0) idn 0 oper NONE(0)
> FSO mutex uid 262142 efd 0 whr 0 slp 0
> ----------------------------------------
>
>
> *Step-3 :- * Then searching for the *pid-207* in the start of the trace
> , i found *sid - 1072 ser 23 *and its pointing to the same ALTER TABLE
> statement. The OSPID is the same one for which the trace gets generated.
> And if I try to see the DML in this sesion before this ALTER it's the same
> one, which has just finished up doing the COMMIT for the direct path load.
>
> So I am wondering , is it possible that we are hitting any bug due to
> which Oracle is actually not releasing the Exclusive table lock immediately
> post Commit of the direct path load ? And that is why , even if we are
> trying to do the ALTER post COMMIT in the same session we are hitting
> Ora-0054 as it blocks itself? And then should we put some wait/sleep
> statement post commit i.e. before the ALTER to avoid this bug?
>
> 207: USER ospid 383076 sid 1072 ser 23,
> Cmd: ALTER TABLE
>
> On Mon, Jun 13, 2022 at 4:28 PM Pap <oracle.developer35_at_gmail.com> wrote:
>
>> Thank You So much Nenad.
>>
>> Unfortunately while checking with the team got to know that the other
>> trace files has been removed from the location. So i will wait for the next
>> occurrence of the error to capture and analyze all the traces wrt that one
>> ospid.
>>
>>
>> On Sun, 12 Jun 2022, 9:24 pm Noveljic Nenad, <nenad.noveljic_at_vontobel.com>
>> wrote:
>>
>>> Your system dump apparently consists of several files.
>>>
>>>
>>>
>>> At the very beginning of the system dump there must be a section that
>>> identifies the blockers for each process and looks something like this:
>>>
>>> 157: USER ospid 1385877 sid 786 ser 49681, waiting for 'log file switch
>>> (checkpoint incomplete)'
>>>
>>> Cmd: INSERT
>>>
>>> Blocked by inst: 1, sid: 266, ser: 13238
>>>
>>> Final Blocker inst: 1, sid: 266, ser: 13238
>>>
>>> 159: USER ospid 1295896 sid 796 ser 48963, waiting for 'log file switch
>>> (checkpoint incomplete)'
>>>
>>> Cmd: INSERT
>>>
>>> Blocked by inst: 1, sid: 266, ser: 13238
>>>
>>> Final Blocker inst: 1, sid: 266, ser: 13238
>>>
>>>
>>>
>>> First, check who was blocking the Powercenter process with ospid 89092
>>> (Blocked by…). Then search **all** system dump trace files (**89092**.trc)
>>> for the blocker to look at its state objects. Once you now the sid and
>>> serial of the blocker, you can position yourself to its state objects with
>>> the following search expression: sid: xxx ser: xxx . One of the state
>>> objects will be for the cursor that blocked your DDL on MAIN_TAB.
>>>
>>>
>>>
>>> Best regards,
>>>
>>>
>>>
>>> Nenad
>>>
>>>
>>>
>>> *From:* Pap <oracle.developer35_at_gmail.com>
>>> *Sent:* Sonntag, 12. Juni 2022 14:06
>>> *To:* Noveljic Nenad <nenad.noveljic_at_vontobel.com>
>>> *Cc:* Oracle L <oracle-l_at_freelists.org>
>>> *Subject:* Re: Reading resource busy error system trace
>>>
>>>
>>>
>>> Thank You Nenad.
>>>
>>> So actually here the session/Alter statement, which failed, is from the
>>> informatica power center session only. So do you mean we should search the
>>> body of the original trace file from which this trace continued from i.e "u01/app/oracle/diag/rdbms/DB1p/DB11/trace/DB11_ora_89092_8.trc"
>>> rather this one. And in that trace the sql statements near the "final
>>> blocker" string will be the cause of this error?
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> ____________________________________________________
>>>
>>> Please consider the environment before printing this e-mail.
>>>
>>> Bitte denken Sie an die Umwelt, bevor Sie dieses E-Mail drucken.
>>>
>>>
>>> Important Notice
>>>
>>> This message is intended only for the individual named. It may contain
>>> confidential or privileged information. If you are not the named addressee
>>> you should in particular not disseminate, distribute, modify or copy this
>>> e-mail. Please notify the sender immediately by e-mail, if you have
>>> received this message by mistake and delete it from your system.
>>> Without prejudice to any contractual agreements between you and us which
>>> shall prevail in any case, we take it as your authorization to correspond
>>> with you by e-mail if you send us messages by e-mail. However, we reserve
>>> the right not to execute orders and instructions transmitted by e-mail at
>>> any time and without further explanation.
>>> E-mail transmission may not be secure or error-free as information could
>>> be intercepted, corrupted, lost, destroyed, arrive late or incomplete. Also
>>> processing of incoming e-mails cannot be guaranteed. All liability of
>>> Vontobel Holding Ltd. and any of its affiliates (hereinafter collectively
>>> referred to as "Vontobel Group") for any damages resulting from e-mail use
>>> is excluded. You are advised that urgent and time sensitive messages should
>>> not be sent by e-mail and if verification is required please request a
>>> printed version.
>>> Please note that all e-mail communications to and from the Vontobel
>>> Group are subject to electronic storage and review by Vontobel Group.
>>> Unless stated to the contrary and without prejudice to any contractual
>>> agreements between you and Vontobel Group which shall prevail in any case,
>>> e-mail-communication is for informational purposes only and is not intended
>>> as an offer or solicitation for the purchase or sale of any financial
>>> instrument or as an official confirmation of any transaction.
>>> The legal basis for the processing of your personal data is the
>>> legitimate interest to develop a commercial relationship with you, as well
>>> as your consent to forward you commercial communications. You can exercise,
>>> at any time and under the terms established under current regulation, your
>>> rights. If you prefer not to receive any further communications, please
>>> contact your client relationship manager if you are a client of Vontobel
>>> Group or notify the sender. Please note for an exact reference to the
>>> affected group entity the corporate e-mail signature. For further
>>> information about data privacy at Vontobel Group please consult
>>> www.vontobel.com.
>>>
>>

--
http://www.freelists.org/webpage/oracle-l