Go to the FreeLists Home Page Home Signup Help Login
 



[oracle-l] || [Date Prev] [05-2005 Date Index] [Date Next] || [Thread Prev] [05-2005 Thread Index] [Thread Next]

Parsing and High CPU consumption

  • From: Robert Pegram <pegramrg@xxxxxxxxx>
  • To: oracle-l@xxxxxxxxxxxxx
  • Date: Tue, 3 May 2005 07:13:18 -0700 (PDT)
Oracle 9.2.0.5
AIX 5.2

I am currently working with Oracle support, and they have been less
than helpful so far.  We have an application that is consuming lots of
CPU.  We have tuned several pieces of sql, which has helped. Parsing
was the next area I was going to focus my attention on.  The developers
are using bind variables and prepared statements in their java
application.  The statements that are getting parsed the most are
Oracle internal statements (see statspack report below).  I'm trying to
figure out why these are getting parsed each time they are executed and
if they are contributing to the high cpu consumption.  Looking at
v$sql, the statements have not been loaded or invalidated very often. 
Also, looking at the v$sql_shared_cursor view, the optimizer_mismatch
is the only column that has a value of 'Y'.  I couldn't find much
information about the optimizer_mismatch column on metalink.

Am I going down the wrong road here?  Should I be focusing my attention
somewhere else?  Am I interpreting the statspack report incorrectly?

Thanks in advance for any tips, suggestions.

Rob Pegram
Duke University




            Snap Id     Snap Time      Sessions Curs/Sess Comment
            ------- ------------------ -------- ---------
-------------------
Begin Snap:    9634 02-May-05 13:01:01       23       3.3
  End Snap:    9643 02-May-05 13:25:24       22       3.5
   Elapsed:               24.38 (mins)

Cache Sizes (end)
~~~~~~~~~~~~~~~~~
               Buffer Cache:       112M      Std Block Size:         8K
           Shared Pool Size:        32M          Log Buffer:       512K
Load Profile
~~~~~~~~~~~~                            Per Second       Per
Transaction
                                   ---------------      
---------------
                  Redo size:              8,425.37               
775.34
              Logical reads:              1,996.05               
183.68
              Block changes:                 61.97                 
5.70
             Physical reads:                 24.16                 
2.22
            Physical writes:                  1.05                 
0.10
                 User calls:                 79.85                 
7.35
                     Parses:                305.54                
28.12
                Hard parses:                 63.90                 
5.88
                      Sorts:                 52.01                 
4.79
                     Logons:                  0.01                 
0.00
                   Executes:                363.83                
33.48
               Transactions:                 10.87

  % Blocks changed per Read:    3.10    Recursive Call %:    97.89
 Rollback per transaction %:    0.00       Rows per Sort:     4.43

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:  100.00
            Buffer  Hit   %:   98.79    In-memory Sort %:  100.00
            Library Hit   %:   90.67        Soft Parse %:   79.09
         Execute to Parse %:   16.02         Latch Hit %:   99.98
Parse CPU to Parse Elapsd %:   99.30     % Non-Parse CPU:   77.24

 Shared Pool Statistics        Begin   End
                               ------  ------
             Memory Usage %:   94.82   94.04
    % SQL with executions>1:   66.30   67.32
  % Memory for SQL w/exec>1:   87.13   87.56

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~                                                    
% Total
Event                                               Waits    Time (s)
Ela Time
-------------------------------------------- ------------ -----------
--------
CPU time                                                        1,299  
 93.90
db file scattered read                              3,438          28  
  2.01
log file parallel write                            15,947          28  
  2.01
log file sequential read                               39           7  
   .48
ARCH wait on SENDREQ                                   61           7  
   .48


.............................................

  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s)
Hash Value
--------------- ------------ -------------- ------ -------- ---------
----------
        573,582       42,610           13.5   19.6    15.05 #########
4080861370
select owner#,name,namespace,remoteowner,linkname,p_timestamp,p_
obj#, d_owner#, nvl(property,0),subname from dependency$,obj$ wh
ere d_obj#=:1 and p_obj#=obj#(+) order by order#

        435,189       42,609           10.2   14.9     8.62      7.36
1198893840
select order#,columns,types from access$ where d_obj#=:1

        308,562       45,006            6.9   10.6     6.10      5.48 
986338823
select /*+ index(idl_ub1$ i_idl_ub11) +*/ piece#,length,piece fr
om idl_ub1$ where obj#=:1 and part=:2 and version=:3 order by pi
ece#

        181,558       45,005            4.0    6.2     4.94      4.45 
386388955
select /*+ index(idl_ub2$ i_idl_ub21) +*/ piece#,length,piece fr
om idl_ub2$ where obj#=:1 and part=:2 and version=:3 order by pi
ece#

.............................................

                           % Total
 Parse Calls  Executions   Parses  Hash Value
------------ ------------ -------- ----------
      45,006       45,006    10.07  336764478
select /*+ index(idl_char$ i_idl_char1) +*/ piece#,length,piece
from idl_char$ where obj#=:1 and part=:2 and version=:3 order by
 piece#

      45,006       45,006    10.07  986338823
select /*+ index(idl_ub1$ i_idl_ub11) +*/ piece#,length,piece fr
om idl_ub1$ where obj#=:1 and part=:2 and version=:3 order by pi
ece#

      45,005       45,005    10.07  386388955
select /*+ index(idl_ub2$ i_idl_ub21) +*/ piece#,length,piece fr
om idl_ub2$ where obj#=:1 and part=:2 and version=:3 order by pi
ece#

      45,005       45,005    10.07 2954231783
select /*+ index(idl_sb4$ i_idl_sb41) +*/ piece#,length,piece fr
om idl_sb4$ where obj#=:1 and part=:2 and version=:3 order by pi
ece#

      42,610       42,610     9.53 4080861370
select owner#,name,namespace,remoteowner,linkname,p_timestamp,p_
obj#, d_owner#, nvl(property,0),subname from dependency$,obj$ wh
ere d_obj#=:1 and p_obj#=obj#(+) order by order#

      42,609       42,609     9.53 1198893840
select order#,columns,types from access$ where d_obj#=:1

      34,396       46,008     7.69 2703824309
select obj#,type#,ctime,mtime,stime,status,dataobj#,flags,oid$,
spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespa
ce=:3 and remoteowner is null and linkname is null and subname i
s null


..........................................

Statistic                                      Total     per Second   
per Trans
--------------------------------- ------------------ --------------
------------
CPU used by this session                     129,909           88.8    
     8.2
CPU used when call started                   129,908           88.8    
     8.2
parse count (failures)                             0            0.0    
     0.0
parse count (hard)                            93,488           63.9    
     5.9
parse count (total)                          447,004          305.5    
    28.1
parse time cpu                                29,571           20.2    
     1.9
parse time elapsed                            29,779           20.4    
     1.9


..........................................


select a.loads, a.invalidations, a.executions, a.parse_calls, 
a.optimizer_mode, b.address, b.KGLHDPAR, b.optimizer_mismatch
from v$sql a, V$SQL_SHARED_CURSOR  b 
where a.hash_value = 336764478 
and a.address = b.KGLHDPAR;

    LOADS INVALIDATIONS EXECUTIONS PARSE_CALLS OPTIMIZER_ ADDRESS      
   KGLHDPAR         O
---------- ------------- ---------- ----------- ----------
---------------- ---------------- -
        15             2    1421505     1421505 CHOOSE    
070000000EBB74E0 07000000100D4090 N
        10             0          2           2 CHOOSE    
070000000EBB74E0 07000000100D4090 N
         4             0          0           0 NONE      
070000000EBB74E0 07000000100D4090 N
        15             2    1421505     1421505 CHOOSE    
0700000010280580 07000000100D4090 Y
        10             0          2           2 CHOOSE    
0700000010280580 07000000100D4090 Y
         4             0          0           0 NONE      
0700000010280580 07000000100D4090 Y

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com 
--
http://www.freelists.org/webpage/oracle-l




[ Home | Signup | Help | Login | Archives | Lists ]

All trademarks and copyrights within the FreeLists archives are owned by their respective owners.
Everything else ©2007 Avenir Technologies, LLC.