RE: Weird Oracle 12.2 issue ..

From: Mark W. Farnham <mwf_at_rsiz.com>
Date: Fri, 15 Sep 2017 07:16:27 -0400
Message-ID: <0d7f01d32e14$15048e00$3f0daa00$_at_rsiz.com>



I thought of one additional sort of major difference that could run with client versus remote: sqlplus version.  

12.2 has a much superior output mode than previous releases. If your client is using an older sqlplus and/or other clients, that could easily explain the difference. (Or maybe not.)  

We’re having fun guessing, but running a profiler on the trace to see where the time is consumed is a more reliable way to an answer.  

The difference between local and remote access is the interesting thing, so I’ll let my compulsive tuning disorder run wild a bit:  

IF you can cobble up the query and convert it into a count(*), and IF that does not mutilate the plan, that should isolate out per chunk of rows latency.  

IF you can cobble up the query adding a rownum on it and slap on a surrounding query ordered by rownum so it cannot factor it out and a where rownum < “binary_search”  

you’ll be able to see whether solution of the query or latency to the client is the issue directrly.  

“binary_search”, meaning run the query a few times, with a rownum limit that is the number of rows, half the number of rows, etc., cutting in half for enough trials to see.  

Check the real plan for each of these. If there is a structural change in the plan then the exercise doesn’t indicate anything.  

What is your output device when you run the query locally? remotely?  

I mention this because from time to time I’ve seen “enterprise class” output devices running output to files on the server and the relative speed of cuneiform tablets being carved and baked on the remote machine (including horrible screen output painting and USB 1 or 2 devices). This will show up in the trace as waiting for the client to ask for more rows, the same as network latency and network bandwidth (which you’ve apparently ruled out with the fast file transmission.) Oh – was the file transmission to the same output device? Obviously not if the query result is the screen, but also possibly not if the output was a file. If you have the equivalent of /dev/null on your client you can try that for the output to rule out output device issues, and if the current output is to the screen you can try a file.  

mwf  

From: oracle-l-bounce_at_freelists.org [mailto:oracle-l-bounce_at_freelists.org] On Behalf Of Niall Litchfield Sent: Friday, September 15, 2017 4:25 AM To: Mark W. Farnham
Cc: Sayan Malakshinov; Oracle-L; nupendra_at_hotmail.com Subject: RE: Weird Oracle 12.2 issue ..  

I entirely agree with Mark and Sayan. You will also need a trace from the 11g system. If you run them both through a profiler, tkprof will do to start* then you'll be able to see where the extra 10s is.  

I'd also take a second look at the plans in your output before saying the output is the same, since the BY INDEX ROWID BATCHED operation is a 12.1+ feature.  

*given the issue is likely to do with network traffic you may find tkprof omitting some relevant waits and will need a full featured profiler.  

On 15 Sep 2017 04:01, "Mark W. Farnham" <mwf_at_rsiz.com> wrote:

hehe after I sent my response I see that Sayan has sent a more complete version of what I was talking about. (Plus the lob bit).  

mwf  

From: oracle-l-bounce_at_freelists.org [mailto:oracle-l-bounce_at_freelists.org] On Behalf Of Sayan Malakshinov Sent: Thursday, September 14, 2017 7:40 PM To: nupendra_at_hotmail.com
Cc: Oracle-L
Subject: Re: Weird Oracle 12.2 issue ..  

Hi Upendra,  

First of all, that is not real execution plan, that's just the plan produced by "autotrace". It uses explain plan really.

You may noticed that statistics showed 1168 SQL*Net roundtrips, though you got just 583 rows. I suspect that your query contains LOB columns in select list - it could cause extra roundtrips.

11 seconds/1168 roundtrips = 8.5ms per roundtrip - it doesn't seem like something strange.

I think the easiest way to check it is to enable sql trace and give us raw trace.

Also I'd set the following parameters:

set termout off arraysize 1000

and execute your query as script.  

On Fri, Sep 15, 2017 at 2:17 AM, Upendra nerilla <nupendra_at_hotmail.com> wrote:

All,

We are running into a unique issue.. We recently migrated a database from 11.2 to 12.2 for testing.

When we compared the performance, 12.2 performance was 3x-4x slow compared to 11g.

When we were peeling the layers to troubleshoot, we discovered:

Here is the output from SQL trace.. the output from running the query from the DB server and through the client produce identical output, except the elapsed time..  

<snip>

583 rows selected.

Elapsed: 00:00:02.51 vs Elapsed: 00:00:11.44

Statistics


      66503  recursive calls
          0  db block gets
      71151  consistent gets
          0  physical reads
          0  redo size
     382206  bytes sent via SQL*Net to client
     248383  bytes received via SQL*Net from client
       1168  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
        583  rows processed

<snip>  

Any suggestions on what I could check to pin-point the issue might be helpful..

Thanks in advance  

-Upendra  

-- 

Best regards,
Sayan Malakshinov

Oracle performance tuning engineer

Oracle ACE Associate
http://orasql.org



--
http://www.freelists.org/webpage/oracle-l
Received on Fri Sep 15 2017 - 13:16:27 CEST

Original text of this message