Re: Weird Oracle 12.2 issue ..

From: Upendra nerilla <nupendra_at_hotmail.com>
Date: Fri, 15 Sep 2017 07:35:27 +0000
Message-ID: <BN6PR1001MB2162C9B86A69E89C110C2C06D86C0_at_BN6PR1001MB2162.namprd10.prod.outlook.com>



It is true that we are using LOBs, but the main question is, why does this query runs faster when it is run directly on the DB server vs run through a client?

Directly executing your query completed in 2.65 seconds. However when the same query was executed through a sqlplus client (through sqlnet) it took 14+ seconds..

Is there a relationship between the LOB data and the latency we are seeing?

Here is the description of the function call:

FUNCTION GET_DESC_LIST RETURNS VARCHAR2

 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 P_DESC_ID                      NUMBER                  IN
FUNCTION GET_DESC_LIST RETURNS VARCHAR2
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 P_DESC_ID                      NUMBER                  IN
 P_CLIENT_ID                    NUMBER                  IN


_at_Peter, I put in the sqlnet.ora parameter, i didn't see any difference between the executions.

-Upendra



From: Sayan Malakshinov <xt.and.r_at_gmail.com> Sent: Friday, September 15, 2017 2:50 AM To: pgr_at_miracle.dk
Cc: Upendra nerilla; Oracle-L
Subject: Re: Weird Oracle 12.2 issue ..

Upendra,

I've just checked your trace file for LOBS: $ grep -c LOBREAD rcaqa_ora_27261.trc
590

$ awk -F, '/LOBREAD/ {print $2}' rcaqa_ora_27261.trc | sort | uniq bytes=25
bytes=80

Could you show what returns the function aep_i18n.get_desc_list? Execute "desc aep_i18n.get_desc_list" in sql*plus and send us the output of this command.

Also you can try the following query - I've split allFields0 into 2 columns: allFields0_varchar is for short strings(as varchar2)

select
  SERVICE_NAME
,ID
,DESCRIPTION_ID
,case when length("allFields0")<=4000 then cast("allFields0" as varchar2(4000)) end "allFields0_varchar"
,case when length("allFields0")>4000 then "allFields0" end "allFields0_CLOB"
from (
select /*+NO_XML_QUERY_REWRITE*/

       AES_REC_TYPE.SERVICE_NAME SERVICE_NAME,
       AES_REC_TYPE.ID<http://AES_REC_TYPE.ID> ID,
       aep_i18n.get_desc_list(AES_REC_TYPE.DESCRIPTION_ID, AES_REC_TYPE.CLIENT_ID) "DESCRIPTION_ID",
       (SELECT (xmlelement("_fieldType",
                    xmlagg(xmlelement("allFields",
                        xmlforest(AES_FLD_TYPE.SERVICE_NAME SERVICE_NAME0, AES_FLD_TYPE.ID<http://AES_FLD_TYPE.ID> ID0, aep_i18n.get_desc_list(AES_FLD_TYPE.DESCRIPTION_ID, AES_REC_TYPE.CLIENT_ID) "DESCRIPTION_ID0",
                                  aep_attributes.fetch_attr(AES_FLD_TYPE.ID<http://AES_FLD_TYPE.ID>, 'AES_FLD_TYPE', 'COLUMN_NAME', AES_REC_TYPE.CLIENT_ID) "COLUMN_NAME",
                                  aep_attributes.fetch_attr(AES_FLD_TYPE.ID<http://AES_FLD_TYPE.ID>, 'AES_FLD_TYPE', 'BI_COLUMN_NAME', AES_REC_TYPE.CLIENT_ID) "BI_COLUMN_NAME"))))).getClobVal()

          FROM AES_FLD_TYPE AES_FLD_TYPE
         WHERE AES_REC_TYPE.ID<http://AES_REC_TYPE.ID> = AES_FLD_TYPE.REC_TYPE_ID
           AND AES_FLD_TYPE.DELETED_DATE IS NULL
           AND AES_REC_TYPE.client_id = AES_FLD_TYPE.client_id) "allFields0"
FROM AES_REC_TYPE AES_REC_TYPE
WHERE AES_REC_TYPE.DELETED_DATE IS NULL
  AND AES_REC_TYPE.CLIENT_ID = 12313400144 )
/

On Fri, Sep 15, 2017 at 9:19 AM, Peter Gram Miracle A/S <pgr_at_miracle.dk<mailto:pgr_at_miracle.dk>> wrote: Hi

Try setting tcp.nodelay=yes in the sqlnet.ora on the client just to make surer you are not bite by that.

Gram/

Med Venlig Hilsen

Peter Gram

Kultur-kustode for Miracle

Miracle Expert Services
Borupvang 2c, 2750 Ballerup, Denmark<https://maps.google.com/?q=Borupvang+2c,+2750+Ballerup,+Denmark&entry=gmail&source=g> Cell: (+45) 53747107<tel:+45%2053%2074%2071%2007> Office Phone: (+45) 44668855<tel:+45%2044%2066%2088%2055> Office Fax: (+45) 44668856<tel:+45%2044%2066%2088%2056> Home : (+45) 38745696<tel:+45%2038%2074%2056%2096> Home : Sæbyholmsvej 18 2500 Valby<https://maps.google.com/?q=S%C3%A6byholmsvej+18+2500+Valby&entry=gmail&source=g> Mail: peter.gram_at_miracle.dk<mailto:peter.gram_at_miracle.dk> linkedin: dk.linkedin.com/in/petergram/<http://dk.linkedin.com/in/petergram/> OakTable : oaktable.net/members <http://oaktable.net/members>

On 15 September 2017 at 01:17, Upendra nerilla <nupendra_at_hotmail.com<mailto: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:

  • A query which runs in 3 seconds at the database directly (in 12.2) takes between 11-14 seconds when it is run through a client like pl/sql developer.
  • To eliminate the variables, we ran sqlplus from another host (which is in same network), and the execution time was still over 13 seconds.
  • sqlplus on the DB server (using tns/sqlnet) produces the result in about 3 seconds as well
  • Sysadmin says, Network throughput between the servers have no issue, he was able to scp a 500MB file in less than 2 seconds.

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

Execution Plan



Plan hash value: 2598178018
| Id  | Operation                            | Name                | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |                     |  1220 | 56120 |  1244   (0)| 00:00:01 |
|   1 |  SORT AGGREGATE                      |                     |     1 |    47 |            |          |
|*  2 |   TABLE ACCESS BY INDEX ROWID BATCHED| AES_FLD_TYPE        |     1 |    47 |     2   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN                  | AES_IDX_FTYPE_RTYPE |     1 |       |     1   (0)| 00:00:01 |
|*  4 |  TABLE ACCESS FULL                   | AES_REC_TYPE        |  1220 | 56120 |    24   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):


   2 - filter("AES_FLD_TYPE"."DELETED_DATE" IS NULL)
   3 - access("AES_FLD_TYPE"."REC_TYPE_ID"=:B1 AND "AES_FLD_TYPE"."CLIENT_ID"=:B2)
   4 - filter("AES_REC_TYPE"."DELETED_DATE" IS NULL AND "AES_REC_TYPE"."CLIENT_ID"=12313400144<tel:(231)%20340-0144>)

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 - 09:35:27 CEST

Original text of this message