Forum Stats

  • 3,826,842 Users
  • 2,260,712 Discussions
  • 7,897,092 Comments

Discussions

Categories

How can this bad query be improved?

jmft2012
jmft2012 Member Posts: 371 Blue Ribbon
edited Mar 8, 2013 5:19AM in General Database Discussions
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.
· Share on TwitterShare on Facebook

Best Answer

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,975 Blue Diamond
    Answer ✓
    jmft2012 wrote:
    the two tables' indexes.
    I commented out the table_owner (same owner for both tables) and truncated those Quest indexing full names for the confidentiality of the work site.
    noticed that there are numbers of duplicated indexes on the tables, how Oracle let this happened?
    ****    TASK            NDX_TASK_CALENDAR                CLNDR_ID

****    TASK            NDX_TASK_CODE                    PROJ_ID
****    TASK            NDX_TASK_CODE                    TASK_CODE
    I should have given you BREAK command as well.
    The indexes aren't duplicated, but there are multi-column indexes.

    Notice how several indexes on the TASK table end with DELETE_SESSION_ID - you need to add that column to the NDX_TASK_CALENDAR index as well if you want to avoid the massive hash join - otherwise the only alternatives have to access the table to satisfy the query.

    Your backout plan for implementing in production would be to add the longer index as an invisible one to check for side effects before switching it to visible and switching the short index to invisible for a few days before dropping it.

    Regards
    Jonathan Lewis
    · Share on TwitterShare on Facebook
«134

Answers

  • Salman Qureshi
    Salman Qureshi Member Posts: 2,483
    edited Feb 26, 2013 8:42PM
    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
    · Share on TwitterShare on Facebook
  • Hemant K Chitale
    Hemant K Chitale Member Posts: 15,759 Blue Diamond
    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
    · Share on TwitterShare on Facebook
  • jmft2012
    jmft2012 Member Posts: 371 Blue Ribbon
    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>
    · Share on TwitterShare on Facebook
  • Hemant K Chitale
    Hemant K Chitale Member Posts: 15,759 Blue Diamond
    '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
    · Share on TwitterShare on Facebook
  • jmft2012
    jmft2012 Member Posts: 371 Blue Ribbon
    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?
    · Share on TwitterShare on Facebook
  • Hemant K Chitale
    Hemant K Chitale Member Posts: 15,759 Blue Diamond
    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
    · Share on TwitterShare on Facebook
  • jmft2012
    jmft2012 Member Posts: 371 Blue Ribbon
    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.
    · Share on TwitterShare on Facebook
  • Hemant K Chitale
    Hemant K Chitale Member Posts: 15,759 Blue Diamond
    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
    · Share on TwitterShare on Facebook
  • jmft2012
    jmft2012 Member Posts: 371 Blue Ribbon
    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.
    · Share on TwitterShare on Facebook
  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,975 Blue Diamond
    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
    · Share on TwitterShare on Facebook
This discussion has been closed.