This discussion is archived
1 2 3 Previous Next 32 Replies Latest reply: Aug 26, 2010 2:40 AM by NM RSS

Query Takes more Time when i execute from the Instant client.

NM Newbie
Currently Being Moderated
Hi,

Currently in our Env we have some Queries takes more time when we run from the Instant Client.

System Details
OS=Solaris 10 x86 64bit
Oracle 10.2.0.4

Client Side

$ sqlplus trd_trd_ro/trd_trd_ro@prdba001/TRADE1

SQL*Plus: Release 10.2.0.2.0 - Production on Mon Aug 9 16:26:25 2010

Copyright (c) 1982, 2005, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Release 10.2.0.4.0 - Production

SQL> set timing on
SQL> select mod(lastinstmessagesequence, 1000000000) LastInstIDSeqNo from tibex_msgseqbyuseralias where useralias='2221';

no rows selected

Elapsed: 00:01:54.19
SQL> Disconnected from Oracle Database 10g Release 10.2.0.4.0 - Production
Same Query running on Server Side
^C130-oracle@prdba001 txt: sql

Database: trd_trd_owner/trd_trd_owner@prdba001/TRADE1



SQL*Plus: Release 10.2.0.4.0 - Production on Mon Aug 9 17:15:18 2010

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Release 10.2.0.4.0 - Production

trd_trd_owner@TRADE1>  set timing on
trd_trd_owner@TRADE1> select mod(lastinstmessagesequence, 1000000000) LastInstIDSeqNo from tibex_msgseqbyuseralias where useralias='2221';

no rows selected

