1 2 Previous Next 26 Replies Latest reply: Feb 8, 2010 12:23 PM by sb92075 Go to original post RSS
      • 15. Re: SQL taking very long time to execute
        Charles Hooper
        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
          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
            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
              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
                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
                  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
                    (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
                      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
                        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
                          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
                            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
                              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