Home » RDBMS Server » Performance Tuning » Slow cpu-bound hard parse in one environment, fast in another
icon5.gif  Slow cpu-bound hard parse in one environment, fast in another [message #354343] Fri, 17 October 2008 20:35 Go to next message
pmc123
Messages: 2
Registered: October 2008
Junior Member
Hi,

I have a strange problem and I think it boils down to parameter differences.


We have two environments - similar hardware, where the exact same query behaves completely differently.

Environment #1 - hard parse takes about 500ms.

Environment #2 - hard parse takes 15+ seconds.

Analyzing the query in Environment #2, all of the time is CPU (parsing), almost nothing in Fetch.

There are about 3 different queries this happens for, all are rather large and have about 30 joins. But nothing weird.

The queries themselves all have excellent, efficient execution plans. So there is nothing wrong at all with the queries.

I suspect a difference in oracle parameters, perhaps the "_" parameters. I would do a comparison, but Environment #2 is at a customer site and they are not responding to our request for all the oracle params.

We've even had a top-top-shelf oracle consultant scrutinize things. He is at a loss. He thinks maybe it is an oracle bug.

I've tried paring down the query, removing joins bit by bit and the speed up is linear, no big jumps.


Does anyone know what settings could cause the hard-parse to behave so poorly like we're seeing in Environment #2?

Thanks.
Re: Slow cpu-bound hard parse in one environment, fast in another [message #354345 is a reply to message #354343] Fri, 17 October 2008 22:35 Go to previous messageGo to next message
pmc123
Messages: 2
Registered: October 2008
Junior Member
Here is an example...

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1     14.46      14.12          0          0          0           0
Execute      1     15.62      15.25          0          0          0           0
Fetch        2      0.03       0.02          0        558          0          13
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     30.11      29.40          0        558          0          13

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 66  

Rows     Row Source Operation
-------  ---------------------------------------------------
     13  SORT ORDER BY (cr=558 pr=0 pw=0 time=23427 us)
     13   FILTER  (cr=558 pr=0 pw=0 time=18665 us)
     13    NESTED LOOPS OUTER (cr=558 pr=0 pw=0 time=18645 us)
     13     NESTED LOOPS OUTER (cr=532 pr=0 pw=0 time=18167 us)
     13      NESTED LOOPS OUTER (cr=506 pr=0 pw=0 time=17652 us)
     13       NESTED LOOPS OUTER (cr=480 pr=0 pw=0 time=17139 us)
     13        NESTED LOOPS OUTER (cr=454 pr=0 pw=0 time=16661 us)
     13         NESTED LOOPS OUTER (cr=454 pr=0 pw=0 time=16551 us)
     13          NESTED LOOPS OUTER (cr=454 pr=0 pw=0 time=16429 us)
     13           NESTED LOOPS OUTER (cr=454 pr=0 pw=0 time=16317 us)
     13            NESTED LOOPS OUTER (cr=454 pr=0 pw=0 time=16169 us)
     13             NESTED LOOPS OUTER (cr=415 pr=0 pw=0 time=15554 us)
     13              NESTED LOOPS OUTER (cr=389 pr=0 pw=0 time=15061 us)
     13               NESTED LOOPS OUTER (cr=350 pr=0 pw=0 time=14361 us)
     13                NESTED LOOPS OUTER (cr=311 pr=0 pw=0 time=13742 us)
     13                 NESTED LOOPS OUTER (cr=272 pr=0 pw=0 time=13110 us)
     13                  NESTED LOOPS OUTER (cr=233 pr=0 pw=0 time=12478 us)
     13                   NESTED LOOPS OUTER (cr=194 pr=0 pw=0 time=11856 us)
     13                    NESTED LOOPS OUTER (cr=170 pr=0 pw=0 time=11661 us)
     13                     NESTED LOOPS OUTER (cr=146 pr=0 pw=0 time=11474 us)
     13                      NESTED LOOPS OUTER (cr=146 pr=0 pw=0 time=11325 us)
     13                       NESTED LOOPS OUTER (cr=107 pr=0 pw=0 time=10754 us)
     13                        NESTED LOOPS OUTER (cr=107 pr=0 pw=0 time=10655 us)
     13                         NESTED LOOPS OUTER (cr=107 pr=0 pw=0 time=10521 us)
     13                          NESTED LOOPS OUTER (cr=81 pr=0 pw=0 time=10040 us)
     13                           NESTED LOOPS OUTER (cr=81 pr=0 pw=0 time=9917 us)
     13                            NESTED LOOPS OUTER (cr=81 pr=0 pw=0 time=9795 us)
     13                             NESTED LOOPS OUTER (cr=81 pr=0 pw=0 time=9658 us)
     13                              NESTED LOOPS OUTER (cr=55 pr=0 pw=0 time=9176 us)
     13                               TABLE ACCESS BY INDEX ROWID XXXX_ORDER (cr=29 pr=0 pw=0 time=8598 us)
    308                                INDEX RANGE SCAN FK__ORDER5 (cr=1 pr=0 pw=0 time=683 us)(object id 64707)
     13                               TABLE ACCESS BY INDEX ROWID XXXX_ZZZZZ_TYPE (cr=26 pr=0 pw=0 time=472 us)
     13                                INDEX UNIQUE SCAN PK_XXXX_ZZZZZ_TYPE (cr=13 pr=0 pw=0 time=293 us)(object id 64505)
     13                              TABLE ACCESS BY INDEX ROWID XXXX_CALCULATION_METHOD (cr=26 pr=0 pw=0 time=428 us)
     13                               INDEX UNIQUE SCAN PK_XXXX_CALCULATION_METHOD (cr=13 pr=0 pw=0 time=257 us)(object id 64431)
      0                             TABLE ACCESS BY INDEX ROWID XXXX_CAPACITY (cr=0 pr=0 pw=0 time=89 us)
      0                              INDEX UNIQUE SCAN PK_XXXX_CAPACITY (cr=0 pr=0 pw=0 time=38 us)(object id 64417)
      0                            TABLE ACCESS BY INDEX ROWID XXXX_YYYY_ASSIGNMENT_RULE (cr=0 pr=0 pw=0 time=77 us)
      0                             INDEX UNIQUE SCAN PK_XXXX_YYYY_ASSIGNMENT_RULE (cr=0 pr=0 pw=0 time=32 us)(object id 64445)
      0                           TABLE ACCESS BY INDEX ROWID XXXX_CAPACITY (cr=0 pr=0 pw=0 time=73 us)
      0                            INDEX UNIQUE SCAN PK_XXXX_CAPACITY (cr=0 pr=0 pw=0 time=32 us)(object id 64417)
     13                          TABLE ACCESS BY INDEX ROWID XXXX_ZZZZZ_SOURCE (cr=26 pr=0 pw=0 time=430 us)
     13                           INDEX UNIQUE SCAN PK_XXXX_ZZZZZ_SOURCE (cr=13 pr=0 pw=0 time=264 us)(object id 64503)
      0                         TABLE ACCESS BY INDEX ROWID XXXX_YYYY_SOURCE (cr=0 pr=0 pw=0 time=89 us)
      0                          INDEX UNIQUE SCAN PK_XXXX_YYYY_SOURCE (cr=0 pr=0 pw=0 time=34 us)(object id 64453)
      0                        TABLE ACCESS BY INDEX ROWID XXXX_YYYY_SOURCE (cr=0 pr=0 pw=0 time=74 us)
      0                         INDEX UNIQUE SCAN PK_XXXX_YYYY_SOURCE (cr=0 pr=0 pw=0 time=30 us)(object id 64453)
     13                       TABLE ACCESS BY INDEX ROWID XXXX_SOMETHING_ENTITY (cr=39 pr=0 pw=0 time=485 us)
     13                        INDEX UNIQUE SCAN PK_XXXX_SOMETHING_ENTITY (cr=26 pr=0 pw=0 time=330 us)(object id 64485)
      0                      TABLE ACCESS BY INDEX ROWID XXXX_ACCOUNT (cr=0 pr=0 pw=0 time=95 us)
      0                       INDEX UNIQUE SCAN PK_XXXX_ACCOUNT (cr=0 pr=0 pw=0 time=41 us)(object id 64399)
      8                     TABLE ACCESS BY INDEX ROWID XXXX_ITEM (cr=24 pr=0 pw=0 time=383 us)
      8                      INDEX UNIQUE SCAN PK_XXXX_ITEM (cr=16 pr=0 pw=0 time=240 us)(object id 64467)
      8                    TABLE ACCESS BY INDEX ROWID XXXX_ITEM_LALALA_HISTORY (cr=24 pr=0 pw=0 time=366 us)
      8                     INDEX UNIQUE SCAN PK_XXXX_ITEM_LALALA_HIST (cr=16 pr=0 pw=0 time=237 us)(object id 64473)
     13                   TABLE ACCESS BY INDEX ROWID XXXX_ITEM (cr=39 pr=0 pw=0 time=575 us)
     13                    INDEX UNIQUE SCAN PK_XXXX_ITEM (cr=26 pr=0 pw=0 time=361 us)(object id 64467)
     13                  TABLE ACCESS BY INDEX ROWID XXXX_ITEM_LALALA_HISTORY (cr=39 pr=0 pw=0 time=553 us)
     13                   INDEX UNIQUE SCAN PK_XXXX_ITEM_LALALA_HIST (cr=26 pr=0 pw=0 time=372 us)(object id 64473)
     13                 TABLE ACCESS BY INDEX ROWID XXXX_ITEM (cr=39 pr=0 pw=0 time=571 us)
     13                  INDEX UNIQUE SCAN PK_XXXX_ITEM (cr=26 pr=0 pw=0 time=369 us)(object id 64467)
     13                TABLE ACCESS BY INDEX ROWID XXXX_ITEM_LALALA_HISTORY (cr=39 pr=0 pw=0 time=555 us)
     13                 INDEX UNIQUE SCAN PK_XXXX_ITEM_LALALA_HIST (cr=26 pr=0 pw=0 time=374 us)(object id 64473)
     13               TABLE ACCESS BY INDEX ROWID XXXX_ITEM (cr=39 pr=0 pw=0 time=618 us)
     13                INDEX UNIQUE SCAN PK_XXXX_ITEM (cr=26 pr=0 pw=0 time=363 us)(object id 64467)
     13              TABLE ACCESS BY INDEX ROWID XXXX_ITEM_TYPE (cr=26 pr=0 pw=0 time=432 us)
     13               INDEX UNIQUE SCAN PK_XXXX_ITEM_TYPE (cr=13 pr=0 pw=0 time=261 us)(object id 64479)
     13             TABLE ACCESS BY INDEX ROWID XXXX_ITEM_LALALA_HISTORY (cr=39 pr=0 pw=0 time=529 us)
     13              INDEX UNIQUE SCAN PK_XXXX_ITEM_LALALA_HIST (cr=26 pr=0 pw=0 time=351 us)(object id 64473)
      0            TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=0 pr=0 pw=0 time=93 us)
      0             INDEX UNIQUE SCAN PK_XXXX_USER (cr=0 pr=0 pw=0 time=39 us)(object id 64537)
      0           TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=0 pr=0 pw=0 time=78 us)
      0            INDEX UNIQUE SCAN PK_XXXX_USER (cr=0 pr=0 pw=0 time=34 us)(object id 64537)
      0          TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=0 pr=0 pw=0 time=72 us)
      0           INDEX UNIQUE SCAN PK_XXXX_USER (cr=0 pr=0 pw=0 time=32 us)(object id 64537)
      0         TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=0 pr=0 pw=0 time=72 us)
      0          INDEX UNIQUE SCAN PK_XXXX_USER (cr=0 pr=0 pw=0 time=31 us)(object id 64537)
     13        TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=26 pr=0 pw=0 time=431 us)
     13         INDEX UNIQUE SCAN PK_XXXX_USER (cr=13 pr=0 pw=0 time=268 us)(object id 64537)
     13       TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=26 pr=0 pw=0 time=432 us)
     13        INDEX UNIQUE SCAN PK_XXXX_USER (cr=13 pr=0 pw=0 time=262 us)(object id 64537)
     13      TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=26 pr=0 pw=0 time=441 us)
     13       INDEX UNIQUE SCAN PK_XXXX_USER (cr=13 pr=0 pw=0 time=258 us)(object id 64537)
     13     TABLE ACCESS BY INDEX ROWID XXXX_USER (cr=26 pr=0 pw=0 time=451 us)
     13      INDEX UNIQUE SCAN PK_XXXX_USER (cr=13 pr=0 pw=0 time=263 us)(object id 64537)

