This discussion is archived
1 2 Previous Next 26 Replies Latest reply: Feb 8, 2010 10:23 AM by sb92075 Go to original post RSS
  • 15. Re: SQL taking very long time to execute
    CharlesHooper Expert
    Currently Being Moderated
    Mohamed Houri wrote:
    Charles,

    How could you always said

    do not use explain plan for and select * from table(dbms_xplan.display)

    Because of the bind variable that are all considered as varchar and impicit conversion could be made by the select * from table(dbms_xplan.display) while it might not be done in the real explain plan,

    And here you didn't said anyword about this fact?

    Regards

    Mohamed Houri
    There are no bind variables in the SQL statement provided by Yasser, and no evidence that he has CURSOR_SHARING set to anything other than EXACT.

    There is still a chance that the actual execution is not displayed for the SQL statement when he executes either an EXPLAIN PLAN FOR or an explain plan generated by AUTOTRACE. If the OP starts executing the SQL statement in one session, he should be able to use another session to query V$SESSION for the SQL_ID and SQL_CHILD_NUMBER that is executing in the first session. With that information, he should be able to call DBMS_XPLAN.DISPLAY_CURSOR to display the actual execution plan for that SQL_ID and CHILD_NUMBER.
    SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR(SQL_ID_here,SQL_CHILD_NUMBER_here,'TYPICAL'));
     
    -or-
     
    SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR(SQL_ID_here,SQL_CHILD_NUMBER_here,'ALLSTATS LAST'));
    So, assuming that the SQL_id is 2q93zsrvbdw48 and the SQL_CHILD_NUMBER is 1, the above might look something like this:
    SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR('2q93zsrvbdw48',1,'TYPICAL'));
     
    -or-
     
    SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR('2q93zsrvbdw48',1,'ALLSTATS LAST'));
    You might test the second method with ALLSTATS LAST - I am not sure if it is updated every 3 to 5 seconds, or only after the query completes.

    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.
  • 16. Re: SQL taking very long time to execute
    user503699 Expert
    Currently Being Moderated
    YasserRACDBA wrote:
    But why statistics has not been collected automatically even after using statistics_level to typical??

    -Yasser
    Not sure what you mean by that. Are you explcitly running stats collection? I guess not and it seems your database has the default stats collection job disabled.
  • 17. Re: SQL taking very long time to execute
    Yasu Newbie
    Currently Being Moderated
    Just for your information providing output for Charles queries.
    SQL> l
      1  SELECT
      2    *
      3  FROM
      4*   TABLE(DBMS_XPLAN.DISPLAY_CURSOR('11d2u41h3sjmr',0,'TYPICAL')
    SQL> SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR(  2    3    4  '11d2u41h3sjmr',0,'TYPICAL'));
    
    PLAN_TABLE_OUTPUT
    ------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  11d2u41h3sjmr, child number 0
    -------------------------------------
    SELECT /*+ gather_plan_statistics */   CCB.BROKER_NAME,   CCB.PARENT_BROKER_CODE,   MAX(CET.LAST_UPDATE_DATE) as
    LAST_SUBMISSION_DATE,   BROKER_CODE as CHILD_BROKER_CODE,   CBD.LOCATION FROM   CM_CACHE_BROKER CCB,   REM_TAG_VALUE RTV,
    CM_ENUM_TAG CET,   CM_CACHE_BROKER_detail CBD WHERE   CCB.PARENT_BROKER_CODE = RTV.TAG_VALUE   AND EXISTS     (SELECT       1
        FROM       REM_TAG_LIST RTL     WHERE       RTL.TAG_LIST_ID = RTV.TAG_LIST_ID       AND RTL.TAG_LIST_CODE =
    'FCBrokerCode')   AND RTV.TAG_VALUE_ID = CET.TAG_VALUE_ID   AND CCB.BROKER_ID=CBD.BROKER_ID GROUP BY   BROKER_NAME,
    PARENT_BROKER_CODE,   BROKER_CODE,   location
    
    Plan hash value: 1716752470
    
    --------------------------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                           | Name                   | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     | Pstart| Pstop |
    --------------------------------------------------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT                    |                        |       |       |       | 10839 (100)|          |       |       |
    |   1 |  HASH GROUP BY                      |                        |  7947 |  1544K|  3368K| 10839   (1)| 00:02:11 |       |       |
    |*  2 |   HASH JOIN                         |                        |  7947 |  1544K|       | 10493   (1)| 00:02:06 |       |       |
    |   3 |    TABLE ACCESS FULL                | CM_CACHE_BROKER_DETAIL |  6266 |   189K|       |    29   (0)| 00:00:01 |       |       |
    |   4 |    TABLE ACCESS BY LOCAL INDEX ROWID| CM_ENUM_TAG            |    41 |  1025 |       |  4970   (1)| 00:01:00 |       |       |
    |   5 |     NESTED LOOPS                    |                        |  4796 |   786K|       | 10463   (1)| 00:02:06 |       |       |
    |*  6 |      HASH JOIN                      |                        |   117 | 16731 |       |   978   (1)| 00:00:12 |       |       |
    |   7 |       TABLE ACCESS FULL             | CM_CACHE_BROKER        |  3781 |   158K|       |    15   (0)| 00:00:01 |       |       |
    |   8 |       NESTED LOOPS                  |                        | 74085 |  7234K|       |   962   (1)| 00:00:12 |       |       |
    |   9 |        TABLE ACCESS BY INDEX ROWID  | REM_TAG_LIST           |     1 |    43 |       |     1   (0)| 00:00:01 |       |       |
    |* 10 |         INDEX UNIQUE SCAN           | AK1_REM_TAG_LIST_CODE  |     1 |       |       |     0   (0)|          |       |       |
    |  11 |        TABLE ACCESS BY INDEX ROWID  | REM_TAG_VALUE          | 74085 |  4123K|       |   961   (1)| 00:00:12 |       |       |
    |* 12 |         INDEX RANGE SCAN            | REM_TAG_VALUE_IDX1     | 74085 |       |       |   115   (1)| 00:00:02 |       |       |
    |  13 |      PARTITION HASH ALL             |                        |  4120 |       |       |    32   (0)| 00:00:01 |     1 |    16 |
    |* 14 |       INDEX RANGE SCAN              | IDX5_ENUM_TAG          |  4120 |       |       |    32   (0)| 00:00:01 |     1 |    16 |
    --------------------------------------------------------------------------------------------------------------------------------------
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       2 - access("CCB"."BROKER_ID"="CBD"."BROKER_ID")
       6 - access("RTV"."TAG_VALUE"=SYS_OP_C2C("CCB"."PARENT_BROKER_CODE"))
      10 - access("RTL"."TAG_LIST_CODE"=U'FCBrokerCode')
      12 - access("RTL"."TAG_LIST_ID"="RTV"."TAG_LIST_ID")
      14 - access("RTV"."TAG_VALUE_ID"="CET"."TAG_VALUE_ID")
    
    
    40 rows selected.
    
    Elapsed: 00:00:00.76
    SQL> sho parameter cursor
    
    NAME                                 TYPE        VALUE
    ------------------------------------ ----------- ------------------------------
    cursor_sharing                       string      EXACT
    cursor_space_for_time                boolean     FALSE
    open_cursors                         integer     300
    session_cached_cursors               integer     20
    
    
    SQL> SELECT
      *
    FROM
      TABLE(DBMS_XPLAN.DISPLAY_CURSOR(  2    3    4  '11d2u41h3sjmr',0,'ALLSTATS LAST'));
    
    PLAN_TABLE_OUTPUT
    ------------------------------------------------------------------------------------------------------------------------------------------------------
    SQL_ID  11d2u41h3sjmr, child number 0
    -------------------------------------
    SELECT /*+ gather_plan_statistics */   CCB.BROKER_NAME,   CCB.PARENT_BROKER_CODE,
    MAX(CET.LAST_UPDATE_DATE) as LAST_SUBMISSION_DATE,   BROKER_CODE as CHILD_BROKER_CODE,
    CBD.LOCATION FROM   CM_CACHE_BROKER CCB,   REM_TAG_VALUE RTV,   CM_ENUM_TAG CET,
    CM_CACHE_BROKER_detail CBD WHERE   CCB.PARENT_BROKER_CODE = RTV.TAG_VALUE   AND EXISTS
    (SELECT       1     FROM       REM_TAG_LIST RTL     WHERE       RTL.TAG_LIST_ID = RTV.TAG_LIST_ID
          AND RTL.TAG_LIST_CODE = 'FCBrokerCode')   AND RTV.TAG_VALUE_ID = CET.TAG_VALUE_ID   AND
    CCB.BROKER_ID=CBD.BROKER_ID GROUP BY   BROKER_NAME,   PARENT_BROKER_CODE,   BROKER_CODE,
    location
    
    Plan hash value: 1716752470
    
    ----------------------------------------------------------------------------------------------------------
    | Id  | Operation                           | Name                   | E-Rows |  OMem |  1Mem | Used-Mem |
    ----------------------------------------------------------------------------------------------------------
    |   1 |  HASH GROUP BY                      |                        |   7947 |  2456K|   959K|          |
    |*  2 |   HASH JOIN                         |                        |   7947 |  1095K|  1095K|          |
    |   3 |    TABLE ACCESS FULL                | CM_CACHE_BROKER_DETAIL |   6266 |       |       |          |
    |   4 |    TABLE ACCESS BY LOCAL INDEX ROWID| CM_ENUM_TAG            |     41 |       |       |          |
    |   5 |     NESTED LOOPS                    |                        |   4796 |       |       |          |
    |*  6 |      HASH JOIN                      |                        |    117 |   970K|   970K|          |
    |   7 |       TABLE ACCESS FULL             | CM_CACHE_BROKER        |   3781 |       |       |          |
    |   8 |       NESTED LOOPS                  |                        |  74085 |       |       |          |
    |   9 |        TABLE ACCESS BY INDEX ROWID  | REM_TAG_LIST           |      1 |       |       |          |
    |* 10 |         INDEX UNIQUE SCAN           | AK1_REM_TAG_LIST_CODE  |      1 |       |       |          |
    |  11 |        TABLE ACCESS BY INDEX ROWID  | REM_TAG_VALUE          |  74085 |       |       |          |
    |* 12 |         INDEX RANGE SCAN            | REM_TAG_VALUE_IDX1     |  74085 |       |       |          |
    |  13 |      PARTITION HASH ALL             |                        |   4120 |       |       |          |
    |* 14 |       INDEX RANGE SCAN              | IDX5_ENUM_TAG          |   4120 |       |       |          |
    ----------------------------------------------------------------------------------------------------------
    
    Predicate Information (identified by operation id):
    ---------------------------------------------------
    
       2 - access("CCB"."BROKER_ID"="CBD"."BROKER_ID")
       6 - access("RTV"."TAG_VALUE"=SYS_OP_C2C("CCB"."PARENT_BROKER_CODE"))
      10 - access("RTL"."TAG_LIST_CODE"=U'FCBrokerCode')
      12 - access("RTL"."TAG_LIST_ID"="RTV"."TAG_LIST_ID")
      14 - access("RTV"."TAG_VALUE_ID"="CET"."TAG_VALUE_ID")
    
    Note
    -----
       - Warning: basic plan statistics not available. These are only collected when:
           * hint 'gather_plan_statistics' is used for the statement or
           * parameter 'statistics_level' is set to 'ALL', at session or system level
    
    
    47 rows selected.
    I have removed the order by clase and its running from past 15 mins...

    -Yasser
  • 18. Re: SQL taking very long time to execute
    Yasu Newbie
    Currently Being Moderated
    Sorry i mean default collection job in Oracle 10g version.
    SQL> select JOB,WHAT from dba_jobs;
    
           JOB
    ----------
    WHAT
    ------------------------------------------------------------------------------------------------------------------------------------------------------
            22
    EMD_MAINTENANCE.EXECUTE_EM_DBMS_JOB_PROCS();
    Seems like job does not exists...

    -Yasser
  • 19. Re: SQL taking very long time to execute
    user503699 Expert
    Currently Being Moderated
    Yasser,

    All I am trying to say is having correct representative statistics helps optimizer to derive optimal execution plan that (almost always) performs well.
    Now, if the default stats collection job is disabled then it is possible that somebody might have taken that as an informed decision. Not collecting stats for last 6+ months may have some (valid or invalid) reason behind it.
    You may want to speak to whoever is in-charge of these important decisions and understand if at all there is a valid reason for not having up-to-date stats. If it turns out that there is no valid reason and it is just a "mistake", then you should consider collecting fresh stats, at least on tables in your query to begin with. That way you can, at least, make sure that there is one less thing to look for when tuning the query.

    p.s. BTW, do you have any particular reason to store same data in two tables in different charactersets ?

    Edited by: user503699 on Feb 2, 2010 10:29 PM
  • 20. Re: SQL taking very long time to execute
    Yasu Newbie
    Currently Being Moderated
    This database was recently migrated from one server to another using expdp and impdb method, and i am not the primary DBA of this database.

    -Yasser

    Edited by: YasserRACDBA on Feb 3, 2010 12:04 AM
    Wrote non-technical sentences.....hence removing
  • 21. Re: SQL taking very long time to execute
    Tanel Poder Oracle ACE Director
    Currently Being Moderated
    (I didn't read through this thread fully, maybe someone has already said this)

    You don't need to wait for the query to complete to get the V$SQL_PLAN_STATISTICS* views populated. If your query has already ran for too long, you can either hit CTRL+C in your client to cancel the query, or if you can't do that then kill the session via regular ALTER SYSTEM KILL SESSION (not IMMEDIATE). The execution statistics up to that point in time will be put to V$SQL_PLAN_STATISTICS[_ALL] during the cursor cleanup process.

    If your query should be running for 5 minutes, but it already has taken 2 hours, you don't need to wait until it completes (which may be never) - as this 2 hours already is 1:55 minutes too much!

    --
    Tanel Poder
    http://tech.e2sn.com
  • 22. Re: SQL taking very long time to execute
    user503699 Expert
    Currently Being Moderated
    YasserRACDBA wrote:
    This database was recently migrated from one server to another using expdp and impdb method, and i am not the primary DBA of this database.
    Now, that is a totally different problem which I can not help with... :)
    Coming back to your original query performance problem, couple of suggestions:
    1.) When asked about up-to-date statistics, you mentioned that stats were last collected more than 6 months back. Now, WHEN stats were collected may not be an issue since it is possible that the data in tables referenced in your query has mostly remained static (or unchanged). My intention behind asking about statistics was to identify whether figures in EXPLAIN PLAN are close to or far off from actual rows.
    For e.g. your plan shows that CM_ENUM_TAG table is being accessed through local partitioned index IDX5_ENUM_TAG and (estimated) 16 partitions of the index are being scanned to produce approx. 4120 rows for each of (approx.) 117 rows. This may not be a problem but looked bit odd to me.
    So now, how many partitions do you have for table CM_ENUM_TAG table and IDX5_ENUM_TAG index ? And approx. how many records do you have in each partition ?

    2) Don't take me wrong but when you respond to Charles's suggestions, it would help if you can post the details for your original query. After all, you are trying to tune a query having ORDER BY clause and Charles never suggested you to take out ORDER BY clause (it was my suggestion).

    p.s. Also how many rows are there in REM_TAG_VALUE table ? The plan shows that it is expected to access 74085 rows using index. That may not necessarily be bad thing but that depends upon how many rows the table contain.

    Edited by: user503699 on Feb 3, 2010 12:49 AM
  • 23. Re: SQL taking very long time to execute
    Yasu Newbie
    Currently Being Moderated
    Thanks...

    I got some data for sql which ran for almost 2 hours and i think data is not useful..
    SQL> select OPERATION_ID,EXECUTIONS,LAST_OUTPUT_ROWS,OUTPUT_ROWS,ELAPSED_TIME from v$sql_plan_statistics where PLAN_HASH_VALUE=1299486493;
    
    OPERATION_ID EXECUTIONS LAST_OUTPUT_ROWS OUTPUT_ROWS ELAPSED_TIME
    ------------ ---------- ---------------- ----------- ------------
               1          2                0           0           52
               2          2              483         483      4711585
               3          2             6489        6489      1922389
               4          2              302         302      2839408
               5          2              307         307     14342858
               6          2                5           5       135370
               7          2             3902        3902        16205
               8          2                5           5          159
               9          2                1           1           71
              10          2                1           1           31
              11          2                5           5           76
              12          2                5           5           41
              13          2              302         302         8970
              14          2              302         302       217158
    
    14 rows selected.
    -Yasser
  • 24. Re: SQL taking very long time to execute
    Taral Journeyer
    Currently Being Moderated
    When you use group by and order by on same references then it can give you sort group by. You can use USE_HASH_AGGREGATION hint to do hash group by and then it will do sort order by.
  • 25. Re: SQL taking very long time to execute
    Tanel Poder Oracle ACE Director
    Currently Being Moderated
    So, did you actually kill the session BEFORE querying the v$ view?

    V$SQL_PLAN_STATISTICS is updated in these conditions:

    1) the database call finishes
    2) query is cancelled
    3) session is killed (not process with kill -9, but session, with alter system)

    If you actually did kill the session like i mentioned but still the stats weren't updated then I'd look into either v$sql_monitor or plan_line_id column in ASH (if you are on 11g and have the diag pack licenses). Otherwise you can look into my os_explain script which I wrote for identifying in which exec plan line time is spent from OS side:

    http://blog.tanelpoder.com/2008/06/15/advanced-oracle-troubleshooting-guide-part-6-understanding-oracle-execution-plans-with-os_explain/


    --
    Tanel Poder
    http://tech.e2sn.com
  • 26. Re: SQL taking very long time to execute
    sb92075 Guru
    Currently Being Moderated
    does following perform any better?
    Since RTV does not return data to SELECT, it does not belong in outer FROM clause.
    SELECT
      CCB.BROKER_NAME,
      CCB.PARENT_BROKER_CODE,
      MAX(CET.LAST_UPDATE_DATE) as LAST_SUBMISSION_DATE,
      CBD.BROKER_CODE as CHILD_BROKER_CODE,
      CBC.LOCATION
    FROM
      CM_CACHE_BROKER CCB,
      CM_ENUM_TAG CET,
      CM_CACHE_BROKER_detail CBD
    WHERE CCB.BROKER_ID=CBC.BROKER_ID
      AND     CCB.PARENT_BROKER_CODE IN (SELECT RTV.TAG_VALUE
                                 FROM   REM_TAG_VALUE RTV, REM_TAG_LIST RTL
                                 WHERE RTL.TAG_LIST_ID = RTV.TAG_LIST_ID
                                  AND  RTL.TAG_LIST_CODE = 'FCBrokerCode'
                                  AND RTV.TAG_VALUE_ID = CET.TAG_VALUE_ID
                                )
    GROUP BY
      BROKER_NAME,
      PARENT_BROKER_CODE,
      BROKER_CODE,
      location
    order by
      BROKER_NAME;
1 2 Previous Next

Legend

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