1. Get rid of all advertisements and get unlimited access to documents by upgrading to Premium Membership. Upgrade to Premium Now and also get a Premium Badge!

how to troubleshoot slow running queries?

Discussion in 'General' started by ashwanth, Jun 12, 2014.

  1. ashwanth

    ashwanth Active Member

    Messages:
    25
    Likes Received:
    0
    Trophy Points:
    80
    how to troubleshoot slow running queries?

    db version 11.2
     
  2. zargon

    zargon Community Moderator Forum Guru

    Messages:
    2,351
    Likes Received:
    348
    Trophy Points:
    1,430
    Location:
    Aurora, CO
    The first issue is your belief that having an index on a table that you're not using will improve performance. You can't use the index on object_key because it's not in the WHERE clause; Oracle doesn't use indexes on columns it's not searching on. Second, if object_key can contain NULL values Oracle won't use the index without an IS NOT NULL directive as it won't return incomplete results. You have no usable indexes on this table so the only path Oracle can take is a full table scan. An index on sharing_key, deletion_flag or both could speed this query up considerably, as could current statistics. As an example:


    Code (SQL):

    SQL> CREATE TABLE objects(
      2  object_class      NUMBER,
      3  object_sub_class      NUMBER,
      4  object_category      varchar2(30),
      5  object_key       varchar2(12),
      6  object_id       NUMBER,
      7  object_name      varchar2(30),
      8  ishidden       varchar2(1),
      9  sharing_key      NUMBER,
     10  ownership_key      varchar2(20),
     11  picturesheet_key      varchar2(20),
     12  haspictureblob      varchar2(1),
     13  deletion_flag      varchar2(1));


    TABLE created.


    SQL>
    SQL> CREATE INDEX objects_key_idx ON objects(object_key);


    INDEX created.


    SQL>
    SQL> BEGIN
      2        FOR i IN 1..2000000 loop
      3         IF i <= 14115 THEN
      4         INSERT INTO objects
      5         VALUES(i, i,'Category'||i, 'XDD'||lpad(i,9,'0'), i, 'Object'||i,'N',0, 'OWN'||lpad(i, 17,'0'),'PCT'||lpad(i, 17,'0'),'Y','N');
      6         elsif i > 14115 AND i<=28230 THEN
      7         INSERT INTO objects
      8         VALUES(i, i,'Category'||i, 'XDD'||lpad(i,9,'0'), i, 'Object'||i,'N',3375705, 'OWN'||lpad(i, 17,'0'),'PCT'||lpad(i, 17,'0'),'Y','N');
      9         elsif i > 28230 AND i<= 42345 THEN
     10         INSERT INTO objects
     11         VALUES(i, i,'Category'||i, 'XDD'||lpad(i,9,'0'), i, 'Object'||i,'N',1199264, 'OWN'||lpad(i, 17,'0'),'PCT'||lpad(i, 17,'0'),'Y','N');
     12         ELSE
     13         INSERT INTO objects
     14         VALUES(i, i,'Category'||i, 'XDD'||lpad(i,9,'0'), i, 'Object'||i,'N',i-1, 'OWN'||lpad(i, 17,'0'),'PCT'||lpad(i, 17,'0'),'Y','Y');
     15         END IF;
     16        END loop;
     17        commit;
     18  END;
     19  /


    PL/SQL PROCEDURE successfully completed.


    SQL>
    SQL> SET autotrace ON timing ON
    SQL>
    SQL> SELECT Object_Class,
      2        Object_Sub_Class,
      3        Object_Category,
      4        Object_Key,
      5        Object_ID,
      6        Object_Name,
      7        IsHidden,
      8        Sharing_Key,
      9        Ownership_Key,
     10        PictureSheet_Key,
     11        HasPictureBlob
     12  FROM Objects
     13  WHERE Deletion_Flag <> 'Y' AND (Sharing_Key IN (0, 3375705, 1199264));


    OBJECT_CLASS OBJECT_SUB_CLASS OBJECT_CATEGORY                OBJECT_KEY    OBJECT_ID OBJECT_NAME                    I SHARING_KEY OWNERSHIP_KEY        PICTURESHEET_KEY     H
    ------------ ---------------- ------------------------------ ------------ ---------- ------------------------------ - ----------- -------------------- -------------------- -
             219              219 Category219                    XDD000000219        219 Object219                      N           0 OWN00000000000000219 PCT00000000000000219 Y
             220              220 Category220                    XDD000000220        220 Object220                      N           0 OWN00000000000000220 PCT00000000000000220 Y
             221              221 Category221                    XDD000000221        221 Object221                      N           0 OWN00000000000000221 PCT00000000000000221 Y
    ...
           41329            41329 Category41329                  XDD000041329      41329 Object41329                    N     1199264 OWN00000000000041329 PCT00000000000041329 Y


    42345 ROWS selected.


    Elapsed: 00:00:23.06


    Execution Plan
    ----------------------------------------------------------
    Plan hash VALUE: 80137940
    -----------------------------------------------------------------------------
    | Id  | Operation         | Name    | ROWS  | Bytes | Cost (%CPU)| TIME     |
    -----------------------------------------------------------------------------
    |   0 | SELECT STATEMENT  |         | 33053 |  4002K|  8853   (1)| 00:00:03 |
    |*  1 |  TABLE ACCESS FULL| OBJECTS | 33053 |  4002K|  8853   (1)| 00:00:03 |
    -----------------------------------------------------------------------------
    Predicate Information (IDENTIFIED BY operation id):
    ---------------------------------------------------
       1 - FILTER(("SHARING_KEY"=0 OR "SHARING_KEY"=1199264 OR
                  "SHARING_KEY"=3375705) AND "DELETION_FLAG"<>'Y')
    Note
    -----
       - dynamic sampling used FOR this statement (level=2)

    Statistics
    ----------------------------------------------------------
             21  recursive calls
              2  db block gets
          68389  consistent gets
          32809  physical reads
           5876  redo SIZE
        4783302  bytes sent via SQL*Net TO client
          31562  bytes received via SQL*Net FROM client
           2824  SQL*Net roundtrips TO/FROM client
              0  sorts (memory)
              0  sorts (disk)
          42345  ROWS processed


    SQL>
    SQL> SELECT Object_Class,
      2        Object_Sub_Class,
      3        Object_Category,
      4        Object_Key,
      5        Object_ID,
      6        Object_Name,
      7        IsHidden,
      8        Sharing_Key,
      9        Ownership_Key,
     10        PictureSheet_Key,
     11        HasPictureBlob
     12  FROM Objects
     13  WHERE Deletion_Flag <> 'Y' AND (Sharing_Key IN (0, 3375705, 1199264)) AND object_key LIKE 'XDD00%';


    OBJECT_CLASS OBJECT_SUB_CLASS OBJECT_CATEGORY                OBJECT_KEY    OBJECT_ID OBJECT_NAME                    I SHARING_KEY OWNERSHIP_KEY        PICTURESHEET_KEY     H
    ------------ ---------------- ------------------------------ ------------ ---------- ------------------------------ - ----------- -------------------- -------------------- -
               1                1 Category1                      XDD000000001          1 Object1                        N           0 OWN00000000000000001 PCT00000000000000001 Y
               2                2 Category2                      XDD000000002          2 Object2                        N           0 OWN00000000000000002 PCT00000000000000002 Y
               3                3 Category3                      XDD000000003          3 Object3                        N           0 OWN00000000000000003 PCT00000000000000003 Y
    ...
           42345            42345 Category42345                  XDD000042345      42345 Object42345                    N     1199264 OWN00000000000042345 PCT00000000000042345 Y


    42345 ROWS selected.


    Elapsed: 00:01:25.69


    Execution Plan
    ----------------------------------------------------------
    Plan hash VALUE: 483981952
    -----------------------------------------------------------------------------------------------
    | Id  | Operation                   | Name            | ROWS  | Bytes | Cost (%CPU)| TIME     |
    -----------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT            |                 | 33053 |  4002K|  6041   (1)| 00:00:02 |
    |*  1 |  TABLE ACCESS BY INDEX ROWID| OBJECTS         | 33053 |  4002K|  6041   (1)| 00:00:02 |
    |*  2 |   INDEX RANGE SCAN          | OBJECTS_KEY_IDX |  2561K|       |  6041   (1)| 00:00:02 |
    -----------------------------------------------------------------------------------------------
    Predicate Information (IDENTIFIED BY operation id):
    ---------------------------------------------------
       1 - FILTER(("SHARING_KEY"=0 OR "SHARING_KEY"=1199264 OR "SHARING_KEY"=3375705) AND
                  "DELETION_FLAG"<>'Y')
       2 - access("OBJECT_KEY" LIKE 'XDD00%')
           FILTER("OBJECT_KEY" LIKE 'XDD00%')
    Note
    -----
       - dynamic sampling used FOR this statement (level=2)

    Statistics
    ----------------------------------------------------------
             10  recursive calls
              3  db block gets
          82873  consistent gets
          34509  physical reads
        2816168  redo SIZE
        4783162  bytes sent via SQL*Net TO client
          31562  bytes received via SQL*Net FROM client
           2824  SQL*Net roundtrips TO/FROM client
              0  sorts (memory)
              0  sorts (disk)
          42345  ROWS processed


    SQL>
     

    Notice that with the right WHERE clause the existing index can be used. This is using 11.2.0.3; earlier releases would not necessarily use an index on a nullable column thus the query shown below would be used to make that index access happen:



    Code (SQL):

    SQL> SELECT Object_Class,
      2        Object_Sub_Class,
      3        Object_Category,
      4        Object_Key,
      5        Object_ID,
      6        Object_Name,
      7        IsHidden,
      8        Sharing_Key,
      9        Ownership_Key,
     10        PictureSheet_Key,
     11        HasPictureBlob
     12  FROM Objects
     13  WHERE Deletion_Flag <> 'Y' AND (Sharing_Key IN (0, 3375705, 1199264)) AND object_key LIKE 'XDD00%' AND object_key IS NOT NULL;


    OBJECT_CLASS OBJECT_SUB_CLASS OBJECT_CATEGORY                OBJECT_KEY    OBJECT_ID OBJECT_NAME                    I SHARING_KEY OWNERSHIP_KEY        PICTURESHEET_KEY     H
    ------------ ---------------- ------------------------------ ------------ ---------- ------------------------------ - ----------- -------------------- -------------------- -
               1                1 Category1                      XDD000000001          1 Object1                        N           0 OWN00000000000000001 PCT00000000000000001 Y
               2                2 Category2                      XDD000000002          2 Object2                        N           0 OWN00000000000000002 PCT00000000000000002 Y
               3                3 Category3                      XDD000000003          3 Object3                        N           0 OWN00000000000000003 PCT00000000000000003 Y
    ...
           42345            42345 Category42345                  XDD000042345      42345 Object42345                    N     1199264 OWN00000000000042345 PCT00000000000042345 Y


    42345 ROWS selected.


    Elapsed: 00:00:59.41


    Execution Plan
    ----------------------------------------------------------
    Plan hash VALUE: 483981952
    -----------------------------------------------------------------------------------------------
    | Id  | Operation                   | Name            | ROWS  | Bytes | Cost (%CPU)| TIME     |
    -----------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT            |                 | 33053 |  4002K|  6041   (1)| 00:00:02 |
    |*  1 |  TABLE ACCESS BY INDEX ROWID| OBJECTS         | 33053 |  4002K|  6041   (1)| 00:00:02 |
    |*  2 |   INDEX RANGE SCAN          | OBJECTS_KEY_IDX |  2561K|       |  6041   (1)| 00:00:02 |
    -----------------------------------------------------------------------------------------------
    Predicate Information (IDENTIFIED BY operation id):
    ---------------------------------------------------
       1 - FILTER(("SHARING_KEY"=0 OR "SHARING_KEY"=1199264 OR "SHARING_KEY"=3375705) AND
                  "DELETION_FLAG"<>'Y')
       2 - access("OBJECT_KEY" LIKE 'XDD00%')
           FILTER("OBJECT_KEY" IS NOT NULL AND "OBJECT_KEY" LIKE 'XDD00%')
    Note
    -----
       - dynamic sampling used FOR this statement (level=2)

    Statistics
    ----------------------------------------------------------
             10  recursive calls
              3  db block gets
          44444  consistent gets
          34095  physical reads
              0  redo SIZE
        4783162  bytes sent via SQL*Net TO client
          31562  bytes received via SQL*Net FROM client
           2824  SQL*Net roundtrips TO/FROM client
              0  sorts (memory)
              0  sorts (disk)
          42345  ROWS processed


    SQL>
     


    Likewise making the column NOT NULL would engage the index access path, as it seems 11.2.0.3 does anyway:



    Code (SQL):
     
    SQL> ALTER TABLE objects MODIFY object_key NOT NULL;


    TABLE altered.


    Elapsed: 00:00:05.45

    SQL>
    SQL> SELECT Object_Class,
      2        Object_Sub_Class,
      3        Object_Category,
      4        Object_Key,
      5        Object_ID,
      6        Object_Name,
      7        IsHidden,
      8        Sharing_Key,
      9        Ownership_Key,
     10        PictureSheet_Key,
     11        HasPictureBlob
     12  FROM Objects
     13  WHERE Deletion_Flag <> 'Y' AND (Sharing_Key IN (0, 3375705, 1199264)) AND object_key LIKE 'XDD00%';


    OBJECT_CLASS OBJECT_SUB_CLASS OBJECT_CATEGORY                OBJECT_KEY    OBJECT_ID OBJECT_NAME                    I SHARING_KEY OWNERSHIP_KEY        PICTURESHEET_KEY     H
    ------------ ---------------- ------------------------------ ------------ ---------- ------------------------------ - ----------- -------------------- -------------------- -
               1                1 Category1                      XDD000000001          1 Object1                        N           0 OWN00000000000000001 PCT00000000000000001 Y
               2                2 Category2                      XDD000000002          2 Object2                        N           0 OWN00000000000000002 PCT00000000000000002 Y
               3                3 Category3                      XDD000000003          3 Object3                        N           0 OWN00000000000000003 PCT00000000000000003 Y
    ...
           42345            42345 Category42345                  XDD000042345      42345 Object42345                    N     1199264 OWN00000000000042345 PCT00000000000042345 Y


    42345 ROWS selected.


    Elapsed: 00:00:41.49


    Execution Plan
    ----------------------------------------------------------
    Plan hash VALUE: 483981952
    -----------------------------------------------------------------------------------------------
    | Id  | Operation                   | Name            | ROWS  | Bytes | Cost (%CPU)| TIME     |
    -----------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT            |                 | 33053 |  4002K|  6041   (1)| 00:00:02 |
    |*  1 |  TABLE ACCESS BY INDEX ROWID| OBJECTS         | 33053 |  4002K|  6041   (1)| 00:00:02 |
    |*  2 |   INDEX RANGE SCAN          | OBJECTS_KEY_IDX |  2561K|       |  6041   (1)| 00:00:02 |
    -----------------------------------------------------------------------------------------------
    Predicate Information (IDENTIFIED BY operation id):
    ---------------------------------------------------
       1 - FILTER(("SHARING_KEY"=0 OR "SHARING_KEY"=1199264 OR "SHARING_KEY"=3375705) AND
                  "DELETION_FLAG"<>'Y')
       2 - access("OBJECT_KEY" LIKE 'XDD00%')
           FILTER("OBJECT_KEY" LIKE 'XDD00%')
    Note
    -----
       - dynamic sampling used FOR this statement (level=2)

    Statistics
    ----------------------------------------------------------
             30  recursive calls
              1  db block gets
          44471  consistent gets
          34154  physical reads
              0  redo SIZE
        4783162  bytes sent via SQL*Net TO client
          31562  bytes received via SQL*Net FROM client
           2824  SQL*Net roundtrips TO/FROM client
              6  sorts (memory)
              0  sorts (disk)
          42345  ROWS processed
    SQL>
     


    Creating an index on deletion_flag doesn't do much good for the queries given the volume of data returned as neither query generates an index access path:



    Code (SQL):
     
    SQL> CREATE INDEX objects_del_flg_idx ON objects(deletion_flag);


    INDEX created.


    Elapsed: 00:00:06.63

    SQL>
    SQL> SELECT Object_Class,
      2        Object_Sub_Class,
      3        Object_Category,
      4        Object_Key,
      5        Object_ID,
      6        Object_Name,
      7        IsHidden,
      8        Sharing_Key,
      9        Ownership_Key,
     10        PictureSheet_Key,
     11        HasPictureBlob
     12  FROM Objects
     13  WHERE Deletion_Flag <> 'Y' AND (Sharing_Key IN (0, 3375705, 1199264));


    OBJECT_CLASS OBJECT_SUB_CLASS OBJECT_CATEGORY                OBJECT_KEY    OBJECT_ID OBJECT_NAME                    I SHARING_KEY OWNERSHIP_KEY        PICTURESHEET_KEY     H
    ------------ ---------------- ------------------------------ ------------ ---------- ------------------------------ - ----------- -------------------- -------------------- -
             219              219 Category219                    XDD000000219        219 Object219                      N           0 OWN00000000000000219 PCT00000000000000219 Y
             220              220 Category220                    XDD000000220        220 Object220                      N           0 OWN00000000000000220 PCT00000000000000220 Y
             221              221 Category221                    XDD000000221        221 Object221                      N           0 OWN00000000000000221 PCT00000000000000221 Y
    ...
           41329            41329 Category41329                  XDD000041329      41329 Object41329                    N     1199264 OWN00000000000041329 PCT00000000000041329 Y


    42345 ROWS selected.


    Elapsed: 00:00:20.41


    Execution Plan
    ----------------------------------------------------------
    Plan hash VALUE: 80137940
    -----------------------------------------------------------------------------
    | Id  | Operation         | Name    | ROWS  | Bytes | Cost (%CPU)| TIME     |
    -----------------------------------------------------------------------------
    |   0 | SELECT STATEMENT  |         | 33053 |  4002K|  8853   (1)| 00:00:03 |
    |*  1 |  TABLE ACCESS FULL| OBJECTS | 33053 |  4002K|  8853   (1)| 00:00:03 |
    -----------------------------------------------------------------------------
    Predicate Information (IDENTIFIED BY operation id):
    ---------------------------------------------------
       1 - FILTER(("SHARING_KEY"=0 OR "SHARING_KEY"=1199264 OR
                  "SHARING_KEY"=3375705) AND "DELETION_FLAG"<>'Y')
    Note
    -----
       - dynamic sampling used FOR this statement (level=2)

    Statistics
    ----------------------------------------------------------
              5  recursive calls
              2  db block gets
          35863  consistent gets
          22207  physical reads
              0  redo SIZE
        4783302  bytes sent via SQL*Net TO client
          31562  bytes received via SQL*Net FROM client
           2824  SQL*Net roundtrips TO/FROM client
              0  sorts (memory)
              0  sorts (disk)
          42345  ROWS processed


    SQL>
    SQL> ALTER TABLE objects MODIFY deletion_flag NOT NULL;


    TABLE altered.


    Elapsed: 00:00:05.26

    SQL>
    SQL> SELECT Object_Class,
      2        Object_Sub_Class,
      3        Object_Category,
      4        Object_Key,
      5        Object_ID,
      6        Object_Name,
      7        IsHidden,
      8        Sharing_Key,
      9        Ownership_Key,
     10        PictureSheet_Key,
     11        HasPictureBlob
     12  FROM Objects
     13  WHERE Deletion_Flag <> 'Y' AND (Sharing_Key IN (0, 3375705, 1199264));


    OBJECT_CLASS OBJECT_SUB_CLASS OBJECT_CATEGORY                OBJECT_KEY    OBJECT_ID OBJECT_NAME                    I SHARING_KEY OWNERSHIP_KEY        PICTURESHEET_KEY     H
    ------------ ---------------- ------------------------------ ------------ ---------- ------------------------------ - ----------- -------------------- -------------------- -
             219              219 Category219                    XDD000000219        219 Object219                      N           0 OWN00000000000000219 PCT00000000000000219 Y
             220              220 Category220                    XDD000000220        220 Object220                      N           0 OWN00000000000000220 PCT00000000000000220 Y
             221              221 Category221                    XDD000000221        221 Object221                      N           0 OWN00000000000000221 PCT00000000000000221 Y
    ...
           41329            41329 Category41329                  XDD000041329      41329 Object41329                    N     1199264 OWN00000000000041329 PCT00000000000041329 Y


    42345 ROWS selected.


    Elapsed: 00:00:20.54


    Execution Plan
    ----------------------------------------------------------
    Plan hash VALUE: 80137940
    -----------------------------------------------------------------------------
    | Id  | Operation         | Name    | ROWS  | Bytes | Cost (%CPU)| TIME     |
    -----------------------------------------------------------------------------
    |   0 | SELECT STATEMENT  |         | 33053 |  4002K|  8853   (1)| 00:00:03 |
    |*  1 |  TABLE ACCESS FULL| OBJECTS | 33053 |  4002K|  8853   (1)| 00:00:03 |
    -----------------------------------------------------------------------------
    Predicate Information (IDENTIFIED BY operation id):
    ---------------------------------------------------
       1 - FILTER(("SHARING_KEY"=0 OR "SHARING_KEY"=1199264 OR
                  "SHARING_KEY"=3375705) AND "DELETION_FLAG"<>'Y')
    Note
    -----
       - dynamic sampling used FOR this statement (level=2)

    Statistics
    ----------------------------------------------------------
             36  recursive calls
              2  db block gets
          35904  consistent gets
          22216  physical reads
              0  redo SIZE
        4783302  bytes sent via SQL*Net TO client
          31562  bytes received via SQL*Net FROM client
           2824  SQL*Net roundtrips TO/FROM client
              6  sorts (memory)
              0  sorts (disk)
          42345  ROWS processed


    SQL>
     

    Notice that none of the executions in this run consumed 16+ minutes of time; you really need to run an AWR report for the time that query ran to see what else may have been happening to slow it down to a crawl.