Re: PL/SQL lock timer event

From: Jure Bratina <jure.bratina_at_gmail.com>
Date: Sun, 9 Oct 2016 10:37:26 +0200
Message-ID: <CAC08BHL71a3Bzy7qF_q2yoL2M+ewTSCdt3Y5yDdA_7-=70jc+A_at_mail.gmail.com>

Hi,

> However, when I looked at the raw trace file, I did not see
DBMS_LOCK.SLEEP call anywhere in the trace file, which I was hoping to see. Maybe the top level PL/SQL call doesn't execute dbms_lock.sleep directly, and instead calls another function/procedure which actually executes dbms_lock.sleep? Something like:

create or replace procedure custom_sleep is begin
 sys.dbms_lock.sleep(5);
end;
/

begin
custom_sleep;
end;
/

The tkprof of the 10046 trace would show something like:

begin
custom_sleep;
end;

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

---

Parse        1      0.00       0.00          0          0
0           0
Execute      1      0.00       4.99          0          0
0           1
Fetch        0      0.00       0.00          0          0
0           0

------- ------ -------- ---------- ---------- ---------- ----------

---

total        2      0.00       5.00          0          0
0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 5

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

• Waited ----------

  ---

  PL/SQL lock timer 1 4.99 4.99 SQL*Net message to client 1 0.00 0.00 SQL*Net message from client 1 0.42 0.42

  ---

Using DBMS_PROFILER or DBMS_HPROF would probably help in this case.

Regards,
Jure Bratina

On Sun, Oct 9, 2016 at 10:27 AM, Martin Berger <martin.a.berger_at_gmail.com> wrote:

> Amir,
>
> You can open your trace file in an editor and search for the cursor(s) for
> the event
> PL/SQL lock timer.
> If the trace was generated with proper parameters, you will find a PARSE
> section for these cursors. (Beware, cursors van be reused, so you need to
> find the matching PARSE).
> There are parser and tools available which can do this work for you.
>
> Martin
>
> ^∆x
>
> Am 09.10.2016 01:24 schrieb "Hameed, Amir" <Amir.Hameed_at_xerox.com>:
>
>> The DB version is 11.2.0.4.
>>
>> I was looking at the TKP output of a concurrent job which was traced with
>> waits turned on from an Oracle E-Business Suite environment. The *PL/SQL
>> lock timer* wait showed up as the most time consuming event. However,
>> when I looked at the raw trace file, I did not see *DBMS_LOCK.SLEEP*
>> call anywhere in the trace file, which I was hoping to see. I was wondering
>> what might have caused this event to appear in the trace file.
>>
>>
>>
>>
>>
>> OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
>>
>>
>>
>> call count cpu elapsed disk query
>> current rows
>>
>> ------- ------ -------- ---------- ---------- ---------- ----------
>> ----------
>>
>> Parse 29 0.00 0.00 0 0
>> 0 0
>>
>> Execute 979 186.42 2259.07 2 73
>> 245 964
>>
>> Fetch 13 0.00 0.00 0 59
>> 0 12
>>
>> ------- ------ -------- ---------- ---------- ---------- ----------
>> ----------
>>
>> total 1021 186.42 2259.07 2 132
>> 245 976
>>
>>
>>
>>
>>
>> Elapsed times include waiting on following events:
>>
>> Event waited on Times Max. Wait Total
>> Waited
>>
>> ---------------------------------------- Waited ----------
>> ------------
>>
>> SQL*Net message to client 3 0.00
>> 0.00
>>
>> SQL*Net message from client 3 0.00
>> 0.00
>>
>> library cache lock 19 0.00
>> 0.00
>>
>> library cache pin 35 0.00
>> 0.01
>>
>> utl_file I/O 2196972 0.04
>> 7.03
>>
>> row cache lock 61 0.00
>> 0.06
>>
>> PL/SQL lock timer 2067 1.28
>> 2067.53
>>
>> enq: IV - contention 127 0.00
>> 0.11
>>
>> gc current grant busy 3 0.00
>> 0.00
>>
>> gc current block 3-way 5 0.00
>> 0.00
>>
>> gc cr grant 2-way 1 0.00
>> 0.00
>>
>> db file sequential read 1 0.00
>> 0.00
>>
>> ************************************************************
>> ********************
>>
>>
>>
>> Thanks,
>>
>> Amir
>>
>

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

Received on Sun Oct 09 2016 - 10:37:26 CEST