Elapsed: 00:00:00.12
trd_trd_owner@TRADE1> exit
Kindly help me what could be the Issues.
  • 1. Re: Query Takes more Time when i execute from the Instant client.
    sb92075 Guru
    Currently Being Moderated
    SQL> SET AUTOTRACE ON EXPLAIN STATISTICS

    repeat previous runs
  • 2. Re: Query Takes more Time when i execute from the Instant client.
    NM Newbie
    Currently Being Moderated
    Hi,

    Thanks for Your reply.
    Server Side Execution
    
    trd_trd_owner@TRADE1> SET AUTOTRACE ON EXPLAIN STATISTICS
    trd_trd_owner@TRADE1> select mod(lastinstmessagesequence, 1000000000) LastInstIDSeqNo from tibex_msgseqbyuseralias where useralias='2221';
    
    no rows selected
    
    
    Execution Plan
    ----------------------------------------------------------
    Plan hash value: 1955857846
    
    ---------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Rows  | Bytes | Cost (%CPU)| Time     |
    ---------------------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT                |                       |    21 |   399 |  2548   (1)| 00:00:31 |
    |   1 |  SORT GROUP BY NOSORT           |                       |    21 |   399 |  2548   (1)| 00:00:31 |
    |   2 |   VIEW                          |                       |    21 |   399 |  2548   (1)| 00:00:31 |
    |   3 |    UNION-ALL                    |                       |       |       |            |          |
    |   4 |     SORT GROUP BY NOSORT        |                       |     1 |    17 |  1874   (1)| 00:00:23 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           | 21056 |   349K|  1874   (1)| 00:00:23 |
    |   6 |     SORT GROUP BY NOSORT        |                       |     1 |    17 |   390   (0)| 00:00:05 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |   660 | 11220 |   390   (0)| 00:00:05 |
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |   660 |       |    10   (0)| 00:00:01 |
    |   9 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     2   (0)| 00:00:01 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |     1 |    19 |     2   (0)| 00:00:01 |
    |  11 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     2   (0)| 00:00:01 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |     1 |    19 |     2   (0)| 00:00:01 |
    |  13 |     SORT GROUP BY NOSORT        |                       |     1 |    13 |    35   (0)| 00:00:01 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |     1 |    13 |    35   (0)| 00:00:01 |
    |  15 |     SORT GROUP BY NOSORT        |                       |     1 |    17 |   229   (1)| 00:00:03 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |   339 |  5763 |   229   (1)| 00:00:03 |
    |  17 |     SORT GROUP BY NOSORT        |                       |     1 |    17 |     9   (0)| 00:00:01 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |     1 |    17 |     9   (0)| 00:00:01 |
    |  19 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |     1 |    19 |     0   (0)| 00:00:01 |
    |  21 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |     1 |    19 |     0   (0)| 00:00:01 |
    |  23 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |     1 |    19 |     0   (0)| 00:00:01 |
    |  25 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     2   (0)| 00:00:01 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |     1 |    19 |     2   (0)| 00:00:01 |
    |  27 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |     1 |    19 |     0   (0)| 00:00:01 |
    |  29 |     SORT GROUP BY NOSORT        |                       |     1 |    15 |     1   (0)| 00:00:01 |
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |     1 |    15 |     1   (0)| 00:00:01 |
    |  31 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |     1 |    19 |     0   (0)| 00:00:01 |
    |  33 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |     1 |    19 |     0   (0)| 00:00:01 |
    |  35 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |     1 |    19 |     0   (0)| 00:00:01 |
    |  37 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |     1 |    19 |     0   (0)| 00:00:01 |
    |  39 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |     1 |    19 |     0   (0)| 00:00:01 |
    |  41 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     0   (0)| 00:00:01 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |     1 |    19 |     0   (0)| 00:00:01 |
    |  43 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     2   (0)| 00:00:01 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |     1 |    19 |     2   (0)| 00:00:01 |
    |  45 |     SORT GROUP BY NOSORT        |                       |     1 |    19 |     2   (0)| 00:00:01 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |     1 |    19 |     2   (0)| 00:00:01 |
    ---------------------------------------------------------------------------------------------------------
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       5 - filter("LASTINSTUSERALIAS"='2221')
       8 - access("LASTINSTUSERALIAS"='2221')
      10 - filter("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"='2221')
      12 - filter("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"='2221')
      14 - filter("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"='2221')
      16 - filter("USERALIAS"='2221')
      18 - filter("USERALIAS"='2221')
      20 - access("USERALIAS"='2221')
      22 - access("USERALIAS"='2221')
      24 - access("USERALIAS"='2221')
      26 - filter("USERALIAS" IS NOT NULL AND "USERALIAS"='2221')
      28 - access("USERALIAS"='2221')
      30 - access("USERALIAS"='2221')
      32 - access("USERALIAS"='2221')
      34 - access("USERALIAS"='2221')
      36 - access("USERALIAS"='2221')
      38 - access("USERALIAS"='2221')
      40 - access("USERALIAS"='2221')
      42 - access("USERALIAS"='2221')
      44 - filter("USERALIAS"='2221')
      46 - filter("USERALIAS"='2221')
    
    
    Statistics
    ----------------------------------------------------------
              1  recursive calls
              1  db block gets
           8212  consistent gets
            159  physical reads
            132  redo size
            332  bytes sent via SQL*Net to client
            481  bytes received via SQL*Net from client
              1  SQL*Net roundtrips to/from client
              0  sorts (memory)
              0  sorts (disk)
              0  rows processed
    
    ------------------------------------------------------------------------------------------
    Client Side Execution
    
    SQL> SET AUTOTRACE ON EXPLAIN STATISTICS
    SQL> select mod(lastinstmessagesequence, 1000000000) LastInstIDSeqNo from tibex_msgseqbyuseralias where useralias='2221';
    
    
    no rows selected
    
    
    Execution Plan
    ----------------------------------------------------------
    Plan hash value: 1955857846
    
    --------------------------------------------------------------------------------
    -------------------------
    
    | Id  | Operation                       | Name                  | Rows  | Bytes
    | Cost (%CPU)| Time     |
    
    --------------------------------------------------------------------------------
    -------------------------
    
    |   0 | SELECT STATEMENT                |                       |    21 |   399
    |  2548   (1)| 00:00:31 |
    
    |   1 |  SORT GROUP BY NOSORT           |                       |    21 |   399
    |  2548   (1)| 00:00:31 |
    
    |   2 |   VIEW                          |                       |    21 |   399
    |  2548   (1)| 00:00:31 |
    
    |   3 |    UNION-ALL                    |                       |       |
    |            |          |
    
    |   4 |     SORT GROUP BY NOSORT        |                       |     1 |    17
    |  1874   (1)| 00:00:23 |
    
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           | 21056 |   349K
    |  1874   (1)| 00:00:23 |
    
    |   6 |     SORT GROUP BY NOSORT        |                       |     1 |    17
    |   390   (0)| 00:00:05 |
    
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |   660 | 11220
    |   390   (0)| 00:00:05 |
    
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |   660 |
    |    10   (0)| 00:00:01 |
    
    |   9 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |  11 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |  13 |     SORT GROUP BY NOSORT        |                       |     1 |    13
    |    35   (0)| 00:00:01 |
    
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |     1 |    13
    |    35   (0)| 00:00:01 |
    
    |  15 |     SORT GROUP BY NOSORT        |                       |     1 |    17
    |   229   (1)| 00:00:03 |
    
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |   339 |  5763
    |   229   (1)| 00:00:03 |
    
    |  17 |     SORT GROUP BY NOSORT        |                       |     1 |    17
    |     9   (0)| 00:00:01 |
    
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |     1 |    17
    |     9   (0)| 00:00:01 |
    
    |  19 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  21 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  23 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  25 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |  27 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  29 |     SORT GROUP BY NOSORT        |                       |     1 |    15
    |     1   (0)| 00:00:01 |
    
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |     1 |    15
    |     1   (0)| 00:00:01 |
    
    |  31 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  33 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  35 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  37 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  39 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  41 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |     1 |    19
    |     0   (0)| 00:00:01 |
    
    |  43 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |  45 |     SORT GROUP BY NOSORT        |                       |     1 |    19
    |     2   (0)| 00:00:01 |
    
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |     1 |    19
    |     2   (0)| 00:00:01 |
    
    --------------------------------------------------------------------------------
    -------------------------
    
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       5 - filter("LASTINSTUSERALIAS"='2221')
       8 - access("LASTINSTUSERALIAS"='2221')
      10 - filter("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"='2221')
      12 - filter("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"='2221')
      14 - filter("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"='2221')
      16 - filter("USERALIAS"='2221')
      18 - filter("USERALIAS"='2221')
      20 - access("USERALIAS"='2221')
      22 - access("USERALIAS"='2221')
      24 - access("USERALIAS"='2221')
      26 - filter("USERALIAS" IS NOT NULL AND "USERALIAS"='2221')
      28 - access("USERALIAS"='2221')
      30 - access("USERALIAS"='2221')
      32 - access("USERALIAS"='2221')
      34 - access("USERALIAS"='2221')
      36 - access("USERALIAS"='2221')
      38 - access("USERALIAS"='2221')
      40 - access("USERALIAS"='2221')
      42 - access("USERALIAS"='2221')
      44 - filter("USERALIAS"='2221')
      46 - filter("USERALIAS"='2221')
    
    
    Statistics
    ----------------------------------------------------------
              0  recursive calls
              0  db block gets
         356714  consistent gets
         315935  physical reads
              0  redo size
            250  bytes sent via SQL*Net to client
            327  bytes received via SQL*Net from client
              1  SQL*Net roundtrips to/from client
              0  sorts (memory)
              0  sorts (disk)
              0  rows processed
  • 3. Re: Query Takes more Time when i execute from the Instant client.
    Mohamed ELAzab Pro
    Currently Being Moderated
    Hello,
    As i can see from the explain plan according to my knowledge you have a bottleneck in |* 5 | TABLE ACCESS FULL | TIBEX_QUOTE | 21056 | 349K| 1874 (1)| 00:00:23 |
    as you have the process doing a full table scan.
    I think you also need to see if there are any wait operations becuase you are doing alot off sort operations.i think you need to check on the pga_aggregrate_target.

    Also you need to gather statoistics regularly on those objects.
    Kind regards
    mohamed
    oracle DBA
  • 4. Re: Query Takes more Time when i execute from the Instant client.
    sb92075 Guru
    Currently Being Moderated
    Also you need to gather statoistics regularly on those objects
    Default behavior for V10+ is that Oracle collects necessary statistics once a day via SCHEDULER job
  • 5. Re: Query Takes more Time when i execute from the Instant client.
    Mohamed ELAzab Pro
    Currently Being Moderated
    I agree Sb but i think you can stop this behavior that is why i asked him to do it or check it according to the database time window.You can also add coments or correct me sb.lets share more on this issue as i am interested in the performance tuning area.
    Kind regards
    Mohamed
    Oracle DBA
  • 6. Re: Query Takes more Time when i execute from the Instant client.
    sybrand_b Guru
    Currently Being Moderated
    If you look at both explain plans closely, you will see they are identical. Somehow he doesn't show all, and he managed to change the width of his lines, so his second explain plan wraps to make it more difficult for those helping him.
    As the plans are identical (the plan hash value is identical too), your suggestion doesn't hold.
    What is striking is at the second run his number of consistent gets and physical reads is way higher.
    Is it possible he is not running this in a sandbox, but in a live environment.
    Also his questions shows he 'thinks' he knows the solution, as he 'assumes' the instant client is the culprit.
    As far as I know the instant client has the jdbc thin client only, and doesn't use oci, so this would be slower by design.
    In sqldeveloper you run the jdbc thin driver by default, but you can enable the thick driver with oci, the thin driver is so slow you want to switch to Toad immediately.
    Toad is using OCI.
    So if he thinks it is the driver, yes, as the driver is slower by design, he should stop using the driver.
    But it is not the driver.
    He needs to run both variants with proper tracing, so we can know 'what it is waiting for' the second time, and what causes IO. Might be recursive calls.

    -------------
    Sybrand Bakker
    Senior Oracle DBA
  • 7. Re: Query Takes more Time when i execute from the Instant client.
    gjilevski1 Journeyer
    Currently Being Moderated
    Hi,

    Seems the situation is that there is a query running against the same database and depending on where is run from performance is different.

    This leads me to exclude the database and figure out what makes the difference between client run and serve run. Can you look at the infrastructure for an explanation?

    Regards,
  • 8. Re: Query Takes more Time when i execute from the Instant client.
    CharlesHooper Expert
    Currently Being Moderated
    I believe that Sybrand's comments are on target. The differences in consistent gets are physical reads between the two executions are significant.

    There is a chance that AUTOTRACE is showing the wrong execution plan. There is also the possibility of a "cold" cache during the first execution, while the most of the blocks were already in the buffer cache during the second execution. Please post the output of the following script when run from both environments:
    ALTER SESSION SET STATISTICS_LEVEL='TYPICAL';
    SET AUTOTRACE OFF
    SET SERVEROUTPUT OFF
    SET TIMING OFF
    SET LINESIZE 160
    SET PAGESIZE 1000
     
    select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, 1000000000) LastInstIDSeqNo from tibex_msgseqbyuseralias where useralias='2221';
     
    select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, 1000000000) LastInstIDSeqNo from tibex_msgseqbyuseralias where useralias='2221';
     
    SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR('NULL,NULL,'ALLSTATS LAST'));
    The execution plan displayed by the above will be the actual execution plan used by the query, including both the optimizer's estimated cardinality for each operation and the actual number of rows returned. The query is executed twice to limit the influence of a "cold" cache.

    Charles Hooper
    Co-author of "Expert Oracle Practices: Oracle Database Administration from the Oak Table"
    http://hoopercharles.wordpress.com/
    IT Manager/Oracle DBA
    K&M Machine-Fabricating, Inc.
  • 9. Re: Query Takes more Time when i execute from the Instant client.
    NM Newbie
    Currently Being Moderated
    Hi Charles,

    Thanks for your response.Below is the Stats.
    Server Side
    trd_trd_owner@TRADE1> SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ----------------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  bpxr7axhxaqvy, child number 1
    -------------------------------------
     select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    
    -------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
    -------------------------------------------------------------------------------------------------------------------
    |   1 |  SORT GROUP BY NOSORT           |                       |      1 |     21 |      0 |00:00:00.12 |    8545 |
    |   2 |   VIEW                          |                       |      1 |     21 |      0 |00:00:00.12 |    8545 |
    |   3 |    UNION-ALL                    |                       |      1 |        |      0 |00:00:00.12 |    8545 |
    |   4 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.10 |    5496 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           |      1 |  21056 |      0 |00:00:00.10 |    5496 |
    |   6 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       4 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |      1 |    660 |      0 |00:00:00.01 |       4 |
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |      1 |    660 |      0 |00:00:00.01 |       4 |
    |   9 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  11 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  13 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |  15 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.02 |    2862 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |      1 |    339 |      0 |00:00:00.02 |    2862 |
    |  17 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |      31 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |      1 |      1 |      0 |00:00:00.01 |      31 |
    |  19 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  21 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  23 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  25 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  27 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  29 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  31 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  33 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  35 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  37 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  39 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  41 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  43 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  45 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |      1 |      1 |      0 |00:00:00.01 |       3 |
    -------------------------------------------------------------------------------------------------------------------
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       5 - filter("LASTINSTUSERALIAS"=:SYS_B_1)
       8 - access("LASTINSTUSERALIAS"=:SYS_B_1)
      10 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      12 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      14 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      16 - filter("USERALIAS"=:SYS_B_1)
      18 - filter("USERALIAS"=:SYS_B_1)
      20 - access("USERALIAS"=:SYS_B_1)
      22 - access("USERALIAS"=:SYS_B_1)
      24 - access("USERALIAS"=:SYS_B_1)
      26 - filter(("USERALIAS" IS NOT NULL AND "USERALIAS"=:SYS_B_1))
      28 - access("USERALIAS"=:SYS_B_1)
      30 - access("USERALIAS"=:SYS_B_1)
      32 - access("USERALIAS"=:SYS_B_1)
      34 - access("USERALIAS"=:SYS_B_1)
      36 - access("USERALIAS"=:SYS_B_1)
      38 - access("USERALIAS"=:SYS_B_1)
      40 - access("USERALIAS"=:SYS_B_1)
      42 - access("USERALIAS"=:SYS_B_1)
      44 - filter("USERALIAS"=:SYS_B_1)
      46 - filter("USERALIAS"=:SYS_B_1)
    
    
    83 rows selected.
    
    Elapsed: 00:00:00.24
    Client Side
    SQL> SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ----------------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  9bft8ncq6k2b1, child number 0
    -------------------------------------
      select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    
    -------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
    -------------------------------------------------------------------------------------------------------------------
    |   1 |  SORT GROUP BY NOSORT           |                       |      1 |     21 |      0 |00:00:00.11 |    8561 |
    |   2 |   VIEW                          |                       |      1 |     21 |      0 |00:00:00.11 |    8561 |
    |   3 |    UNION-ALL                    |                       |      1 |        |      0 |00:00:00.11 |    8561 |
    |   4 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.09 |    5512 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           |      1 |  21056 |      0 |00:00:00.09 |    5512 |
    |   6 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       4 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |      1 |    660 |      0 |00:00:00.01 |       4 |
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |      1 |    660 |      0 |00:00:00.01 |       4 |
    |   9 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  11 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  13 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |  15 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.02 |    2862 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |      1 |    339 |      0 |00:00:00.02 |    2862 |
    |  17 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |      31 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |      1 |      1 |      0 |00:00:00.01 |      31 |
    |  19 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  21 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  23 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  25 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  27 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  29 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  31 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  33 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  35 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  37 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  39 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  41 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  43 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  45 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |      1 |      1 |      0 |00:00:00.01 |       3 |
    -------------------------------------------------------------------------------------------------------------------
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       5 - filter("LASTINSTUSERALIAS"=:SYS_B_1)
       8 - access("LASTINSTUSERALIAS"=:SYS_B_1)
      10 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      12 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      14 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      16 - filter("USERALIAS"=:SYS_B_1)
      18 - filter("USERALIAS"=:SYS_B_1)
      20 - access("USERALIAS"=:SYS_B_1)
      22 - access("USERALIAS"=:SYS_B_1)
      24 - access("USERALIAS"=:SYS_B_1)
      26 - filter(("USERALIAS" IS NOT NULL AND "USERALIAS"=:SYS_B_1))
      28 - access("USERALIAS"=:SYS_B_1)
      30 - access("USERALIAS"=:SYS_B_1)
      32 - access("USERALIAS"=:SYS_B_1)
      34 - access("USERALIAS"=:SYS_B_1)
      36 - access("USERALIAS"=:SYS_B_1)
      38 - access("USERALIAS"=:SYS_B_1)
      40 - access("USERALIAS"=:SYS_B_1)
      42 - access("USERALIAS"=:SYS_B_1)
      44 - filter("USERALIAS"=:SYS_B_1)
      46 - filter("USERALIAS"=:SYS_B_1)
    
    
    83 rows selected.
    
    Elapsed: 00:00:00.03
  • 10. Re: Query Takes more Time when i execute from the Instant client.
    CharlesHooper Expert
    Currently Being Moderated
    NM wrote:
    Hi Charles,

    Thanks for your response.Below is the Stats.
    Server Side
    trd_trd_owner@TRADE1> SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ----------------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  bpxr7axhxaqvy, child number 1
    -------------------------------------
    select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    (Snip)
    Client Side
    SQL> SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ----------------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  9bft8ncq6k2b1, child number 0
    -------------------------------------
    select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    (Snip)
    Very helpful, thank you.

    Notice the presence of :"SYS_B_0" in the output - that is a sign of system generated bind variables as a result of setting CURSOR_SHARING to either FORCE or SIMILAR. Bind peeking takes effect during the initial hard parse (assuming 9i and above) so the SQL statement is optimized just as if a constant were still present in the SQL statement. Why is this important, after all the same plan hash value of 1955857846 is displayed for both executions? Notice for the client-side execution the child number is listed as 0, and for the server-side execution the child number is listed as 1 - this indicates that there was a hard parse when the SQL statement was executed on the server-side. But also notice that the SQL_ID changed between the two executions - that should not happen if you used the same script on both the client and server sides (unless maybe the default characterset is different for the two sides). This leads me to believe that the client-side and server-side may be using entirely different execution plans when you noticed performance differences. You can pull the existing execution plans for all child cursors for these SQL statements from the library cache by replacing the first NULL in the DBMS_XPLAN.DISPLAY_CURSOR call with the SQL_IDs:
    SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR('bpxr7axhxaqvy',NULL,'ALLSTATS LAST'));
     
    SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR('9bft8ncq6k2b1',NULL,'ALLSTATS LAST'));
    You can quickly compare the plan hash value for each of the execution plans that are output to determine if the execution plan changed.

    Charles Hooper
    Co-author of "Expert Oracle Practices: Oracle Database Administration from the Oak Table"
    http://hoopercharles.wordpress.com/
    IT Manager/Oracle DBA
    K&M Machine-Fabricating, Inc.
  • 11. Re: Query Takes more Time when i execute from the Instant client.
    NM Newbie
    Currently Being Moderated
    Hi Charles,

    Thanks for your Quick response.I pulled the info.
    sys@TRADE1> SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR('bpxr7axhxaqvy',NULL,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  bpxr7axhxaqvy, child number 0
    -------------------------------------
     select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    
    -------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
    -------------------------------------------------------------------------------------------------------------------
    |   1 |  SORT GROUP BY NOSORT           |                       |      1 |     21 |      0 |00:00:00.06 |    6121 |
    |   2 |   VIEW                          |                       |      1 |     21 |      0 |00:00:00.06 |    6121 |
    |   3 |    UNION-ALL                    |                       |      1 |        |      0 |00:00:00.06 |    6121 |
    |   4 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.05 |    3073 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           |      1 |  30080 |      0 |00:00:00.05 |    3073 |
    |   6 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |      1 |    971 |      0 |00:00:00.01 |       3 |
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |      1 |    971 |      0 |00:00:00.01 |       3 |
    |   9 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  11 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  13 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |  15 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |    2862 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |      1 |    339 |      0 |00:00:00.01 |    2862 |
    |  17 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |      31 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |      1 |      1 |      0 |00:00:00.01 |      31 |
    |  19 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  21 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  23 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  25 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  27 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  29 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  31 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  33 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  35 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  37 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  39 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  41 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  43 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  45 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |      1 |      1 |      0 |00:00:00.01 |       3 |
    -------------------------------------------------------------------------------------------------------------------
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
       5 - filter("LASTINSTUSERALIAS"=:SYS_B_1)
       8 - access("LASTINSTUSERALIAS"=:SYS_B_1)
      10 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      12 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      14 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      16 - filter("USERALIAS"=:SYS_B_1)
      18 - filter("USERALIAS"=:SYS_B_1)
      20 - access("USERALIAS"=:SYS_B_1)
      22 - access("USERALIAS"=:SYS_B_1)
      24 - access("USERALIAS"=:SYS_B_1)
      26 - filter(("USERALIAS" IS NOT NULL AND "USERALIAS"=:SYS_B_1))
      28 - access("USERALIAS"=:SYS_B_1)
      30 - access("USERALIAS"=:SYS_B_1)
      32 - access("USERALIAS"=:SYS_B_1)
      34 - access("USERALIAS"=:SYS_B_1)
      36 - access("USERALIAS"=:SYS_B_1)
      38 - access("USERALIAS"=:SYS_B_1)
      40 - access("USERALIAS"=:SYS_B_1)
      42 - access("USERALIAS"=:SYS_B_1)
      44 - filter("USERALIAS"=:SYS_B_1)
      46 - filter("USERALIAS"=:SYS_B_1)
    
    SQL_ID  bpxr7axhxaqvy, child number 1
    -------------------------------------
     select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    Plan hash value: 1955857846
    
    -------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
    -------------------------------------------------------------------------------------------------------------------
    |   1 |  SORT GROUP BY NOSORT           |                       |      1 |     21 |      0 |00:00:00.12 |    8545 |
    |   2 |   VIEW                          |                       |      1 |     21 |      0 |00:00:00.12 |    8545 |
    |   3 |    UNION-ALL                    |                       |      1 |        |      0 |00:00:00.12 |    8545 |
    |   4 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.10 |    5496 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           |      1 |  21056 |      0 |00:00:00.10 |    5496 |
    |   6 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       4 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |      1 |    660 |      0 |00:00:00.01 |       4 |
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |      1 |    660 |      0 |00:00:00.01 |       4 |
    |   9 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  11 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  13 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |  15 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.02 |    2862 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |      1 |    339 |      0 |00:00:00.02 |    2862 |
    |  17 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |      31 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |      1 |      1 |      0 |00:00:00.01 |      31 |
    |  19 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  21 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  23 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  25 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  27 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  29 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  31 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  33 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  35 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  37 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  39 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  41 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  43 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  45 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |      1 |      1 |      0 |00:00:00.01 |       3 |
    -------------------------------------------------------------------------------------------------------------------
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       5 - filter("LASTINSTUSERALIAS"=:SYS_B_1)
       8 - access("LASTINSTUSERALIAS"=:SYS_B_1)
      10 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      12 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      14 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      16 - filter("USERALIAS"=:SYS_B_1)
      18 - filter("USERALIAS"=:SYS_B_1)
      20 - access("USERALIAS"=:SYS_B_1)
      22 - access("USERALIAS"=:SYS_B_1)
      24 - access("USERALIAS"=:SYS_B_1)
      26 - filter(("USERALIAS" IS NOT NULL AND "USERALIAS"=:SYS_B_1))
      28 - access("USERALIAS"=:SYS_B_1)
      30 - access("USERALIAS"=:SYS_B_1)
      32 - access("USERALIAS"=:SYS_B_1)
      34 - access("USERALIAS"=:SYS_B_1)
      36 - access("USERALIAS"=:SYS_B_1)
      38 - access("USERALIAS"=:SYS_B_1)
      40 - access("USERALIAS"=:SYS_B_1)
      42 - access("USERALIAS"=:SYS_B_1)
      44 - filter("USERALIAS"=:SYS_B_1)
      46 - filter("USERALIAS"=:SYS_B_1)
    
    SQL_ID  bpxr7axhxaqvy, child number 2
    -------------------------------------
     select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    
    ----------------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |
    ----------------------------------------------------------------------------------------------------------------------------
    |   1 |  SORT GROUP BY NOSORT           |                       |      1 |     21 |      1 |00:00:00.13 |    8476 |      3 |
    |   2 |   VIEW                          |                       |      1 |     21 |      1 |00:00:00.13 |    8476 |      3 |
    |   3 |    UNION-ALL                    |                       |      1 |        |      1 |00:00:00.13 |    8476 |      3 |
    |   4 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.10 |    5283 |      0 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           |      1 |  21056 |      0 |00:00:00.10 |    5283 |      0 |
    |   6 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      1 |00:00:00.01 |     148 |      3 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |      1 |    660 |    150 |00:00:00.01 |     148 |      3 |
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |      1 |    660 |    150 |00:00:00.01 |       5 |      0 |
    |   9 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |  11 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |  13 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |     126 |      0 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |      1 |      1 |      0 |00:00:00.01 |     126 |      0 |
    |  15 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.02 |    2862 |      0 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |      1 |    339 |      0 |00:00:00.02 |    2862 |      0 |
    |  17 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |      31 |      0 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |      1 |      1 |      0 |00:00:00.01 |      31 |      0 |
    |  19 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  21 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  23 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  25 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |  27 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  29 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  31 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  33 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  35 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  37 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  39 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  41 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |      1 |      1 |      0 |00:00:00.01 |       1 |      0 |
    |  43 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |  45 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |      1 |      1 |      0 |00:00:00.01 |       3 |      0 |
    ----------------------------------------------------------------------------------------------------------------------------
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       5 - filter("LASTINSTUSERALIAS"=:SYS_B_1)
       8 - access("LASTINSTUSERALIAS"=:SYS_B_1)
      10 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      12 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      14 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      16 - filter("USERALIAS"=:SYS_B_1)
      18 - filter("USERALIAS"=:SYS_B_1)
      20 - access("USERALIAS"=:SYS_B_1)
      22 - access("USERALIAS"=:SYS_B_1)
      24 - access("USERALIAS"=:SYS_B_1)
      26 - filter(("USERALIAS" IS NOT NULL AND "USERALIAS"=:SYS_B_1))
      28 - access("USERALIAS"=:SYS_B_1)
      30 - access("USERALIAS"=:SYS_B_1)
      32 - access("USERALIAS"=:SYS_B_1)
      34 - access("USERALIAS"=:SYS_B_1)
      36 - access("USERALIAS"=:SYS_B_1)
      38 - access("USERALIAS"=:SYS_B_1)
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
      40 - access("USERALIAS"=:SYS_B_1)
      42 - access("USERALIAS"=:SYS_B_1)
      44 - filter("USERALIAS"=:SYS_B_1)
      46 - filter("USERALIAS"=:SYS_B_1)
    249 rows selected.
  • 12. Re: Query Takes more Time when i execute from the Instant client.
    NM Newbie
    Currently Being Moderated
    Hi Charles,

    Cont...

    This is Second plan for 9bft8ncq6k2b1

    sys@TRADE1> SELECT  * FROM  TABLE(DBMS_XPLAN.DISPLAY_CURSOR('9bft8ncq6k2b1',NULL,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  9bft8ncq6k2b1, child number 0
    -------------------------------------
      select /*+ GATHER_PLAN_STATISTICS */ mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from
    tibex_msgseqbyuseralias where useralias=:"SYS_B_1"
    
    Plan hash value: 1955857846
    
    -------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                       | Name                  | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
    -------------------------------------------------------------------------------------------------------------------
    |   1 |  SORT GROUP BY NOSORT           |                       |      1 |     21 |      0 |00:00:00.11 |    8561 |
    |   2 |   VIEW                          |                       |      1 |     21 |      0 |00:00:00.11 |    8561 |
    |   3 |    UNION-ALL                    |                       |      1 |        |      0 |00:00:00.11 |    8561 |
    |   4 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.09 |    5512 |
    |*  5 |      TABLE ACCESS FULL          | TIBEX_QUOTE           |      1 |  21056 |      0 |00:00:00.09 |    5512 |
    |   6 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       4 |
    |   7 |      TABLE ACCESS BY INDEX ROWID| TIBEX_ORDER           |      1 |    660 |      0 |00:00:00.01 |       4 |
    |*  8 |       INDEX RANGE SCAN          | TIBEX_ORDER_IDX_OLT   |      1 |    660 |      0 |00:00:00.01 |       4 |
    |   9 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 10 |      TABLE ACCESS FULL          | TIBEX_TSTRADE         |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  11 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 12 |      TABLE ACCESS FULL          | TIBEX_IOIREQUEST      |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  13 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |* 14 |      TABLE ACCESS FULL          | TIBEX_BESTEXREL       |      1 |      1 |      0 |00:00:00.01 |     126 |
    |  15 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.02 |    2862 |
    |* 16 |      INDEX FAST FULL SCAN       | SYS_C0058325          |      1 |    339 |      0 |00:00:00.02 |    2862 |
    |  17 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |      31 |
    |* 18 |      TABLE ACCESS FULL          | TIBEX_EDPPULLORDERS   |      1 |      1 |      0 |00:00:00.01 |      31 |
    |  19 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 20 |      INDEX RANGE SCAN           | SYS_C0058803          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  21 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 22 |      INDEX RANGE SCAN           | SYS_C0057785          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  23 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 24 |      INDEX RANGE SCAN           | SYS_C0057827          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  25 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 26 |      TABLE ACCESS FULL          | TIBEX_DELETEADMIN     |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  27 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 28 |      INDEX RANGE SCAN           | SYS_C0058148          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  29 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 30 |      INDEX RANGE SCAN           | SYS_C0058264          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  31 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 32 |      INDEX RANGE SCAN           | SYS_C0058516          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  33 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 34 |      INDEX RANGE SCAN           | SYS_C0058561          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  35 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 36 |      INDEX RANGE SCAN           | SYS_C0058783          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  37 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 38 |      INDEX RANGE SCAN           | SYS_C0058977          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  39 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 40 |      INDEX RANGE SCAN           | SYS_C0058859          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  41 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       1 |
    |* 42 |      INDEX RANGE SCAN           | SYS_C0059197          |      1 |      1 |      0 |00:00:00.01 |       1 |
    |  43 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 44 |      TABLE ACCESS FULL          | TIBEX_CANCELTRDADMIN  |      1 |      1 |      0 |00:00:00.01 |       3 |
    |  45 |     SORT GROUP BY NOSORT        |                       |      1 |      1 |      0 |00:00:00.01 |       3 |
    |* 46 |      TABLE ACCESS FULL          | TIBEX_BULKCANCELADMIN |      1 |      1 |      0 |00:00:00.01 |       3 |
    -------------------------------------------------------------------------------------------------------------------
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
    
    PLAN_TABLE_OUTPUT
    ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
       5 - filter("LASTINSTUSERALIAS"=:SYS_B_1)
       8 - access("LASTINSTUSERALIAS"=:SYS_B_1)
      10 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      12 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      14 - filter(("LASTINSTUSERALIAS" IS NOT NULL AND "LASTINSTUSERALIAS"=:SYS_B_1))
      16 - filter("USERALIAS"=:SYS_B_1)
      18 - filter("USERALIAS"=:SYS_B_1)
      20 - access("USERALIAS"=:SYS_B_1)
      22 - access("USERALIAS"=:SYS_B_1)
      24 - access("USERALIAS"=:SYS_B_1)
      26 - filter(("USERALIAS" IS NOT NULL AND "USERALIAS"=:SYS_B_1))
      28 - access("USERALIAS"=:SYS_B_1)
      30 - access("USERALIAS"=:SYS_B_1)
      32 - access("USERALIAS"=:SYS_B_1)
      34 - access("USERALIAS"=:SYS_B_1)
      36 - access("USERALIAS"=:SYS_B_1)
      38 - access("USERALIAS"=:SYS_B_1)
      40 - access("USERALIAS"=:SYS_B_1)
      42 - access("USERALIAS"=:SYS_B_1)
      44 - filter("USERALIAS"=:SYS_B_1)
      46 - filter("USERALIAS"=:SYS_B_1)
    
    
    83 rows selected.
    Edited by: NM on 10-Aug-2010 08:13
  • 13. Re: Query Takes more Time when i execute from the Instant client.
    NM Newbie
    Currently Being Moderated
    Hi Charles,

    I collected awr stats during that period.
    DB Name         DB Id    Instance     Inst Num Release     RAC Host
    ------------ ----------- ------------ -------- ----------- --- ------------
    TRADE1        1759894270 TRADE1              1 10.2.0.4.0  NO  prdba001
                  Snap Id      Snap Time      Sessions Curs/Sess
                --------- ------------------- -------- ---------
    Begin Snap:     21020 09-Aug-10 16:00:42        96      10.6
      End Snap:     21021 09-Aug-10 16:30:31        96      10.2
       Elapsed:               29.81 (mins)
       DB Time:               23.46 (mins)
    Cache Sizes
    ~~~~~~~~~~~                       Begin        End
                                 ---------- ----------
                   Buffer Cache:     2,752M     2,768M  Std Block Size:         8K
               Shared Pool Size:       320M       304M      Log Buffer:   145,412K
    Load Profile
    ~~~~~~~~~~~~                            Per Second       Per Transaction
                                       ---------------       ---------------
                      Redo size:          1,707,965.39              2,981.37
                  Logical reads:             13,631.51                 23.79
                  Block changes:              8,323.17                 14.53
                 Physical reads:                678.13                  1.18
                Physical writes:                187.38                  0.33
                     User calls:              1,925.97                  3.36
                         Parses:                  4.71                  0.01
                    Hard parses:                  0.06                  0.00
                          Sorts:                  3.41                  0.01
                         Logons:                  0.71                  0.00
                       Executes:                590.20                  1.03
                   Transactions:                572.88
      % Blocks changed per Read:   61.06    Recursive Call %:    41.60
     Rollback per transaction %:    0.00       Rows per Sort:  2425.97
    Instance Efficiency Percentages (Target 100%)
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                Buffer Nowait %:   99.84       Redo NoWait %:  100.00
                Buffer  Hit   %:   95.08    In-memory Sort %:   99.98
                Library Hit   %:  100.00        Soft Parse %:   98.72
             Execute to Parse %:   99.20         Latch Hit %:   99.60
    Parse CPU to Parse Elapsd %:   32.18     % Non-Parse CPU:   99.96
     Shared Pool Statistics        Begin    End
                                  ------  ------
                 Memory Usage %:   73.16   71.38
        % SQL with executions>1:   81.84   82.83
      % Memory for SQL w/exec>1:   82.81   85.66
    
    Top 5 Timed Events                                         Avg %Total
    ~~~~~~~~~~~~~~~~~~                                        wait   Call
    Event                                 Waits    Time (s)   (ms)   Time Wait Class
    ------------------------------ ------------ ----------- ------ ------ ----------
    CPU time                                            687          48.8
    db file scattered read              150,720         585      4   41.6   User I/O
    log file parallel write             515,882         583      1   41.4 System I/O
    db file sequential read              20,437         149      7   10.6   User I/O
    db file parallel write               29,702         145      5   10.3 System I/O
              -------------------------------------------------------------
    Statistic Name                                       Time (s) % of DB Time
    ------------------------------------------ ------------------ ------------
    sql execute elapsed time                              1,219.3         86.6
    DB CPU                                                  687.3         48.8
    connection management call elapsed time                   4.9           .3
    parse time elapsed                                        2.1           .1
    hard parse elapsed time                                   1.4           .1
    hard parse (sharing criteria) elapsed time                0.5           .0
    PL/SQL execution elapsed time                             0.5           .0
    hard parse (bind mismatch) elapsed time                   0.3           .0
    PL/SQL compilation elapsed time                           0.3           .0
    repeated bind elapsed time                                0.0           .0
    failed parse elapsed time                                 0.0           .0
    DB time                                               1,407.7          N/A
    background elapsed time                                 900.8          N/A
    background cpu time                                     337.4          N/A
              -------------------------------------------------------------
                                                                     Avg
                                           %Time       Total Wait    wait     Waits
    Wait Class                      Waits  -outs         Time (s)    (ms)      /txn
    -------------------- ---------------- ------ ---------------- ------- ---------
    User I/O                      172,355     .0              752       4       0.2
    System I/O                    548,403     .0              736       1       0.5
    Concurrency                    81,397     .0               29       0       0.1
    Commit                          2,023     .1                6       3       0.0
    Configuration                  23,796   98.3                5       0       0.0
    Network                     3,453,138     .0                5       0       3.4
    Other                          27,836    9.8                2       0       0.0
    Application                         4     .0                0       0       0.0
              
                                                                       Avg
                                                 %Time  Total Wait    wait     Waits
    Event                                 Waits  -outs    Time (s)    (ms)      /txn
    ---------------------------- -------------- ------ ----------- ------- ---------
    db file scattered read              150,720     .0         585       4       0.1
    log file parallel write             515,882     .0         583       1       0.5
    db file sequential read              20,437     .0         149       7       0.0
    db file parallel write               29,702     .0         145       5       0.0
    enq: TX - index contention            8,088     .0          23       3       0.0
    direct path write temp                  363     .0          11      31       0.0
    control file parallel write             638     .0           6      10       0.0
    log file sync                         2,023     .1           6       3       0.0
    SQL*Net message to client         3,446,370     .0           5       0       3.4
    log file switch completion               73     .0           5      68       0.0
    read by other session                   114     .0           5      41       0.0
    buffer busy waits                    39,819     .0           4       0       0.0
    direct path read temp                   651     .0           2       4       0.0
    control file sequential read          2,157     .0           2       1       0.0
    latch: In memory undo latch          33,279     .0           2       0       0.0
    rdbms ipc reply                         199     .0           1       7       0.0
    LGWR wait for redo copy              24,307     .0           0       0       0.0
    log buffer space                        309     .3           0       1       0.0
    SQL*Net more data from clien          6,732     .0           0       0       0.0
    log file sequential read                 12     .0           0       7       0.0
    undo segment extension               23,402  100.0           0       0       0.0
    direct path read                         33     .0           0       2       0.0
    latch free                               32     .0           0       1       0.0
    os thread startup                         1     .0           0      46       0.0
    buffer deadlock                       2,783   98.2           0       0       0.0
    db file parallel read                     1     .0           0      23       0.0
    latch: cache buffers chains             197     .0           0       0       0.0
    latch: messages                          54     .0           0       0       0.0
    library cache load lock                   1     .0           0       9       0.0
    latch: session allocation                34     .0           0       0       0.0
    log file single write                    12     .0           0       1       0.0
    cursor: pin S                           406     .0           0       0       0.0
    latch: library cache                      9     .0           0       0       0.0
    direct path write                        36     .0           0       0       0.0
    enq: TX - contention                      2     .0           0       1       0.0
    latch: redo allocation                    9     .0           0       0       0.0
    enq: FB - contention                      4     .0           0       0       0.0
    latch: redo writing                       8     .0           0       0       0.0
    SQL*Net more data to client              36     .0           0       0       0.0
    enq: HW - contention                      4     .0           0       0       0.0
    SQL*Net break/reset to clien              4     .0           0       0       0.0
    latch: shared pool                        3     .0           0       0       0.0
    latch: enqueue hash chains                2     .0           0       0       0.0
    latch: checkpoint queue latc              1     .0           0       0       0.0
    latch: undo global data                   1     .0           0       0       0.0
    latch: cache buffers lru cha              2     .0           0       0       0.0
    SQL*Net message from client       3,446,369     .0     118,085      34       3.4
    Streams AQ: qmn slave idle w             64     .0       1,726   26973       0.0
    Streams AQ: qmn coordinator             128   50.0       1,726   13487       0.0
    virtual circuit status                   59  100.0       1,717   29105       0.0
    Streams AQ: waiting for time             24  100.0       1,611   67116       0.0
    class slave wait                          1     .0           0       0       0.0
                                                                       Avg
                                                 %Time  Total Wait    wait     Waits
    Event                                 Waits  -outs    Time (s)    (ms)      /txn
    ---------------------------- -------------- ------ ----------- ------- ---------
    log file parallel write             515,882     .0         583       1       0.5
    db file parallel write               29,702     .0         145       5       0.0
    control file parallel write             638     .0           6      10       0.0
    events in waitclass Other            24,557     .0           2       0       0.0
    db file scattered read                  166     .0           1       9       0.0
    control file sequential read            120     .0           1       8       0.0
    log buffer space                        309     .3           0       1       0.0
    db file sequential read                  86     .0           0       1       0.0
    log file sequential read                 12     .0           0       7       0.0
    direct path read                         33     .0           0       2       0.0
    os thread startup                         1     .0           0      46       0.0
    log file single write                    12     .0           0       1       0.0
    buffer busy waits                        33     .0           0       0       0.0
    latch: redo writing                       8     .0           0       0       0.0
    direct path write                        31     .0           0       0       0.0
    latch: cache buffers chains               7     .0           0       0       0.0
    latch: In memory undo latch               2     .0           0       0       0.0
    rdbms ipc message                 2,287,034     .2      19,493       9       2.2
    pmon timer                              716  100.0       1,746    2439       0.0
    Streams AQ: qmn slave idle w             64     .0       1,726   26973       0.0
    Streams AQ: qmn coordinator             128   50.0       1,726   13487       0.0
    smon timer                               88     .0       1,707   19395       0.0
    Streams AQ: waiting for time             24  100.0       1,611   67116       0.0
              -------------------------------------------------------------
    
    Operating System Statistics         DB/Inst: TRADE1/TRADE1  Snaps: 21020-21021
    
    Statistic                                       Total
    -------------------------------- --------------------
    AVG_BUSY_TIME                                  29,540
    AVG_IDLE_TIME                                 149,296
    AVG_IOWAIT_TIME                                     0
    AVG_SYS_TIME                                   11,457
    AVG_USER_TIME                                  18,032
    BUSY_TIME                                     473,589
    IDLE_TIME                                   2,389,633
    IOWAIT_TIME                                         0
    SYS_TIME                                      184,140
    USER_TIME                                     289,449
    LOAD                                                3
    OS_CPU_WAIT_TIME                               31,100
    RSRC_MGR_CPU_WAIT_TIME                              0
    VM_IN_BYTES                                    57,344
    VM_OUT_BYTES                                        0
    PHYSICAL_MEMORY_BYTES                  17,170,685,952
    NUM_CPUS                                           16
        Service Statistics                 DB/Inst: TRADE1/TRADE1  Snaps: 21020-21021
    -> ordered by DB Time
    
                                                                 Physical    Logical
    Service Name                      DB Time (s)   DB CPU (s)      Reads      Reads
    -------------------------------- ------------ ------------ ---------- ----------
    TRADE1                                1,194.3        651.8    910,636 ##########
    SYS$USERS                               213.5         35.6    300,083    497,748
    SYS$BACKGROUND                            0.0          0.0      2,254     17,025
    TRADE1XDB                                 0.0          0.0          0          0
              -------------------------------------------------------------
    
    Service Wait Class Stats            DB/Inst: TRADE1/TRADE1  Snaps: 21020-21021
    -> Wait Class info for services in the Service Statistics section.
    -> Total Waits and Time Waited displayed for the following wait
       classes:  User I/O, Concurrency, Administrative, Network
    -> Time Waited (Wt Time) in centisecond (100th of a second)
    
    Service Name
    ----------------------------------------------------------------
     User I/O  User I/O  Concurcy  Concurcy     Admin     Admin   Network   Network
    Total Wts   Wt Time Total Wts   Wt Time Total Wts   Wt Time Total Wts   Wt Time
    --------- --------- --------- --------- --------- --------- --------- ---------
    TRADE1
       129821     55804     81292      2938         0         0   3442048       511
    SYS$USERS
        41426     18885        62         1         0         0      5963         1
    SYS$BACKGROUND
         1097       528        43         5         0         0         0         0
              -------------------------------------------------------------
    
    SQL ordered by Elapsed Time        DB/Inst: TRADE1/TRADE1  Snaps: 21020-21021
    -> Resources reported for PL/SQL code includes the resources used by all SQL
       statements called by the code.
    -> % Total DB Time is the Elapsed Time of the SQL statement divided
       into the Total Database Time multiplied by 100
    
      Elapsed      CPU                  Elap per  % Total
      Time (s)   Time (s)  Executions   Exec (s)  DB Time    SQL Id
    ---------- ---------- ------------ ---------- ------- -------------
           340        278      639,914        0.0    24.1 2yrr9gdghrdbs
    Module: perbroker@prdba001 (TNS V1-V3)
    INSERT INTO tibex_Order(ORDERID,USERORDERID,ORDERSIDE,ORDERTYPE,ORDERSTATUS,BOAR
    DID,TIMEINFORCE,INSTRUMENTID,REFERENCEID,PRICETYPE,PRICE,AVERAGEPRICE,QUANTITY,M
    INIMUMFILL,DISCLOSEDQTY,REMAINQTY,AON,PARTICIPANTID,ACCOUNTTYPE,ACCOUNTNO,CLEARI
    NGAGENCY,LASTINSTRESULT,LASTINSTMESSAGESEQUENCE,LASTEXECUTIONID,NOTE,TIMESTAMP,Q
    
           203         27            5       40.6    14.4 03fqwamsdv6pf
    Module: perbroker@prdba001 (TNS V1-V3)
    select mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from tibex_msgse
    qbyuseralias where useralias=:"SYS_B_1"
    
           167        106      376,683        0.0    11.9 4faqv5m86gjn1
    Module: perbroker@prdba001 (TNS V1-V3)
    INSERT INTO tibex_FixSessionState(USERALIAS,FIXMESSAGETYPE,FROMFIXSEQUENCE,TOETS
    SEQUENCE,FROMETSSEQUENCE,TOFIXSEQUENCE,INSTRUMENTID,FROMETSTIMESTAMP,TIMESTAMP,F
    ROMRESETCOUNT,SENDTYPE) VALUES (:USERALIAS ,:FIXMESSAGETYPE ,:FR
    OMFIXSEQUENCE ,:TOETSSEQUENCE ,:FROMETSSEQUENCE ,:TOFIXSEQU
    
           160         19            1      160.4    11.4 3dduvdtcjtqu3
    Module: SQL*Plus
    select mod(lastinstmessagesequence, :"SYS_B_0") LastInstIDSeqNo from tibex_msgse
    qbyuseralias where useralias<>:"SYS_B_1"
    
           134         16            1      133.7     9.5 frqyvd3w3bh83
    Module: perl@prdfweb01 (TNS V1-V3)
    SELECT participantID, count(*) FROM tibex_order GROUP BY participantID ORD
    ER BY :"SYS_B_0"
    
           113         19            1      112.9     8.0 0umu85c0fmjq2
    Module: SQL*Plus
    select useralias from tibex_msgseqbyuseralias where useralias<>:"SYS_B_0"
    
            73         14            1       73.3     5.2 23ndzxsxzhs9d
    Module: perl@prdfweb01 (TNS V1-V3)
    SELECT quotes, quoteUpdates, orders, orderupdates FROM ( select to_char(count(
    distinct orderid) , :"SYS_B_0") orders, to_char(count(*) , :"SY
    S_B_1") orderUpdates from tibex_order ), ( select to_ch
    ar(count(distinct quoteID) , :"SYS_B_2") quotes, to_char(count(*
    
    
    Instance Activity Stats            DB/Inst: TRADE1/TRADE1  Snaps: 21020-21021
    
    Statistic                                     Total     per Second     per Trans
    -------------------------------- ------------------ -------------- -------------
    CPU used by this session                     70,421           39.4           0.1
    CPU used when call started                   70,115           39.2           0.1
    CR blocks created                             8,172            4.6           0.0
    Cached Commit SCN referenced                    240            0.1           0.0
    Commit SCN cached                                 6            0.0           0.0
    DB time                                     146,225           81.8           0.1
    DBWR checkpoint buffers written             152,274           85.1           0.2
    DBWR checkpoints                                  3            0.0           0.0
    DBWR object drop buffers written                  0            0.0           0.0
    DBWR thread checkpoint buffers w            152,274           85.1           0.2
    DBWR transaction table writes                    36            0.0           0.0
    DBWR undo block writes                      150,737           84.3           0.2
    IMU CR rollbacks                                  1            0.0           0.0
    IMU Flushes                                 240,737          134.6           0.2
    IMU Redo allocation size                796,681,460      445,387.5         777.5
    IMU commits                                 651,086          364.0           0.6
    IMU contention                              101,672           56.8           0.1
  • 14. Re: Query Takes more Time when i execute from the Instant client.
    CharlesHooper Expert
    Currently Being Moderated
    We might be reaching the end of potential analysis for DBMS_XPLAN - we do not know for certain what the generated SQL_ID is when the program executes client-side and server-side. What might be interesting in what you posted is the following:
    SQL_ID  bpxr7axhxaqvy, child number 2
    Note that this is child number 2 - previously we only saw child number 0 and 1 in your output. The execution plan for this child number shows a value of 1 in the "A-Rows" column for the top row, while that row/column combination for child number 0 and 1 is 0. The "A-Rows" column will only be populated when the STATISTICS_LEVEL parameter is set to ALL at the session or instance-wide level, or when the GATHER_PLAN_STATISTICS hint is specified. In this case the hint was specified. Setting the STATISTICS_LEVEL parameter to ALL will impact the execution time, especially in 10g R2 when nested loop operations appear in the execution plan. If you used the script that I provided, the SQL statement would have been executed with the STATISTICS_LEVEL parameter set to TYPICAL, but it might be set to ALL in the instant client's session by default (this is something we will need to check).

    Quick question: if you change the script to specify SET TIMING ON, do you observe a similar time on the server and client side for the script?

    If you still see performance differences between the client-side and server-side when 0 rows (or 1 row) are returned, consider enabling an extended SQL trace (event 10046 at level 8 or 12). Refer to this two part blog series:
    http://hoopercharles.wordpress.com/2009/12/01/10046-extended-sql-trace-interpretation/

    If you enable a 10046 trace, after the problematic (slow performing) SQL statement, execute a simple SQL statement such as the following to make certain that the execution plan (STAT lines) for the previous SQL statement are written to the trace file (this may not happen if the SQL statement has been executed 3 times by the session). A simple SQL statement might look like this:
    SELECT SYSDATE FROM DUAL;
    In 10g the SQL_ID for the SQL statement is not written to the trace file, as is the case for 11g. The hash value (hv) for the SQL statement is written to the trace file, and you can use that to query V$SQL to retrieve the matching SQL_ID so that you can then call DBMS_XPLAN to see a nicely formatted version of the actual execution plan.

    We are interested in the actual execution plan and the wait events. If you process the 10046 trace file using tkprof (do NOT use the EXPLAIN parameter), that output should contain the information that we need to help you determine what is different - why the instant client is slow while the server side is fast.

    Charles Hooper
    Co-author of "Expert Oracle Practices: Oracle Database Administration from the Oak Table"
    http://hoopercharles.wordpress.com/
    IT Manager/Oracle DBA
    K&M Machine-Fabricating, Inc.
1 2 3 Previous Next

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points