1 2 Previous Next 18 Replies Latest reply: Dec 18, 2012 10:35 PM by KODS Go to original post RSS
      • 15. Re: Plan shows SQL execution time Hrs 999:59:59 Sec.
        Martin Preiss
        Hi Nikolay,

        I absolutely agree: with view merging or predicate pushing the NL would be a sensible operation (and better than a HJ) - but if it is not possible then the NL is deadly and I could imagine the CBO only uses it in the absence of other allowed operations. So my comment was not meant as a solution for the problem - it should add only some additional data.

        Regards

        Martin
        • 16. Re: Plan shows SQL execution time Hrs 999:59:59 Sec.
          KODS
          Dear All,

          Thank you for your valuble suggesitions. As you all said the statistics are stale when I verified in DB. After collecting the stats the query plan is showing approximately 33Hrs.

          As suggested by you, I granted the MERGE VIEW privilige to SIBEL user and executed from SIEBEL session. Kindly have a look in the plan and guide me is there any posibility of further tuning this query.
          siebel@CRMSPH1> siebel@CRMSPH1> select * from table(dbms_xplan.display);
          
          PLAN_TABLE_OUTPUT
          ------------------------------------------------------------------------------------------------------------------------------------------------------
          Plan hash value: 3425281120
          
          --------------------------------------------------------------------------------------------------------------------------------
          | Id  | Operation                                                  | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
          --------------------------------------------------------------------------------------------------------------------------------
          |   0 | SELECT STATEMENT                                           |                   |  3130K|    12G|    75M  (1)| 33:45:22 |
          |   1 |  NESTED LOOPS OUTER                                        |                   |  3130K|    12G|    75M  (1)| 33:45:22 |
          |   2 |   NESTED LOOPS OUTER                                       |                   |  3130K|    12G|    69M  (1)| 31:01:04 |
          |   3 |    NESTED LOOPS OUTER                                      |                   |  3130K|    12G|    63M  (1)| 28:16:36 |
          |   4 |     NESTED LOOPS OUTER                                     |                   |  3130K|    12G|    60M  (1)| 27:08:59 |
          |   5 |      NESTED LOOPS OUTER                                    |                   |  3130K|    12G|    58M  (1)| 26:01:22 |
          |   6 |       NESTED LOOPS                                         |                   |  3130K|    12G|    50M  (1)| 22:39:06 |
          |   7 |        NESTED LOOPS OUTER                                  |                   |  3130K|    12G|    43M  (1)| 19:16:50 |
          |   8 |         NESTED LOOPS OUTER                                 |                   |  3130K|    12G|    37M  (1)| 16:32:32 |
          |   9 |          NESTED LOOPS OUTER                                |                   |  3130K|    12G|    30M  (1)| 13:48:03 |
          |  10 |           NESTED LOOPS OUTER                               |                   |  3130K|    12G|    24M  (1)| 11:03:33 |
          |  11 |            NESTED LOOPS OUTER                              |                   |  3130K|    12G|    24M  (1)| 11:03:33 |
          |  12 |             NESTED LOOPS OUTER                             |                   |  3130K|    12G|    24M  (1)| 11:03:28 |
          |  13 |              NESTED LOOPS OUTER                            |                   |  3130K|    11G|    19M  (1)| 08:48:32 |
          |  14 |               NESTED LOOPS OUTER                           |                   |  3130K|    11G|    12M  (2)| 05:26:23 |
          |  15 |                NESTED LOOPS OUTER                          |                   |  3130K|    11G|  9721K  (2)| 04:20:13 |
          |  16 |                 NESTED LOOPS OUTER                         |                   |  3130K|    11G|  9721K  (2)| 04:20:13 |
          |  17 |                  NESTED LOOPS OUTER                        |                   |  3130K|    11G|  9718K  (2)| 04:20:09 |
          |  18 |                   NESTED LOOPS OUTER                       |                   |  3130K|    11G|  9718K  (2)| 04:20:09 |
          |  19 |                    NESTED LOOPS OUTER                      |                   |  3130K|    11G|  9718K  (2)| 04:20:09 |
          |  20 |                     NESTED LOOPS OUTER                     |                   |  3130K|    10G|  9718K  (2)| 04:20:09 |
          |  21 |                      NESTED LOOPS OUTER                    |                   |  3130K|    10G|  9716K  (2)| 04:20:06 |
          |  22 |                       NESTED LOOPS                         |                   |  3130K|  9633M|  9715K  (2)| 04:20:03 |
          |  23 |                        NESTED LOOPS OUTER                  |                   |  3130K|  7203M|  4673K  (2)| 02:05:07 |
          |  24 |                         NESTED LOOPS OUTER                 |                   |  3130K|  7027M|  2148K  (3)| 00:57:30 |
          |  25 |                          NESTED LOOPS OUTER                |                   |  3130K|  6928M|  2148K  (3)| 00:57:30 |
          |  26 |                           NESTED LOOPS OUTER               |                   |  3130K|  6794M|  1321K  (4)| 00:35:23 |
          |  27 |                            NESTED LOOPS OUTER              |                   |  3130K|  6024M|  1320K  (4)| 00:35:21 |
          |  28 |                             NESTED LOOPS OUTER             |                   |  3130K|  5624M|  1320K  (4)| 00:35:21 |
          |  29 |                              NESTED LOOPS OUTER            |                   |  3130K|  5224M|  1320K  (4)| 00:35:21 |
          |  30 |                               VIEW                         | V_ORDER_ITEM      |  3130K|  4824M|  1320K  (4)| 00:35:21 |
          |  31 |                                NESTED LOOPS                |                   |  3130K|  1370M|  1320K  (4)| 00:35:21 |
          |  32 |                                 INDEX FAST FULL SCAN       | S_ETL_I_IMG_25_M2 |  3130K|    32M|  2767  (11)| 00:00:05 |
          |* 33 |                                 TABLE ACCESS BY INDEX ROWID| S_ORDER_ITEM      |     1 |   448 |     2   (0)| 00:00:01 |
          |* 34 |                                  INDEX UNIQUE SCAN         | S_ORDER_ITEM_P1   |     1 |       |     2   (0)| 00:00:01 |
          |  35 |                               TABLE ACCESS BY INDEX ROWID  | S_VDISCNT_ITEM    |     1 |   134 |     1   (0)| 00:00:01 |
          |* 36 |                                INDEX UNIQUE SCAN           | S_VDISCNT_ITEM_P1 |     1 |       |     1   (0)| 00:00:01 |
          |  37 |                              TABLE ACCESS BY INDEX ROWID   | S_VOL_DISCNT      |     1 |   134 |     1   (0)| 00:00:01 |
          |* 38 |                               INDEX UNIQUE SCAN            | S_VOL_DISCNT_P1   |     1 |       |     1   (0)| 00:00:01 |
          |  39 |                             TABLE ACCESS BY INDEX ROWID    | S_VDISCNT_ITEM    |     1 |   134 |     1   (0)| 00:00:01 |
          |* 40 |                              INDEX UNIQUE SCAN             | S_VDISCNT_ITEM_P1 |     1 |       |     1   (0)| 00:00:01 |
          |  41 |                            TABLE ACCESS BY INDEX ROWID     | S_ADDR_ORG        |     1 |   258 |     1   (0)| 00:00:01 |
          |* 42 |                             INDEX UNIQUE SCAN              | S_ADDR_ORG_P1     |     1 |       |     1   (0)| 00:00:01 |
          |* 43 |                           TABLE ACCESS FULL                | S_ORDER_ITM_PRI   |     1 |    45 |     0   (0)| 00:00:01 |
          |  44 |                          TABLE ACCESS BY INDEX ROWID       | S_INVLOC          |     1 |    33 |     1   (0)| 00:00:01 |
          |* 45 |                           INDEX UNIQUE SCAN                | S_INVLOC_P1       |     1 |       |     1   (0)| 00:00:01 |
          |  46 |                         TABLE ACCESS BY INDEX ROWID        | S_PROD_INT        |     1 |    59 |     1   (0)| 00:00:01 |
          |* 47 |                          INDEX UNIQUE SCAN                 | S_PROD_INT_P1     |     1 |       |     1   (0)| 00:00:01 |
          |  48 |                        TABLE ACCESS BY INDEX ROWID         | S_ORDER           |     1 |   814 |     2   (0)| 00:00:01 |
          |* 49 |                         INDEX UNIQUE SCAN                  | S_ORDER_P1        |     1 |       |     1   (0)| 00:00:01 |
          |  50 |                       TABLE ACCESS BY INDEX ROWID          | S_ADDR_ORG        |     1 |   258 |     1   (0)| 00:00:01 |
          |* 51 |                        INDEX UNIQUE SCAN                   | S_ADDR_ORG_P1     |     1 |       |     1   (0)| 00:00:01 |
          |  52 |                      TABLE ACCESS BY INDEX ROWID           | S_ADDR_ORG        |     1 |   258 |     1   (0)| 00:00:01 |
          |* 53 |                       INDEX UNIQUE SCAN                    | S_ADDR_ORG_P1     |     1 |       |     1   (0)| 00:00:01 |
          |  54 |                     TABLE ACCESS BY INDEX ROWID            | S_CAMP_CON        |     1 |    96 |     1   (0)| 00:00:01 |
          |* 55 |                      INDEX UNIQUE SCAN                     | S_CAMP_CON_P1     |     1 |       |     1   (0)| 00:00:01 |
          |  56 |                    TABLE ACCESS BY INDEX ROWID             | S_ENTLMNT         |     1 |    64 |     1   (0)| 00:00:01 |
          |* 57 |                     INDEX UNIQUE SCAN                      | S_ENTLMNT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  58 |                   TABLE ACCESS BY INDEX ROWID              | S_SRC             |     1 |    82 |     1   (0)| 00:00:01 |
          |* 59 |                    INDEX UNIQUE SCAN                       | S_SRC_P1          |     1 |       |     1   (0)| 00:00:01 |
          |  60 |                  TABLE ACCESS BY INDEX ROWID               | S_CAMP_LD_WAVE    |     1 |    41 |     1   (0)| 00:00:01 |
          |* 61 |                   INDEX UNIQUE SCAN                        | S_CAMP_LD_WAVE_P1 |     1 |       |     1   (0)| 00:00:01 |
          |  62 |                 TABLE ACCESS BY INDEX ROWID                | S_DOC_QUOTE       |     1 |    18 |     1   (0)| 00:00:01 |
          |* 63 |                  INDEX UNIQUE SCAN                         | S_DOC_QUOTE_P1    |     1 |       |     1   (0)| 00:00:01 |
          |  64 |                TABLE ACCESS BY INDEX ROWID                 | S_POSTN           |     1 |    31 |     1   (0)| 00:00:01 |
          |* 65 |                 INDEX UNIQUE SCAN                          | S_POSTN_P1        |     1 |       |     1   (0)| 00:00:01 |
          |  66 |               TABLE ACCESS BY INDEX ROWID                  | S_ORDER_X         |     1 |    36 |     2   (0)| 00:00:01 |
          |* 67 |                INDEX RANGE SCAN                            | S_ORDER_X_U1      |     1 |       |     2   (0)| 00:00:01 |
          |  68 |              TABLE ACCESS BY INDEX ROWID                   | S_CONTACT         |     1 |    14 |     2   (0)| 00:00:01 |
          |* 69 |               INDEX UNIQUE SCAN                            | S_CONTACT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  70 |             TABLE ACCESS BY INDEX ROWID                    | S_POSTN           |     1 |    20 |     1   (0)| 00:00:01 |
          |* 71 |              INDEX UNIQUE SCAN                             | S_POSTN_P1        |     1 |       |     1   (0)| 00:00:01 |
          |  72 |            TABLE ACCESS BY INDEX ROWID                     | S_CONTACT         |     1 |    14 |     1   (0)| 00:00:01 |
          |* 73 |             INDEX UNIQUE SCAN                              | S_CONTACT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  74 |           TABLE ACCESS BY INDEX ROWID                      | S_ORG_EXT         |     1 |    14 |     2   (0)| 00:00:01 |
          |* 75 |            INDEX UNIQUE SCAN                               | S_ORG_EXT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  76 |          TABLE ACCESS BY INDEX ROWID                       | S_ORG_EXT         |     1 |    14 |     2   (0)| 00:00:01 |
          |* 77 |           INDEX UNIQUE SCAN                                | S_ORG_EXT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  78 |         TABLE ACCESS BY INDEX ROWID                        | S_ORG_EXT         |     1 |    17 |     2   (0)| 00:00:01 |
          |* 79 |          INDEX UNIQUE SCAN                                 | S_ORG_EXT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  80 |        TABLE ACCESS BY INDEX ROWID                         | S_ORDER_ITEM      |     1 |    60 |     2   (0)| 00:00:01 |
          |* 81 |         INDEX UNIQUE SCAN                                  | S_ORDER_ITEM_P1   |     1 |       |     2   (0)| 00:00:01 |
          |  82 |       TABLE ACCESS BY INDEX ROWID                          | S_ORDER_ITEM      |     1 |    24 |     2   (0)| 00:00:01 |
          |* 83 |        INDEX UNIQUE SCAN                                   | S_ORDER_ITEM_P1   |     1 |       |     2   (0)| 00:00:01 |
          |  84 |      TABLE ACCESS BY INDEX ROWID                           | S_PROD_INT        |     1 |    16 |     1   (0)| 00:00:01 |
          |* 85 |       INDEX UNIQUE SCAN                                    | S_PROD_INT_P1     |     1 |       |     1   (0)| 00:00:01 |
          |  86 |     TABLE ACCESS BY INDEX ROWID                            | S_PROD_INT        |     1 |    16 |     1   (0)| 00:00:01 |
          |* 87 |      INDEX UNIQUE SCAN                                     | S_PROD_INT_P1     |     1 |       |     1   (0)| 00:00:01 |
          |  88 |    TABLE ACCESS BY INDEX ROWID                             | S_ORG_EXT         |     1 |    14 |     2   (0)| 00:00:01 |
          |* 89 |     INDEX UNIQUE SCAN                                      | S_ORG_EXT_P1      |     1 |       |     1   (0)| 00:00:01 |
          |  90 |   TABLE ACCESS BY INDEX ROWID                              | S_ORG_EXT         |     1 |    17 |     2   (0)| 00:00:01 |
          |* 91 |    INDEX UNIQUE SCAN                                       | S_ORG_EXT_P1      |     1 |       |     1   (0)| 00:00:01 |
          --------------------------------------------------------------------------------------------------------------------------------
          
          Predicate Information (identified by operation id):
          ---------------------------------------------------
          
            33 - filter("S_ORDER_ITEM"."ROOT_ORDER_ITEM_ID" IS NOT NULL)
            34 - access("S_ORDER_ITEM"."ROW_ID"="S_ETL_I_IMG_25"."ROW_ID")
            36 - access("S_ORDER_ITEM"."VOL_DISCNT_ITEM_ID"="A"."ROW_ID"(+))
            38 - access("S_ORDER_ITEM"."VOL_DISCNT_ID"="S_VOL_DISCNT"."ROW_ID"(+))
            40 - access("S_ORDER_ITEM"."VOL_UPSELL_ITEM_ID"="B"."ROW_ID"(+))
            42 - access("S_ORDER_ITEM"."SHIP_ADDR_ID"="SHIPOITEM"."ROW_ID"(+))
            43 - filter("S_ORDER_ITEM"."ROW_ID"="OPRI"."PAR_ROW_ID"(+))
            45 - access("S_ORDER_ITEM"."SRC_INVLOC_ID"="S_INVLOC"."ROW_ID"(+))
            47 - access("S_ORDER_ITEM"."PROD_ID"="S_PROD_INT"."ROW_ID"(+))
            49 - access("S_ORDER_ITEM"."ORDER_ID"="S_ORDER"."ROW_ID")
            51 - access("S_ORDER"."SHIP_ADDR_ID"="SHIPO"."ROW_ID"(+))
            53 - access("S_ORDER"."BL_ADDR_ID"="BILL"."ROW_ID"(+))
            55 - access("S_ORDER"."CAMP_CON_ID"="S_CAMP_CON"."ROW_ID"(+))
            57 - access("S_ORDER"."ENTLMNT_ID"="S_ENTLMNT"."ROW_ID"(+))
            59 - access("S_ORDER"."PROMO_ID"="S_SRC"."ROW_ID"(+))
          
          PLAN_TABLE_OUTPUT
          ------------------------------------------------------------------------------------------------------------------------------------------------------
            61 - access("S_CAMP_CON"."CAMP_LD_WAVE_ID"="S_CAMP_LD_WAVE"."ROW_ID"(+))
            63 - access("S_ORDER"."QUOTE_ID"="QUOTE"."ROW_ID"(+))
            65 - access("S_ORDER"."PR_POSTN_ID"="POSOWNERORG"."ROW_ID"(+))
            67 - access("S_ORDER_ITEM"."ORDER_ID"="S_ORDER_X"."PAR_ROW_ID"(+))
            69 - access("S_ORDER_ITEM"."CREATED_BY"="CRTD"."ROW_ID"(+))
            71 - access("CRTD"."PR_HELD_POSTN_ID"="POSCRTDORG"."ROW_ID"(+))
            73 - access("S_ORDER"."APPR_BY_EMP_ID"="APPRBYPOS"."ROW_ID"(+))
            75 - access("S_ORDER"."ACCNT_ID"="ACCNT"."ROW_ID"(+))
            77 - access("POSOWNERORG"."OU_ID"="OWNORG1"."ROW_ID"(+))
            79 - access("OWNORG1"."PAR_BU_ID"="OWNORG"."ROW_ID"(+))
            81 - access("S_ORDER_ITEM"."ROOT_ORDER_ITEM_ID"="ROOTOITEM"."ROW_ID")
            83 - access("S_ORDER_ITEM"."PAR_ORDER_ITEM_ID"="PAROITEM"."ROW_ID"(+))
            85 - access("PAROITEM"."PROD_ID"="PARPROD"."ROW_ID"(+))
            87 - access("ROOTOITEM"."PROD_ID"="ROOTPROD"."ROW_ID"(+))
            89 - access("S_ORDER"."BU_ID"="VISORG1"."ROW_ID"(+))
            91 - access("VISORG1"."PAR_BU_ID"="VISORG"."ROW_ID"(+))
          
          133 rows selected.
          • 17. Re: Plan shows SQL execution time Hrs 999:59:59 Sec.
            Nikolay Savvinov
            Hi,

            1) the time estimate in the plan table is very inaccurate. Basically it's assuming that every single block would have to be read from cache, which is very unlikely, especially given that the plan is full of nested loops and index range/unique scans. So it's unlikely that the query would actually take 33 hours to run
            2) tuning by explain plan is not very reliable because you'll have to rely on accuracy of optimizer estimates -- it's much better to either use rowsource stats (dbms_xplan.display_cursor) or extended SQL trace (enable via event 10046, or via dbms_monitor). Unfortunately both methods require that the query be completed, so if it runs forever than I guess you don't really have an alternative
            3) the plan you posted now is a big improvement over what you used to see before, and basically it looks like it's as good as you're gonna get with your current design, because the query is basically constructing one row by taking pieces from about 30 outer-joined table. I.e. per each row you have to visit about 30 tables, given that index access typically requires at least 2 block reads (one from index, the other one from the table using the rowid from the index), 75M reads per 3.1M rows doesn't sound bad.

            So the questions you're gonna have to ask yourself are:

            - does the query really return 3.1M rows?
            - if it does, does the user really need all of them? what he's going to do with all those rows (no human is capable of processing this much data within reasonable time, and for automated processing the database is the best place)
            - is it really necessary to split pieces of data that belong together (at least as far as this report is concerned) into so many different tables? any chance you overnormalized your schema?

            If nothing of the above happens, try throwing more resources at your query (i.e. parallelize it) and/or buy better hardware. I don't think you have other options.

            Best regards,
            Nikolay
            • 18. Re: Plan shows SQL execution time Hrs 999:59:59 Sec.
              KODS
              Thanks Nikolay for your comments.
              1 2 Previous Next