Re: Weird Oracle 12.2 issue ..

  • From: Upendra nerilla <nupendra@xxxxxxxxxxx>
  • To: Sayan Malakshinov <xt.and.r@xxxxxxxxx>, "pgr@xxxxxxxxxx" <pgr@xxxxxxxxxx>
  • Date: Fri, 15 Sep 2017 07:35:27 +0000

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


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


-Upendra


________________________________
From: Sayan Malakshinov <xt.and.r@xxxxxxxxx>
Sent: Friday, September 15, 2017 2:50 AM
To: pgr@xxxxxxxxxx
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@xxxxxxxxxx<mailto:pgr@xxxxxxxxxx>> 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@xxxxxxxxxx<mailto:peter.gram@xxxxxxxxxx>
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@xxxxxxxxxxx<mailto:nupendra@xxxxxxxxxxx>> 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

Other related posts: