Home » RDBMS Server » Performance Tuning » Slow performance of DBPLease help!
Slow performance of DBPLease help! [message #65515] Mon, 11 October 2004 21:19 Go to next message
Joy
Messages: 21
Registered: November 2001
Junior Member
Dear All,

For the last few days, I am facing a problem for which I am not able to give any solutions.

The client database is running slow, and the CPU utilization is varying between 80 - 90% and for all the statspack report i have seen that CPU is the topmost timed events.

I have tried to tune the query having the highest CPU time but of no effect.

We are on oracle 9ir2, win2k, raid 5, datafiles are on raid5(problemaric not not possible to move now), single CPU, 2GB RAM.

This is a part of the STATSPACK report. (excluded the SQLs)

=======================================

STATSPACK report for

DB Name         DB Id    Instance     Inst Num Release     Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
IIMSDB        4196346812 iimsdb              1 9.2.0.4.0   NO      DB-SERVER

            Snap Id     Snap Time      Sessions Curs/Sess Comment
            ------- ------------------ -------- --------- -------------------
Begin Snap:                         4119 08-Oct-04 14:17:17       19      39.9

  End Snap:                         4122 08-Oct-04 15:36:43       14      34.4

   Elapsed:                               79.43 (mins)

Cache Sizes (end)
~~~~~~~~~~~~~~~~~
               Buffer Cache:       656M      Std Block Size:
        8K
           Shared Pool Size:       520M          Log Buffer:
      512K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:              7,389.61             18,400.67
              Logical reads:             26,123.40             65,049.19
              Block changes:                 37.76                 94.02
             Physical reads:                443.13              1,103.43
            Physical writes:                  1.20                  2.99
                 User calls:                112.99                281.35
                     Parses:                 39.12                 97.40
                Hard parses:                  0.58                  1.45
                      Sorts:                 24.13                 60.08
                     Logons:                  1.34                  3.33
                   Executes:                498.02              1,240.10
               Transactions:                  0.40

  % Blocks changed per Read:    0.14    Recursive Call %:                85.99
Rollback per transaction %:    4.60       Rows per Sort:                71.15

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:              100.00
            Buffer  Hit   %:   98.30    In-memory Sort %:              100.00
            Library Hit   %:   99.83        Soft Parse %:               98.51
         Execute to Parse %:   92.15         Latch Hit %:               99.91
Parse CPU to Parse Elapsd %:   96.08     % Non-Parse CPU:               99.37

Shared Pool Statistics        Begin   End
                               ------  ------
             Memory Usage %:   30.43   35.41
    % SQL with executions>1:   49.61   48.99
  % Memory for SQL w/exec>1:   50.67   49.49

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~                                                     % Total
Event                                               Waits    Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
CPU time                                                        3,743    71.70
db file sequential read                           133,180         677    12.96
db file scattered read                            170,821         608    11.65
log file parallel write                             3,964          42      .80
db file parallel write                                795          39      .74
          -------------------------------------------------------------
Wait Events for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)

                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file sequential read           133,180          0        677      5     69.6
db file scattered read            170,821          0        608      4     89.2
log file parallel write             3,964      3,750         42     11      2.1
db file parallel write                795          0         39     49      0.4
log file sync                       3,303          0         38     12      1.7
control file parallel write         1,540          0         31     20      0.8
enqueue                                13          5         21   1654      0.0
latch free                          2,141      1,841         13      6      1.1
buffer busy waits                   1,027          0          4      4      0.5
control file sequential read          780          0          3      4      0.4
SQL*Net more data to client         3,188          0          0      0      1.7
SQL*Net break/reset to clien           74          0          0      2      0.0
LGWR wait for redo copy                 4          0          0      8      0.0
row cache lock                          6          0          0      0      0.0
SQL*Net message from client       616,150          0     34,045     55    321.9
wakeup time manager                   150        150      4,601  30676      0.1
jobq slave wait                        66         63        202   3060      0.0
SQL*Net message to client         616,145          0          2      0    321.9
SQL*Net more data from clien          541          0          1      1      0.3
          -------------------------------------------------------------
Background Wait Events for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122
-> ordered by wait time desc, waits desc (idle events last)

                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
