1 2 3 Previous Next 40 Replies Latest reply: Mar 8, 2013 4:19 AM by jmft2012 RSS

    How can this bad query be improved?

    jmft2012
      Db:11.2.0.3
      We have a 3rd party app and the web app runs very slow. We want to make the 3rd party to fix the issue. for the
      app login process, I did an AWR , found the problem query it runs 10 mins. Then I did the sqltrace
      here is it:
      select clndr_id , count(*) 
      from
       task where (clndr_id = :"SYS_B_0") group by clndr_id union select clndr_id , 
        count(*) from project where (clndr_id = :"SYS_B_1") group by clndr_id
      
      
      call     count       cpu    elapsed       disk      query    current        rows
      ------- ------  -------- ---------- ---------- ---------- ----------  ----------
      Parse        1      0.01       0.00          0          0          0           0
      Execute      1      0.01       0.00          0          0          0           0
      Fetch        2     53.32     612.03      81650      58920          0           2
      ------- ------  -------- ---------- ---------- ---------- ----------  ----------
      total        4     53.34     612.04      81650      58920          0           2
      
      Misses in library cache during parse: 1
      Optimizer mode: ALL_ROWS
      Parsing user id: 34  (PX)
      Number of plan statistics captured: 1
      
      Rows (1st) Rows (avg) Rows (max)  Row Source Operation
      ---------- ---------- ----------  ---------------------------------------------------
               2          2          2  SORT UNIQUE (cr=58923 pr=81650 pw=22868 time=113329109 us cost=58277 size=24 card=2)
               2          2          2   UNION-ALL  (cr=58923 pr=81650 pw=22868 time=113329001 us)
               1          1          1    SORT GROUP BY NOSORT (cr=58330 pr=81070 pw=22868 time=104312437 us cost=58128 size=7 card=1)
         5589739    5589739    5589739     VIEW  index$_join$_003 (cr=58330 pr=81070 pw=22868 time=619784236 us cost=57240 size=38875249 card=5553607)
         5589739    5589739    5589739      HASH JOIN  (cr=58330 pr=81070 pw=22868 time=617373467 us)
         5590158    5590158    5590158       INDEX RANGE SCAN NDX_TASK_CALENDAR (cr=21676 pr=21676 pw=0 time=113637058 us cost=11057 size=38875249 card=5553607)(object id 24749)
         6673774    6673774    6673774       INDEX FAST FULL SCAN NDX_TASK_PROJ_RSRC (cr=36651 pr=36526 pw=0 time=213370625 us cost=21921 size=38875249 card=5553607)(object id 217274)
               1          1          1    SORT GROUP BY NOSORT (cr=593 pr=580 pw=0 time=9016527 us cost=149 size=17 card=1)
          136390     136390     136390     INDEX FAST FULL SCAN NDX_PROJECT_CALENDAR (cr=593 pr=580 pw=0 time=165434 us cost=132 size=2315876 card=136228)(object id 154409)
      
      
      Rows     Execution Plan
      -------  ---------------------------------------------------
            0  SELECT STATEMENT   MODE: ALL_ROWS
            2   SORT (UNIQUE)
            2    UNION-ALL
            1     SORT (GROUP BY NOSORT)
      5589739      TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 'TASK' 
                       (TABLE)
      5589739       INDEX   MODE: ANALYZED (RANGE SCAN) OF 
                        'NDX_TASK_CALENDAR' (INDEX)
      5590158     SORT (GROUP BY NOSORT)
      6673774      INDEX   MODE: ANALYZED (RANGE SCAN) OF 
                       'NDX_PROJECT_CALENDAR' (INDEX)
      
      
      Elapsed times include waiting on following events:
        Event waited on                             Times   Max. Wait  Total Waited
        ----------------------------------------   Waited  ----------  ------------
        SQL*Net message to client                       2        0.00          0.00
        Disk file operations I/O                        2        0.00          0.00
        db file sequential read                     22235        1.61        138.66
        direct path write                            1620        3.25        177.42
        db file scattered read                       2313        1.89        238.98
        direct path read                              385        1.72         19.52
        SQL*Net message from client                     2        0.11          0.21
      Please make your comments.
      Thanks in Advance.
        • 1. Re: How can this bad query be improved?
          Salman Qureshi
          Hi,
          It looks to me that end result will give you distinct values because of distinct clndr_id. If my thinking is correct, can you use UNION ALL istead of UNION? This will reduce your query execution time by not spending time on removing duplication of results (UNION removes duplication).
          Do you have fresh statistics on the tables/indexes involved in this query?

          Salman
          • 2. Re: How can this bad query be improved?
            Hemant K Chitale
            Are the values of CLNDR_ID uniformly distributed in both tables TASK and PROJECT ?

            What happens if you put a FULL Hint for the TASK query ?
            select /*+ FULL (task) */ clndr_id , count(*) 
            from task 
            where (clndr_id = :"SYS_B_0") 
            group by clndr_id 
            union 
            select  clndr_id ,   count(*) 
            from 
            project 
            where (clndr_id = :"SYS_B_1") 
            group by clndr_id
            It is actually the execution of the HASH JOIN that takes the longest time (617-113-213 == 291) seconds

            Hemant K Chitale

            Hemant K Chitale
            • 3. Re: How can this bad query be improved?
              jmft2012
              Salman Qureshi wrote:
              Hi,
              It looks to me that end result will give you distinct values because of distinct clndr_id. If my thinking is correct, can you use UNION ALL istead of UNION? This will reduce your query execution time by not spending time on removing duplication of results (UNION removes duplication).
              Do you have fresh statistics on the tables/indexes involved in this query?

              Salman
              It is a 3rd party app, not sure the query is exactly doing for, a good input though,
              I have given a try as comparison.
              Found
              $$$$$$$$$$$$$$$$$$$$$$$$$$$$$
              UNION
              select clndr_id , count(*) 
              from
               task where (clndr_id = :"SYS_B_0") group by clndr_id union select clndr_id , 
                count(*) from project where (clndr_id = :"SYS_B_1") group by clndr_id
              
              
              call     count       cpu    elapsed       disk      query    current        rows
              ------- ------  -------- ---------- ---------- ---------- ----------  ----------
              Parse        1      0.00       0.00          0          0          0           0
              Execute      1      0.00       0.00          0          0          0           0
              Fetch        2     31.18      70.39      25288      58920          0           2
              ------- ------  -------- ---------- ---------- ---------- ----------  ----------
              total        4     31.18      70.39      25288      58920          0           2
              
              Misses in library cache during parse: 0
              Optimizer mode: ALL_ROWS
              Parsing user id: 34  (PX)
              Number of plan statistics captured: 1
              
              Rows (1st) Rows (avg) Rows (max)  Row Source Operation
              ---------- ---------- ----------  ---------------------------------------------------
                       2          2          2  SORT UNIQUE (cr=58923 pr=25288 pw=25284 time=70390927 us cost=58277 size=24 card=2)
                       2          2          2   UNION-ALL  (cr=58923 pr=25288 pw=25284 time=70390652 us)
                       1          1          1    SORT GROUP BY NOSORT (cr=58330 pr=25288 pw=25284 time=70309151 us cost=58128 size=7 card=1)
                 5589739    5589739    5589739     VIEW  index$_join$_003 (cr=58330 pr=25288 pw=25284 time=70027453 us cost=57240 size=38875249 card=5553607)
                 5589739    5589739    5589739      HASH JOIN  (cr=58330 pr=25288 pw=25284 time=68083254 us)
                 5590158    5590158    5590158       INDEX RANGE SCAN NDX_TASK_CALENDAR (cr=21676 pr=0 pw=0 time=2449897 us cost=11057 size=38875249 card=5553607)(object id 24749)
                 6673774    6673774    6673774       INDEX FAST FULL SCAN NDX_TASK_PROJ_RSRC (cr=36651 pr=0 pw=0 time=3097204 us cost=21921 size=38875249 card=5553607)(object id 217274)
                       1          1          1    SORT GROUP BY NOSORT (cr=593 pr=0 pw=0 time=81462 us cost=149 size=17 card=1)
                  136390     136390     136390     INDEX FAST FULL SCAN NDX_PROJECT_CALENDAR (cr=593 pr=0 pw=0 time=68732 us cost=132 size=2315876 card=136228)(object id 154409)
              
              
              Rows     Execution Plan
              -------  ---------------------------------------------------
                    0  SELECT STATEMENT   MODE: ALL_ROWS
                    2   SORT (UNIQUE)
                    2    UNION-ALL
                    1     SORT (GROUP BY NOSORT)
              5589739      TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 'TASK' 
                               (TABLE)
              5589739       INDEX   MODE: ANALYZED (RANGE SCAN) OF 
                                'NDX_TASK_CALENDAR' (INDEX)
              5590158     SORT (GROUP BY NOSORT)
              6673774      INDEX   MODE: ANALYZED (RANGE SCAN) OF 
                               'NDX_PROJECT_CALENDAR' (INDEX)
              
              
              Elapsed times include waiting on following events:
                Event waited on                             Times   Max. Wait  Total Waited
                ----------------------------------------   Waited  ----------  ------------
                SQL*Net message to client                       2        0.00          0.00
                direct path write                            3347        1.59         43.26
                direct path read                              130        0.20          0.32
                SQL*Net message from client                     2        0.23          0.27
              ********************************************************************************
              $$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$

              UNION ALL
              SQL ID: d6z3ag876m67h Plan Hash: 4277397671
              
              select clndr_id , count(*) 
              from
               task where (clndr_id = :"SYS_B_0") group by clndr_id union all select 
                clndr_id , count(*) from project where (clndr_id = :"SYS_B_1") group by 
                clndr_id
              
              
              call     count       cpu    elapsed       disk      query    current        rows
              ------- ------  -------- ---------- ---------- ---------- ----------  ----------
              Parse        1      0.00       0.00          0          0          0           0
              Execute      1      0.01       0.00          0          0          0           0
              Fetch        2     31.77      89.93      22886      58920          0           2
              ------- ------  -------- ---------- ---------- ---------- ----------  ----------
              total        4     31.78      89.94      22886      58920          0           2
              
              Misses in library cache during parse: 1
              Optimizer mode: ALL_ROWS
              Parsing user id: 34  (PX)
              Number of plan statistics captured: 1
              
              Rows (1st) Rows (avg) Rows (max)  Row Source Operation
              ---------- ---------- ----------  ---------------------------------------------------
                       2          2          2  UNION-ALL  (cr=58932 pr=22887 pw=22868 time=89865448 us)
                       1          1          1   SORT GROUP BY NOSORT (cr=58339 pr=22887 pw=22868 time=89865428 us cost=57240 size=7 card=1)
                 5589739    5589739    5589739    VIEW  index$_join$_003 (cr=58339 pr=22887 pw=22868 time=302390812 us cost=57240 size=38875249 card=5553607)
                 5589739    5589739    5589739     HASH JOIN  (cr=58339 pr=22887 pw=22868 time=300505731 us)
                 5590158    5590158    5590158      INDEX RANGE SCAN NDX_TASK_CALENDAR (cr=21676 pr=0 pw=0 time=2275780 us cost=11057 size=38875249 card=5553607)(object id 24749)
                 6673774    6673774    6673774      INDEX FAST FULL SCAN NDX_TASK_PROJ_RSRC (cr=36651 pr=18 pw=0 time=3233656 us cost=21921 size=38875249 card=5553607)(object id 217274)
                       1          1          1   SORT GROUP BY NOSORT (cr=593 pr=0 pw=0 time=77989 us cost=132 size=17 card=1)
                  136390     136390     136390    INDEX FAST FULL SCAN NDX_PROJECT_CALENDAR (cr=593 pr=0 pw=0 time=55006 us cost=132 size=2315876 card=136228)(object id 154409)
              
              
              Rows     Execution Plan
              -------  ---------------------------------------------------
                    0  SELECT STATEMENT   MODE: ALL_ROWS
                    2   UNION-ALL
                    1    SORT (GROUP BY NOSORT)
              5589739     TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 'TASK' 
                              (TABLE)
              5589739      INDEX   MODE: ANALYZED (RANGE SCAN) OF 'NDX_TASK_CALENDAR' 
                               (INDEX)
              5590158    SORT (GROUP BY NOSORT)
              6673774     INDEX   MODE: ANALYZED (RANGE SCAN) OF 
                              'NDX_PROJECT_CALENDAR' (INDEX)
              
              
              Elapsed times include waiting on following events:
                Event waited on                             Times   Max. Wait  Total Waited
                ----------------------------------------   Waited  ----------  ------------
                SQL*Net message to client                       2        0.00          0.00
                Disk file operations I/O                        2        0.00          0.00
                direct path write                            2069        3.12         58.90
                db file sequential read                        18        0.78          4.35
                direct path read                               22        0.12          0.15
                SQL*Net message from client                     2        0.46          0.71
              ********************************************************************************
              found union all used 90s vs union 70s, and the logic and the physical reads are about the same.

              Notice that we now have it ran less that 2 mins for the query vs 10 mins before.
              The before was at the peak hrs and now it is off the peak. the disk read from peak's 81650 reduced to 22886.
              that was the cause of slow -- I/O contentions at peak hrs.

              How can we improve the query performance by increasing disk throughput?
              SQL> show parameter mem
              
              NAME                                 TYPE        VALUE
              ------------------------------------ ----------- ------------------------------
              hi_shared_memory_address             integer     0
              memory_max_target                    big integer 4000M
              memory_target                        big integer 3600M
              shared_memory_address                integer     0
              
              SQL> show parameter db_b
              
              NAME                                 TYPE        VALUE
              ------------------------------------ ----------- ------------------------------
              db_block_buffers                     integer     0
              db_block_checking                    string      FALSE
              db_block_checksum                    string      TYPICAL
              db_block_size                        integer     8192
              SQL>  
              • 4. Re: How can this bad query be improved?
                Hemant K Chitale
                'db file sequential read' and 'db file scattered read' waits are gone now --- as if the blocks are now in the buffer cache and need not be read from disk.


                Hemant K Chitale
                • 5. Re: How can this bad query be improved?
                  jmft2012
                  Hemant K Chitale wrote:
                  'db file sequential read' and 'db file scattered read' waits are gone now --- as if the blocks are now in the buffer cache and need not be read from disk.


                  Hemant K Chitale
                  understood that, the db has not been restarted over weeks. got the cache issue, correct?
                  • 6. Re: How can this bad query be improved?
                    Hemant K Chitale
                    the cache issue
                    I would call it "the cache effect". Caching can "solve" an issue ; caching can "hide" an issue (i.e. too many logical I/Os). In your case it "solved" the physical I/O issue -- I notice that the average read time for 'db file scattered read" was high.


                    Hemant K Chitale
                    • 7. Re: How can this bad query be improved?
                      jmft2012
                      Hemant K Chitale wrote:
                      the cache issue
                      I would call it "the cache effect". Caching can "solve" an issue ; caching can "hide" an issue (i.e. too many logical I/Os). In your case it "solved" the physical I/O issue -- I notice that the average read time for 'db file scattered read" was high.


                      Hemant K Chitale
                      it solved now. and it will be back at peak hours. how can it be resolved. this was what i tried to ask for input.
                      • 8. Re: How can this bad query be improved?
                        Hemant K Chitale
                        If we assume that the blocks for these two tables aren't normally present during the peak period, you could "pre-load" the cache by running the query just before the peak period.

                        I have suggested a FULL hint on the first table. You could try that as well.


                        Hemant K Chitale
                        • 9. Re: How can this bad query be improved?
                          jmft2012
                          Hemant K Chitale wrote:
                          If we assume that the blocks for these two tables aren't normally present during the peak period, you could "pre-load" the cache by running the query just before the peak period.

                          I have suggested a FULL hint on the first table. You could try that as well.


                          Hemant K Chitale
                          will try the both.
                          • 10. Re: How can this bad query be improved?
                            Jonathan Lewis
                            IDM99 wrote:
                            5589739    5589739    5589739     VIEW  index$_join$_003 (cr=58330 pr=81070 pw=22868 time=619784236 us cost=57240 size=38875249 card=5553607)
                            5589739    5589739    5589739      HASH JOIN  (cr=58330 pr=81070 pw=22868 time=617373467 us)
                            5590158    5590158    5590158       INDEX RANGE SCAN NDX_TASK_CALENDAR (cr=21676 pr=21676 pw=0 time=113637058 us cost=11057 size=38875249 card=5553607)(object id 24749)
                            6673774    6673774    6673774       INDEX FAST FULL SCAN NDX_TASK_PROJ_RSRC (cr=36651 pr=36526 pw=0 time=213370625 us cost=21921 size=38875249 card=5553607)(object id 217274)
                            The strange thing here is that the optimizer does an index hash join for the first part of the UNION ALL, it doesn't seem to be necessary (guessing from the column names and index names). Indeed, the "Execution Plan" generated by tkprof suggests that the index range scan on NDX_TASK_CALENDAR should be sufficient.

                            Can you re-run the query with the appropriate environment and pull the plan from memory (dbms_xplan.display_cursor - http://jonathanlewis.wordpress.com/2006/11/09/dbms_xplan-in-10g/ ) so that we can see what predicate appear and how they have been used.

                            One thought that crosses my mind is that there is a security predicate (fgac / rls) applied to the table; another is that the TASKS table is actually a view which does little more restrict the rows and columns exposed.

                            Regards
                            Jonathan Lewis
                            • 11. Re: How can this bad query be improved?
                              jmft2012
                              here you go .. thanks
                              18:29:44 SQL> select clndr_id , count(*) from task where (clndr_id = 597) group by clndr_id 
                                   union select clndr_id , count(*) from project where (clndr_id = 597) group by clndr_id 
                              18:29:46   2  /
                              
                                CLNDR_ID   COUNT(*)
                              ---------- ----------
                                     597     136390
                                     597    5589739
                              
                              18:41:44 SQL> 
                              18:41:44 SQL> select * from table(dbms_xplan.display_cursor(null,null,'ALLSTATS LAST'));    
                              
                              PLAN_TABLE_OUTPUT
                              --------------------------------------------------------------------------------
                              SQL_ID  bv3d7gnr100vm, child number 0
                              -------------------------------------
                              select clndr_id , count(*) from task where (clndr_id = :"SYS_B_0")
                              group by clndr_id union select clndr_id , count(*) from project where
                              (clndr_id = :"SYS_B_1") group by clndr_id
                              
                              Plan hash value: 3115928431
                              
                              --------------------------------------------------------------------------------------------------------
                              
                              
                              PLAN_TABLE_OUTPUT
                              --------------------------------------------------------------------------------
                              | Id  | Operation                 | Name                 | E-Rows |  OMem |  1Mem | Used-Mem | Used-Tmp|
                              
                              --------------------------------------------------------------------------------------------------------
                              
                              |   0 | SELECT STATEMENT          |                      |        |       |       |          |         |
                              
                              |   1 |  SORT UNIQUE              |                      |      2 |  2048 |  2048 | 2048  (0)|         |
                              
                              PLAN_TABLE_OUTPUT
                              --------------------------------------------------------------------------------
                              
                              |   2 |   UNION-ALL               |                      |        |       |       |          |         |
                              
                              |   3 |    SORT GROUP BY NOSORT   |                      |      1 |       |       |          |         |
                              
                              |*  4 |     VIEW                  | index$_join$_003     |   5553K|       |       |          |         |
                              
                              |*  5 |      HASH JOIN            |                      |        |   207M|    11M|  176M (1)|     181K|
                              
                              |*  6 |       INDEX RANGE SCAN    | NDX_TASK_CALENDAR    |   5553K|       |       |          |         |
                              
                              |*  7 |       INDEX FAST FULL SCAN| NDX_TASK_PROJ_RSRC   |   5553K|       |       |          |         |
                              
                              |   8 |    SORT GROUP BY NOSORT   |                      |      1 |       |                  |         |
                              
                              |*  9 |     INDEX FAST FULL SCAN  | NDX_PROJECT_CALENDAR |    136K|       |       |          |         |
                              
                              --------------------------------------------------------------------------------------------------------
                              
                              
                              Predicate Information (identified by operation id):
                              ---------------------------------------------------
                              
                                 4 - filter("CLNDR_ID"=:SYS_B_0)
                              
                              PLAN_TABLE_OUTPUT
                              --------------------------------------------------------------------------------
                                 5 - access(ROWID=ROWID)
                                 6 - access("CLNDR_ID"=:SYS_B_0)
                                 7 - filter("DELETE_SESSION_ID" IS NULL)
                                 9 - filter(("CLNDR_ID"=:SYS_B_1 AND "DELETE_SESSION_ID" IS NULL))
                              
                              Note
                              -----
                                 - Warning: basic plan statistics not available. These are only collected when:
                              
                                     * hint 'gather_plan_statistics' is used for the statement or
                              
                              PLAN_TABLE_OUTPUT
                              --------------------------------------------------------------------------------
                                     * parameter 'statistics_level' is set to 'ALL', at session or system level
                              
                              
                              
                              38 rows selected.
                              
                              18:41:45 SQL> 
                              • 12. Re: How can this bad query be improved?
                                Jonathan Lewis
                                IDM99 wrote:
                                18:29:44 SQL> select clndr_id , count(*) from task where (clndr_id = 597) group by clndr_id 
                                     union select clndr_id , count(*) from project where (clndr_id = 597) group by clndr_id 
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------
                                5 - access(ROWID=ROWID)
                                6 - access("CLNDR_ID"=:SYS_B_0)
                                7 - filter("DELETE_SESSION_ID" IS NULL)
                                9 - filter(("CLNDR_ID"=:SYS_B_1 AND "DELETE_SESSION_ID" IS NULL))
                                Note the "magical" appearance of the predicate "delete_session_id is null".

                                Either your tables are really view of the form "select * from delete_session_id is null", or there's a security predicate on the two tables which introduces that predicate (you could use event 10730 to dump any security predicates to the session's trace file).

                                The index on the second table presumably includes this column, the index on the tasks table doesn't - so the optmizer has chosen an index join over a tablescan. You need to consider adding the column to the index.

                                Regards
                                Jonathan Lewis
                                • 13. Re: How can this bad query be improved?
                                  jmft2012
                                  Note the "magical" appearance of the predicate "delete_session_id is null".

                                  Either your tables are really view of the form "select * from delete_session_id is null", or there's a security predicate on the two tables which introduces that predicate (you could use event 10730 to dump any security predicates to the session's trace file).

                                  The index on the second table presumably includes this column, the index on the tasks table doesn't - so the optmizer has chosen an index join over a tablescan. You need to consider adding the column to the index.
                                  there is the index for 2nd table porject:
                                  NDX_PROJECT_DSI (DELETE_SESSION_ID , DELETE_DATE )

                                  I did trace event 10730:

                                  ALTER SESSION SET EVENTS '10730 trace name context forever, level 12';
                                  then the query:
                                  select clndr_id , count(*) from task where (clndr_id = 597) group by clndr_id union select clndr_id , count(*) from project where (clndr_id = 597) group by clndr_id
                                  /

                                  But I do not see the trace file created in the dum loc.
                                  What I have might missed?
                                  • 14. Re: How can this bad query be improved?
                                    jmft2012
                                    why the trace event not work? thanks.
                                    1 2 3 Previous Next