Re: Slow cpu-bound hard parse in one environment, fast in another [message #354420 is a reply to message #354343] Sat, 18 October 2008 13:34 Go to previous messageGo to next message
Kevin Meade
Messages: 2101
Registered: December 1999
Location: Connecticut USA
Senior Member
Lots of joins leads to lots of alternative plans. Your problem may simply be a matter of how long it takes oracle to construct a join order. Try reading up on the following parameters and hints:

I have solved this problem before using variations of the following parameters, hints, and techniques:

Quote:
optimizer_max_permutations
/*+ ordered */


I have never used this one but it too could be helpful:

Quote:

optimizer_search_limit
plan stability



Good luck, kevin
Re: Slow cpu-bound hard parse in one environment, fast in another [message #354430 is a reply to message #354420] Sat, 18 October 2008 21:57 Go to previous message
rleishman
Messages: 3724
Registered: October 2005
Location: Melbourne, Australia
Senior Member
That sounds like good advice from Kevin.

I have experience similar in the past. I never got to the bottom of it, but I didn't try mucking about with these parameters.

If these parameters dont help, you should be able to avoid (but not fix) the problem by adding a LEADING(tab) hint to your SQL.

Ross Leishman
Previous Topic: tuning a view
Next Topic: Slow query - Please help.
Goto Forum:
  


Current Time: Sat Dec 10 22:12:37 CST 2016

Total time taken to generate the page: 0.04293 seconds