log file parallel write             3,964      3,750         42     11      2.1
db file parallel write                795          0         39     49      0.4
control file parallel write         1,540          0         31     20      0.8
control file sequential read          616          0          3      5      0.3
db file scattered read                 41          0          1     17      0.0
db file sequential read                 7          0          0      6      0.0
LGWR wait for redo copy                 4          0          0      8      0.0
latch free                              3          2          0      9      0.0
buffer busy waits                       2          0          0      1      0.0
rdbms ipc message                  13,323      8,403     17,092   1283      7.0
pmon timer                          2,040      2,040      4,765   2336      1.1
smon timer                             17         14      4,691 ######      0.0
          -------------------------------------------------------------
SQL ordered by Gets for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122
-> End Buffer Gets Threshold:   10000
-> Note that resources reported for PL/SQL includes the resources used by
   all SQL statements called within the PL/SQL code.  As individual SQL
   statements are also reported, it is possible and valid for the summed
   total % to exceed 100
===========================================

Instance Activity Stats for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122

Statistic                                      Total     per Second    per Trans
--------------------------------- ------------------ -------------- ------------
CPU used by this session                     374,251           78.5        195.5
CPU used when call started                   374,251           78.5        195.5
CR blocks created                              2,622            0.6          1.4
DBWR buffers scanned                           6,509            1.4          3.4
DBWR checkpoint buffers written                5,527            1.2          2.9
DBWR checkpoints                                   0            0.0          0.0
DBWR free buffers found                        6,324            1.3          3.3
DBWR lru scans                                     8            0.0          0.0
DBWR make free requests                            8            0.0          0.0
DBWR summed scan depth                         6,509            1.4          3.4
DBWR transaction table writes                     20            0.0          0.0
DBWR undo block writes                         1,907            0.4          1.0
SQL*Net roundtrips to/from client            596,953          125.3        311.9
active txn count during cleanout               3,012            0.6          1.6
background checkpoints completed                   0            0.0          0.0
background checkpoints started                     0            0.0          0.0
background timeouts                            5,575            1.2          2.9
branch node splits                                 5            0.0          0.0
buffer is not pinned count               143,925,752       30,198.4     75,196.3
buffer is pinned count                    49,033,167       10,288.1     25,618.2
bytes received via SQL*Net from c         48,192,389       10,111.7     25,178.9
bytes sent via SQL*Net to client          45,697,976        9,588.3     23,875.6
calls to get snapshot scn: kcmgss          2,657,077          557.5      1,388.2
calls to kcmgas                               14,803            3.1          7.7
calls to kcmgcs                                  683            0.1          0.4
change write time                                198            0.0          0.1
cleanout - number of ktugct calls              3,115            0.7          1.6
cleanouts and rollbacks - consist              2,031            0.4          1.1
cleanouts only - consistent read                 195            0.0          0.1
cluster key scan block gets                      213            0.0          0.1
cluster key scans                                 71            0.0          0.0
commit cleanout failures: buffer                   3            0.0          0.0
commit cleanout failures: callbac                  0            0.0          0.0
commit cleanout failures: cannot                   1            0.0          0.0
commit cleanouts                              25,970            5.5         13.6
commit cleanouts successfully com             25,966            5.5         13.6
commit txn count during cleanout               1,002            0.2          0.5
consistent changes                            32,222            6.8         16.8
consistent gets                          124,272,520       26,074.8     64,928.2
consistent gets - examination             53,290,782       11,181.5     27,842.6
cursor authentications                           118            0.0          0.1
data blocks consistent reads - un             32,216            6.8         16.8
db block changes                             179,951           37.8         94.0
db block gets                                231,618           48.6        121.0
deferred (CURRENT) block cleanout             15,673            3.3          8.2
dirty buffers inspected                            6            0.0          0.0
enqueue conversions                            1,930            0.4          1.0
enqueue releases                              42,550            8.9         22.2
enqueue requests                              42,544            8.9         22.2
enqueue waits                                      7            0.0          0.0
execute count                              2,373,542          498.0      1,240.1
free buffer inspected                            237            0.1          0.1
free buffer requested                      2,117,569          444.3      1,106.4
hot buffers moved to head of LRU              25,031            5.3         13.1
immediate (CR) block cleanout app              2,226            0.5          1.2
immediate (CURRENT) block cleanou              1,260            0.3          0.7
Instance Activity Stats for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122

