Re: DB time Less Than Elapsed Time - is there a performance problem? or is the report interval incorrect?

  • From: Andrew Kerber <andrew.kerber@xxxxxxxxx>
  • To: oracledbawannabe@xxxxxxxxx
  • Date: Sat, 18 Sep 2010 19:31:00 -0500

As I recall, the db_time is the actual CPU time used by the DB, so there is
a lot of time to give on the db.  It looks like it is waiting on CPU
though.  So, how is it spending all that CPU time?  Parsing?  Check your
memory advice (PGA advice, buffer pool advice, etc).

On Sat, Sep 18, 2010 at 5:28 PM, Oracle Dba Wannabe <
oracledbawannabe@xxxxxxxxx> wrote:

> Hi All,
> I've been given two awr reports for a 2 node, 11.1.0.7 RAC instance running
> on AIX and told to determine what the performance problem is with the
> system. Looking through the reports I can't say that I can see anything
> wrong with this system - at least based on the awrs I have been given (a few
> extracts from the reports given below). What I have noticed is that for both
> nodes the db time is considerably less than the elapsed time of the report
> - is this enough to deduce that this system is actually not busy and not
> performing any sort of work?.  That said, the 'transactions per second'
> statistic is at 0.6 and 1.6 (for each node), additionally , logical reads,
> physical reads appear to be quite low.
> Or perhaps one of the following possible:
> (a) Since DB time excludes a few idle events - such as the sql*net related
> events that perhaps time is being spent there are not being recorded?
> Therefore db time is less than elapsed time and gives the illusion that the
> system is not busy?
> (b) That perhaps the performance problem is short lived - lasts for a
> duration less than the elapsed time - therefore is not evident from these
> two awr reports
> Thanks in advance for any pointers or help.
>
> --Node1--:
>
>
> Snap Id Snap Time Sessions Cursors/Session Begin Snap: 3479 17-Sep-10
> 08:59:58 67 2.6 End Snap: 3480 17-Sep-10 10:00:10 76 2.1 Elapsed:   60.19
> (mins)     DB Time:   8.54 (mins)
>
> Top 5 Timed Foreground Events
>
>   Event Waits Time(s) Avg wait (ms) % DB time Wait Class DB CPU   434
> 84.72   gc buffer busy acquire 956 5 5 0.98 Cluster gc cr block 2-way
> 7,515 4 1 0.74 Cluster IPC send completion sync 7,847 3 0 0.56 Other enq:
> PS - contention 4,534 2 1 0.49 Other
>
> Load Profile
>
>
> Per Second Per Transaction Per Exec Per Call DB Time(s): 0.1 0.2 0.01 0.01 DB
> CPU(s): 0.1 0.2 0.00 0.01 Redo size: 3,311.9 5,441.9     Logical reads:
> 7,384.6 12,133.9     Block changes: 154.9 254.5     Physical reads: 0.2
> 0.3     Physical writes: 1.4 2.3     User calls: 11.3 18.6     Parses:
> 17.7 29.2     Hard parses: 0.1 0.2     W/A MB processed: 1,211,497.8
> 1,990,648.6     Logons: 0.9 1.4     Executes: 26.5 43.5     Rollbacks: 0.2
> 0.3     Transactions: 0.6
> --End Node1--
>
> --Node2--
>
>
>
> Snap Id Snap Time Sessions Cursors/Session Begin Snap: 3479 17-Sep-10
> 09:00:29 61 2.5 End Snap: 3480 17-Sep-10 10:00:41 59 1.8 Elapsed:   60.19
> (mins)     DB Time:   15.60 (mins)
>
> Top 5 Timed Foreground Events
>
>   Event Waits Time(s) Avg wait (ms) % DB time Wait Class DB CPU   738
> 78.83   library cache load lock 714 38 53 4.03 Concurrency enq: TQ - DDL
> contention 509 24 47 2.58 Other db file sequential read 15,618 23 2 2.51 User
> I/O gc buffer busy acquire 1,206 6 5 0.64 Cluster
>
> Load Profile
>
>
> Per Second Per Transaction Per Exec Per Call DB Time(s): 0.3 0.2 0.00 0.02 DB
> CPU(s): 0.2 0.1 0.00 0.02 Redo size: 5,855.0 3,772.7     Logical reads:
> 10,669.5 6,875.0     Block changes: 907.2 584.6     Physical reads: 6.3
> 4.1     Physical writes: 2.1 1.4     User calls: 12.7 8.2     Parses: 41.3
> 26.6     Hard parses: 0.2 0.1     W/A MB processed: 1,327,061.6 855,097.2
>     Logons: 1.0 0.6     Executes: 65.3 42.1     Rollbacks: 0.4 0.2
> Transactions: 1.6
>
> --End Node2--
>
>


-- 
Andrew W. Kerber

'If at first you dont succeed, dont take up skydiving.'

Other related posts: