Re: Transaction slowness

From: Jonathan Lewis <jlewisoracle_at_gmail.com>
Date: Sat, 16 Oct 2021 09:41:37 +0100
Message-ID: <CAGtsp8=uTOFjWCat8pmMYm0KngDjt6VUOwRPZYmjwbcoFa=h=g_at_mail.gmail.com>



I asked about the first 50 lines and last 20 lines of the trace file. I did not ask for 10MB of trace file and a third copy of the analysed file. The information of interest appeared, as I had thought it might, by line 36:



Received ORADEBUG command (#1) 'event 10046 trace name context forever, level 12' from process '20805'
  • 2021-10-13 06:52:50.280 Finished processing ORADEBUG command (#1) 'event 10046 trace name context forever, level 12'
  • 2021-10-13 06:53:03.288 Received ORADEBUG command (#2) 'tracefile_name' from process '20805'
  • 2021-10-13 06:53:03.288 Finished processing ORADEBUG command (#2) 'tracefile_name'
  • 2021-10-13 06:56:10.447 WAIT #140089538672720: nam='SQL*Net message from client' ela= 285915949 driver id=675562835 #bytes=1 p3=0 obj#=27621 tim=16004790053338

Whatever was in cursor #140089538672720 is the last thing the session did before the database started waiting for it. You may get a clue from obj# = 27621, but that might be deceptive since it might be an example of an object id not being cleared whle some recursive SQL is executed.
You need to find a way to enable tracing before the first call from the device starts.

Regards
Jonathan Lewis

On Fri, 15 Oct 2021 at 22:24, Amit Saroha <eramitsaroha_at_gmail.com> wrote:

> Hi Jonathan,
>
> I had sent the interpreted trace file earlier but now attached the raw
> trace file.
>
> The trace file was enabled from Putty session using ORADEBUG.
>
>
> Best Regards,
> AMIT SAROHA
>
>
> On Fri, Oct 15, 2021 at 4:41 PM Jonathan Lewis <jlewisoracle_at_gmail.com>
> wrote:
>
>>
>> Nothing stands out from that report.
>> What's in the first 50 and last 20 lines of the trace file?
>> What mechanism are you using to enable tracing?
>>
>> Regards
>> Jonathan Lewis
>>
>>
>>
>>
>> On Fri, 15 Oct 2021 at 17:47, Amit Saroha <eramitsaroha_at_gmail.com> wrote:
>>
>>> Thanks, Jonathan. Please find the details below.
>>>
>>> SQL*NET message from client - only 1 wait of 300 seconds
>>> SQL*NET message to client - only 1 wait of fractional second
>>> SQL*NET more data to client Not present in tracle.
>>>
>>> I have enclosed the trace analysis report if you want to take a look at
>>> it. I am not sure what you mean by - what the database was doing before
>>> the wait start.
>>>
>>>
>>> Best Regards,
>>> Amit
>>>
>>>
>>> On Fri, Oct 15, 2021 at 11:05 AM Jonathan Lewis <jlewisoracle_at_gmail.com>
>>> wrote:
>>>
>>>>
>>>> I don't know if it's relevant to the specific technology, but I like
>>>> the idea suggested by Rajeev.
>>>>
>>>> One thing I'd check is whether that time spent in SQL*Net message from
>>>> client is a small number of long waits or a very large number of small
>>>> waits, and how much of the time also turns out to be "SQL*Net more data to
>>>> client"; and what happens at the database just before the wait for client.
>>>>
>>>> Regards
>>>> Jonathan Lewis
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> On Fri, 15 Oct 2021 at 02:47, Amit Saroha <eramitsaroha_at_gmail.com>
>>>> wrote:
>>>>
>>>>> Hi Rajeev,
>>>>>
>>>>> Thanks for the response.
>>>>>
>>>>> The mobile devices are using Oracle MWA for WMS operations accessing
>>>>> EBS database. This is Java based mobile app framework.
>>>>>
>>>>>
>>>>> Regards,
>>>>> Amit
>>>>>
>>>>> On Thu, Oct 14, 2021 at 9:38 PM Rajeev Prabhakar <rprabha01_at_gmail.com>
>>>>> wrote:
>>>>>
>>>>>> Amit,
>>>>>>
>>>>>> I could be way off the mark, but, just wondering if
>>>>>> this the case of jsp files getting created/compiled
>>>>>> on the first time invocation by the App given that
>>>>>> this is done via mobile device ?
>>>>>>
>>>>>> The subsequent calls could be utilizing the cached /
>>>>>> compiled jsp files, so, are faster…
>>>>>>
>>>>>> If not, perhaps you could give some background on
>>>>>> the interface/language being used by the App ?
>>>>>>
>>>>>> My point, unless you have already ruled it out, there
>>>>>> could be variables/factors outside of the database
>>>>>> layer contributing to the initial sluggishness..
>>>>>>
>>>>>> Rajeev
>>>>>>
>>>>>> On Oct 14, 2021 at 6:55 PM, <Amit Saroha <eramitsaroha_at_gmail.com>>
>>>>>> wrote:
>>>>>>
>>>>>> Hello All,
>>>>>>
>>>>>> We are facing a weird slowness in database response to users. The
>>>>>> situation is - Warehouse operators are unloading trucks on the dock and
>>>>>> moving material to locators. When they are doing the activity, they have to
>>>>>> scan barcodes on a mobile device and keep moving items in locators to clean
>>>>>> up the dock to make a way for another truck for unloading material. When
>>>>>> the user is doing the first transaction on a mobile device, it takes 5-10
>>>>>> minutes, but the next transactions are complete in 5-10 seconds. The delay
>>>>>> in first transaction completion is causing an overall delay in warehouse
>>>>>> work efficiency.
>>>>>>
>>>>>> 10046 traces enabled on the session while doing the first
>>>>>> transaction, which takes 5-10 minutes, revealed that over 80% of the time
>>>>>> is going in SQL*NET message from the client. Trace for the next sessions
>>>>>> also shows the same event is top, but the transaction completes within 10
>>>>>> seconds.
>>>>>>
>>>>>> We don’t understand why the first transaction is taking time, and the
>>>>>> next is not so struggling to fix the issue. We also don’t want to conclude
>>>>>> it as a network issue because subsequent transactions are quick.
>>>>>>
>>>>>> We would appreciate it if any of you could please tell us if anyone
>>>>>> has observed the same situation and what we can do to rectify such behavior?
>>>>>>
>>>>>> Thank you in advance for your inputs.
>>>>>>
>>>>>>
>>>>>> Best Regards,
>>>>>> AMIT
>>>>>>
>>>>>> --
>>>>> Best Regards,
>>>>> AMIT SAROHA
>>>>>
>>>>

--
http://www.freelists.org/webpage/oracle-l
Received on Sat Oct 16 2021 - 10:41:37 CEST

Original text of this message