Statistic                                      Total     per Second    per Trans
--------------------------------- ------------------ -------------- ------------
index fast full scans (full)                      95            0.0          0.1
index fetch by key                        39,653,228        8,320.0     20,717.5
index scans kdiixs1                        1,937,914          406.6      1,012.5
leaf node 90-10 splits                            52            0.0          0.0
leaf node splits                                 375            0.1          0.2
logons cumulative                              6,383            1.3          3.3
messages received                              4,451            0.9          2.3
messages sent                                  4,451            0.9          2.3
no buffer to keep pinned count                     0            0.0          0.0
no work - consistent read gets            68,917,400       14,460.2     36,007.0
opened cursors cumulative                    177,914           37.3         93.0
parse count (failures)                             0            0.0          0.0
parse count (hard)                             2,782            0.6          1.5
parse count (total)                          186,432           39.1         97.4
parse time cpu                                 2,355            0.5          1.2
parse time elapsed                             2,451            0.5          1.3
physical reads                             2,111,970          443.1      1,103.4
physical reads direct                              0            0.0          0.0
physical writes                                5,718            1.2          3.0
physical writes direct                             0            0.0          0.0
physical writes non checkpoint                 2,939            0.6          1.5
pinned buffers inspected                         140            0.0          0.1
prefetched blocks                          1,807,943          379.3        944.6
process last non-idle time         7,000,300,293,360 ############## ############
recursive calls                            3,305,041          693.5      1,726.8
recursive cpu usage                          345,450           72.5        180.5
redo blocks written                           72,746           15.3         38.0
redo buffer allocation retries                     0            0.0          0.0
redo entries                                  92,662           19.4         48.4
redo log space requests                            0            0.0          0.0
redo log space wait time                           0            0.0          0.0
redo size                                 35,218,876        7,389.6     18,400.7
redo synch time                                3,863            0.8          2.0
redo synch writes                              3,284            0.7          1.7
redo wastage                               1,002,380          210.3        523.7
redo write time                                4,219            0.9          2.2
redo writer latching time                          3            0.0          0.0
redo writes                                    3,961            0.8          2.1
rollback changes - undo records a                 82            0.0          0.0
rollbacks only - consistent read                 604            0.1          0.3
rows fetched via callback                 36,866,150        7,735.2     19,261.3
session connect time               7,000,300,293,360 ############## ############
session cursor cache hits                     81,074           17.0         42.4
session logical reads                    124,504,141       26,123.4     65,049.2
session uga memory                        71,103,632       14,918.9     37,149.2
session uga memory max                 3,494,620,612      733,239.7  1,825,820.6
shared hash latch upgrades - no w          1,841,329          386.4        962.0
shared hash latch upgrades - wait                 18            0.0          0.0
sorts (memory)                               115,002           24.1         60.1
sorts (rows)                               8,182,443        1,716.8      4,275.1
summed dirty queue length                        191            0.0          0.1
switch current to new buffer                   1,311            0.3          0.7
table fetch by rowid                      47,615,247        9,990.6     24,877.4
table fetch continued row                          2            0.0          0.0
table scan blocks gotten                  58,351,500       12,243.3     30,486.7
table scan rows gotten                 1,588,396,504      333,276.7    829,883.2
Instance Activity Stats for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122

Statistic                                      Total     per Second    per Trans
--------------------------------- ------------------ -------------- ------------
table scans (long tables)                      2,179            0.5          1.1
table scans (short tables)                   117,607           24.7         61.5
transaction rollbacks                             38            0.0          0.0
user calls                                   538,507          113.0        281.4
user commits                                   1,826            0.4          1.0
user rollbacks                                    88            0.0          0.1
workarea executions - optimal                149,119           31.3         77.9
write clones created in foregroun                  0            0.0          0.0
          -------------------------------------------------------------
Tablespace IO Stats for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122
->ordered by IOs (Reads + Writes) desc

Tablespace
------------------------------
                 Av      Av     Av                    Av        Buffer Av Buf
         Reads Reads/s Rd(ms) Blks/Rd       Writes Writes/s      Waits Wt(ms)
-------------- ------- ------ ------- ------------ -------- ---------- ------
TS_IIMS_ACC_DAT_01
       186,218      39    4.6     2.5          182        0      1,023    4.0
TS_IIMS_UWR_DAT_01
       113,122      24    3.9    14.1          562        0          1    0.0
TS_IIMS_PTY_DAT_01
         3,151       1    5.6    13.9           34        0          0    0.0
UNDOTBS1
             0       0    0.0                1,929        0          2    0.0
TS_IIMS_ACC_IND_01
           330       0    8.6     1.0        1,389        0          0    0.0
TS_IIMS_UWR_IND_01
           659       0    5.4     1.0          516        0          0    0.0
USERS
           148       0    5.3     1.0          484        0          0    0.0
TS_IIMS_SEC_DAT_01
            96       0    6.5     1.0          363        0          0    0.0
TS_IIMS_PTY_IND_01
           137       0    7.4     1.0          227        0          0    0.0
SYSTEM
           114       0   10.5     4.5           32        0          1   10.0
TS_IIMS_CLM_DAT_01
             9       0    4.4    10.7            0        0          0    0.0
TS_IIMS_PRD_DAT_01
             7       0    1.4     1.0            0        0          0    0.0
TS_IIMS_PRD_IND_01
             3       0   10.0     1.0            0        0          0    0.0
TS_IIMS_CLM_IND_01
             2       0    5.0     1.0            0        0          0    0.0
          -------------------------------------------------------------
File IO Stats for DB: IIMSDB  Instance: iimsdb  Snaps: 4119 -4122
->ordered by Tablespace, File
===============================================

Parameter Name                Begin value                       (if different)
----------------------------- --------------------------------- --------------
aq_tm_processes               1
background_dump_dest          D:oracleadminIIMSDBbdump
compatible                    9.2.0.4
control_files                 D:oracleoradataIIMSDBcontrol0
core_dump_dest                D:oracleadminIIMSDBcdump
cursor_sharing                FORCE
db_block_size                 8192
db_cache_size                 687865856
db_domain
db_file_multiblock_read_count 16
db_name                       IIMSDB
fast_start_mttr_target        300
hash_join_enabled             TRUE
ifile                         D:oracleadminIIMSDBpfileinit
instance_name                 IIMSDB
java_pool_size                58720256
job_queue_processes           10
large_pool_size               209715200
open_cursors                  3000
pga_aggregate_target          367001600
processes                     600
query_rewrite_enabled         FALSE
remote_login_passwordfile     EXCLUSIVE
session_cached_cursors        100
sga_max_size                  1628515328
shared_pool_size              545259520
sort_area_size                524288
star_transformation_enabled   FALSE
timed_statistics              TRUE
undo_management               AUTO
undo_retention                10800
undo_tablespace               UNDOTBS1
user_dump_dest                D:oracleadminIIMSDBudump
utl_file_dir                  *
workarea_size_policy          AUTO

 
Re: Slow performance of DBPLease help! [message #65620 is a reply to message #65515] Wed, 10 November 2004 13:40 Go to previous message
Pete Karanikas
Messages: 1
Registered: November 2004
Junior Member
You have high reads and a low amount of writes. You buffer hit and library hit ratio is great. You are doing well in terms of in-memory sorts as opposed to sorts on disk. Seems that your apps have a large amount of idle time as well and you've got plenty of memory. So there's no problem reading or writing data. The problem is probably with the sorting that your apps are performing. You are also performing lots of full table scans.

First, check the basics-

- Analyze your tables to generate valid statistics and then rebuild all of your indexes.
- Make sure that all of your data, indexes, and temp datafiles are in different places.

- Make sure you have your degree of parallelism is set to 1 since you have only 1 CPU. If it's set to something else, then you'll have twice the overhead on your 1 CPU.

Second, check the code-

- Generate explain plans for your resource intensive queries and create appropriate indexes on the necessary colums to eliminate the full table scans.

- Make sure the developers aren't using incorrect HINTS in their code. They could be forcing the use of bad indexes.

- Make sure the developers are not performing too many nested operations in a single query. If they are, BREAK UP THE OPERATIONS into seperate parts. For example, insert the results of the first query to a temp table and then select and sort the data from that temp table. That usually increases the performance of complex queries by 2X or 3X.

Last, tweak the DB

- Since you are performing lots of reads you should think about splitting up your buffer pool. This will keep your heavily used data in the buffer so you don't have to get it from disk. This isn't a huge problem for you since your buffer hit ratio is good. But you should try it out since it has generally increases performance. Create a BUFFER_POOL_KEEP and a BUFFER_POOL_RECYCLE. Assign your small, heavily used tables to the KEEP buffer pool. Assign your large tables that you peroform adhoc queries on to the RECYCLE pool.

- Partition tables if it makes sense to speed up reads and scans.

- Since you're performing lots of sorts, make sure that your TEMP tablespace is big and that the datafiles are in a seperate place from your other tablespaces.

- I've had great luck by setting SESSION_CACHED_CURSORS = 10

- I've also had great increases by setting CURSOR_SHARING = FORCE
----------------------------------------------

This should fix you up.
Hope it helps,
Pete
Previous Topic: To find out the Stored Procedure name and the Full table scan
Next Topic: Tunning Timestamp field
Goto Forum:
  


Current Time: Sun Sep 20 16:33:08 CDT 2020