Re: Oracle db writer taking too much CPU ?

Hi,

First at all, I think you should take an snapshot a little more longer than this. Nevertheless, what I get from here is that your DBWR doesn't keep up with its work. My advices are:

• Take a look of the queries the Database is receiving. Maybe you find some hurting full-scans. I said this on account of the db file scattered read and because of the hit ratio you make reference. And if you are using costs as I think you use, analyze the schemas involved in the application.
• You should increase the db_block_buffers. Also consider setting the buffer_pool_keep and buffer_poor_recycle parameters. I suppose you have Oracle 8 according some statistics. And after correcting these issues you would increase shared_pool_size too. However it doesn't seem to be the problem now.
• Also look what it has CD_IND_2 because "he is winning all the prizes". Maybe there is very big table with bad pctfree/pctused and freelists settings. Maybe it has some indexes and apparently it is for data only. Also spread its datafiles accross the file systems.
• It is possible that you need to increase db_simultaneous_writes or _db_block_write_batch because of the write complete waits. Maybe DBWR couldn't keep up with the batch writes. Also the average dirty queue seems to be big.
• It is out of the matter but in your case I should decrease the sort_area_size. Maybe you have some paging or swapping problems and you haven't noticed yet. And also in your place I should ask the Unix support team about the configuration of the fs buffer size. I'm saying this because of the db_file_multiblock_read_count. I think it is a little higher considering the block size and considering the optimizer you are using either.

Hope it helps. Regards.

>From: R Bresner <wawb_at_escape.net>
>Reply-To: ORACLE-L_at_fatcity.com
>To: Multiple recipients of list ORACLE-L <ORACLE-L_at_fatcity.com>
>Subject: Re: Oracle db writer taking too much CPU ?
>Date: Tue, 02 May 2000 13:08:35 -0800
>
>Hello again,
>
>I'm pasting a report that my groovy ( well dressed, good looking, good
>singing,
>and recently subscribed member of this list, so he's probably reading this)
>DBA guy has generated, in an effort to possibly verify the reason that the
>Oracle
>DB Writer process is going mad.
>
>To me this is mostly greek.
>Could someone take a look at this and form a conclusion?
>Good karma ensues!
>
>To quickly recap:
> During a typical, simple update of a 40GB 19+ million row DB, a top
>call is
> showing my process at between 0.05% and 5.00% CPU, while the DBWR
> process is taking up an entire CPU of the machine (33%). Simple queries
> (thanks again, Chuck Hamilton) show that there are 60 incomplete
>checkpoints
> and a 60.3% hit ratio, indicating problems (which may be due to a
>faulty scsi device
> of some kind.
>
>Thanks very much in advance to anyone brave enough to squint their eyes
>at the following lines.
>
>Rob
>
>=================================
>SVRMGR>
>SVRMGR> set charwidth 12
>Charwidth 12
>SVRMGR> set numwidth 10
>Numwidth 10
>SVRMGR> Rem Select Library cache statistics. The pin hit rate should be
>high.
>SVRMGR> select namespace library,
> 2> gets,
> 3> round(decode(gethits,0,1,gethits)/decode(gets,0,1,gets),3)
> 4> gethitratio,
> 5> pins,
> 6> round(decode(pinhits,0,1,pinhits)/decode(pins,0,1,pins),3)
> 7> pinhitratio,
> 8> reloads, invalidations
> 9> from stats$lib;
>LIBRARY GETS GETHITRATI PINS PINHITRATI RELOADS
>INVALIDATI
>------------ ---------- ---------- ---------- ---------- ----------
>----------
>BODY 25 .84 25 .84 0
> 0
>CLUSTER 101 .99 91 .978 0
> 0
>INDEX 12 .5 18 .333 0
> 0
>OBJECT 0 1 0 1 0
> 0
>PIPE 0 1 0 1 0
> 0
>SQL AREA 1653 .903 89297 .996 7
> 1
>TABLE/PROCED 988 .778 1643 .786 6
> 0
>TRIGGER 42 .952 42 .905 0
> 0
>8 rows selected.
>SVRMGR>
>SVRMGR> set charwidth 27;
>Charwidth 27
>SVRMGR> set numwidth 12;
>Numwidth 12
>SVRMGR> Rem The total is the total value of the statistic between the time
>SVRMGR> Rem bstat was run and the time estat was run. Note that the estat
>SVRMGR> Rem script logs on as "internal" so the per_logon statistics will
>SVRMGR> Rem always be based on at least one logon.
>SVRMGR> select n1.name "Statistic",
> 2> n1.change "Total",
> 3> round(n1.change/trans.change,2) "Per Transaction",
> 4> round(n1.change/logs.change,2) "Per Logon",
> 5> round(n1.change/(to_number(to_char(end_time,
>'J'))*60*60*24 -
> 6> to_number(to_char(start_time,
>'J'))*60*60*24 +
> 7> to_number(to_char(end_time, 'SSSSS')) -
> 8> to_number(to_char(start_time, 'SSSSS')))
> 9> , 2) "Per Second"
> 10> from stats$stats n1, stats$stats trans, stats$stats logs,
>stats$dates
> 11> where trans.name='user commits'
> 12> and logs.name='logons cumulative'
> 13> and n1.change != 0
> 14> order by n1.name;
>Statistic Total Per Transact Per Logon Per
>Second
>--------------------------- ------------ ------------ ------------
>------------
>CPU used by this session 48272 766.22 1149.33
>34.53
>CPU used when call started 48271 766.21 1149.31
>34.53
>DBWR Flush object call foun 6 .1 .14
> 0
>DBWR Flush object cross ins 6 .1 .14
> 0
>DBWR buffers scanned 619029 9825.86 14738.79
>442.8
>DBWR checkpoint buffers wri 625 9.92 14.88
>.45
>DBWR checkpoint write reque 36 .57 .86
>.03
>DBWR free buffers found 576290 9147.46 13721.19
>412.22
>DBWR lru scans 794 12.6 18.9
>.57
>DBWR make free requests 758 12.03 18.05
>.54
>DBWR revisited being-writte 260 4.13 6.19
>.19
>DBWR skip hot writes 5 .08 .12
> 0
>DBWR summed scan depth 635200 10082.54 15123.81
>454.36
>DBWR transaction table writ 46 .73 1.1
>.03
>DBWR undo block writes 1012 16.06 24.1
>.72
>SQL*Net roundtrips to/from 84533 1341.79 2012.69
>60.47
>background checkpoints comp 12 .19 .29
>.01
>background checkpoints star 12 .19 .29
>.01
>background timeouts 1052 16.7 25.05
>.75
>buffer is not pinned count 756379 12006.02 18009.02
>541.04
>buffer is pinned count 1703506 27039.78 40559.67
>1218.53
>bytes received via SQL*Net 10350289 164290.3 246435.45
>7403.64
>bytes sent via SQL*Net to c 8471714 134471.65 201707.48
>6059.88
>calls to get snapshot scn: 86264 1369.27 2053.9
>61.71
>calls to kcmgas 106 1.68 2.52
>.08
>calls to kcmgcs 4 .06 .1
> 0
>calls to kcmgrs 111088 1763.3 2644.95
>79.46
>change write time 1004 15.94 23.9
>.72
>cleanouts only - consistent 526 8.35 12.52
>.38
>cluster key scan block gets 285691 4534.78 6802.17
>204.36
>cluster key scans 141210 2241.43 3362.14
>101.01
>commit cleanout failures: b 144 2.29 3.43
> .1
>commit cleanout failures: b 8 .13 .19
>.01
>commit cleanouts 6230 98.89 148.33
>4.46
>commit cleanouts successful 6078 96.48 144.71
>4.35
>consistent gets 966379 15339.35 23009.02
>691.26
>cursor authentications 67 1.06 1.6
>.05
>db block changes 313442 4975.27 7462.9
>224.21
>db block gets 191048 3032.51 4548.76
>136.66
>deferred (CURRENT) block cl 9945 157.86 236.79
>7.11
>dirty buffers inspected 16169 256.65 384.98
>11.57
>enqueue releases 503 7.98 11.98
>.36
>enqueue requests 501 7.95 11.93
>.36
>execute count 86143 1367.35 2051.02
>61.62
>free buffer inspected 133540 2119.68 3179.52
>95.52
>free buffer requested 311726 4948.03 7422.05
>222.98
>immediate (CR) block cleano 526 8.35 12.52
>.38
>immediate (CURRENT) block c 17 .27 .4
>.01
>logons cumulative 42 .67 1
>.03
>logons current 4 .06 .1
> 0
>messages received 2224 35.3 52.95
>1.59
>messages sent 2225 35.32 52.98
>1.59
>no work - consistent read g 564531 8960.81 13441.21
>403.81
>opened cursors cumulative 1509 23.95 35.93
>1.08
>opened cursors current 3 .05 .07
> 0
>parse count (hard) 168 2.67 4
>.12
>parse count (total) 1661 26.37 39.55
>1.19
>parse time cpu 889 14.11 21.17
>.64
>parse time elapsed 2019 32.05 48.07
>1.44
>physical reads 293612 4660.51 6990.76
>210.02
>physical writes 32690 518.89 778.33
>23.38
>process last non-idle time 15861729407 251773482.65 377660223.98
>11346015.31
>recursive calls 34937 554.56 831.83
>24.99
>recursive cpu usage 740 11.75 17.62
>.53
>redo blocks written 81474 1293.24 1939.86
>58.28
>redo buffer allocation retr 5 .08 .12
> 0
>redo entries 156552 2484.95 3727.43
>111.98
>redo log space requests 5 .08 .12
> 0
>redo log space wait time 234 3.71 5.57
>.17
>redo ordering marks 1 .02 .02
> 0
>redo size 39567092 628049.08 942073.62
>28302.64
>redo small copies 671 10.65 15.98
>.48
>redo synch time 232 3.68 5.52
>.17
>redo synch writes 77 1.22 1.83
>.06
>redo wastage 513460 8150.16 12225.24
>367.28
>redo write time 6938 110.13 165.19
>4.96
>redo writer latching time 3 .05 .07
> 0
>redo writes 1711 27.16 40.74
>1.22
>session connect time 15861729407 251773482.65 377660223.98
>11346015.31
>session logical reads 1157425 18371.83 27557.74
>827.91
>session pga memory 7967572 126469.4 189704.1
>5699.26
>session pga memory max 9159872 145394.79 218092.19
>6552.13
>session uga memory 258376 4101.21 6151.81
>184.82
>session uga memory max 1246064 19778.79 29668.19
>891.32
>sorts (memory) 448 7.11 10.67
>.32
>sorts (rows) 205833 3267.19 4900.79
>147.23
>summed dirty queue length 16171 256.68 385.02
>11.57
>table fetch by rowid 230962 3666.06 5499.1
>165.21
>table fetch continued row 4 .06 .1
> 0
>table scan blocks gotten 445705 7074.68 10612.02
>318.82
>table scan rows gotten 23121293 367004.65 550506.98
>16538.84
>table scans (long tables) 35 .56 .83
>.03
>table scans (short tables) 10863 172.43 258.64
>7.77
>total file opens 152 2.41 3.62
>.11
>user calls 84654 1343.71 2015.57
>60.55
>user commits 63 1 1.5
>.05
>user rollbacks 7 .11 .17
>.01
>write requests 698 11.08 16.62
> .5
>98 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set numwidth 27
>Numwidth 27
>SVRMGR> Rem Average length of the dirty buffer write queue. If this is
>larger
>SVRMGR> Rem than the value of:
>SVRMGR> Rem 1. (db_files * db_file_simultaneous_writes)/2
>SVRMGR> Rem or
>SVRMGR> Rem 2. 1/4 of db_block_buffers
>SVRMGR> Rem which ever is smaller and also there is a platform specific
>limit
>SVRMGR> Rem on the write batch size (normally 1024 or 2048 buffers). If the
>average
>SVRMGR> Rem length of the dirty buffer write queue is larger than the value
>SVRMGR> Rem calculated before, increase db_file_simultaneous_writes or
>db_files.
>SVRMGR> Rem Also check for disks that are doing many more IOs than other
>disks.
>SVRMGR> select queue.change/writes.change "Average Write Queue Length"
> 2> from stats$stats queue, stats$stats writes
> 3> where queue.name = 'summed dirty queue length'
> 4> and writes.name = 'write requests';
>Average Write Queue Length
>---------------------------
>23.167621776504297994269341
>1 row selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set charwidth 32;
>Charwidth 32
>SVRMGR> set numwidth 13;
>Numwidth 13
>SVRMGR> Rem System wide wait events for non-background processes (PMON,
>SVRMGR> Rem SMON, etc). Times are in hundreths of seconds. Each one of
>SVRMGR> Rem these is a context switch which costs CPU time. By looking at
>SVRMGR> Rem the Total Time you can often determine what is the bottleneck
>SVRMGR> Rem that processes are waiting for. This shows the total time
>spent
>SVRMGR> Rem waiting for a specific event and the average time per wait on
>SVRMGR> Rem that event.
>SVRMGR> select n1.event "Event Name",
> 2> n1.event_count "Count",
> 3> n1.time_waited "Total Time",
> 4> round(n1.time_waited/n1.event_count, 2) "Avg Time"
> 5> from stats$event n1
> 6> where n1.event_count > 0
> 7> order by n1.time_waited desc;
>Event Name Count Total Time Avg Time
>-------------------------------- ------------- ------------- -------------
>SQL*Net message from client 84682 653198 7.71
>db file sequential read 218055 125228 .57
>db file scattered read 6205 62265 10.03
>write complete waits 342 32730 95.7
>free buffer waits 31 2333 75.26
>log file switch completion 5 234 46.8
>log file sync 75 232 3.09
>latch free 134 147 1.1
>SQL*Net message to client 84684 120 0
>buffer busy waits 6 105 17.5
>library cache pin 2 70 35
>SQL*Net break/reset to client 30 50 1.67
>file open 144 21 .15
>SQL*Net more data to client 201 13 .06
>refresh controlfile command 9 13 1.44
>control file sequential read 29 2 .07
>rdbms ipc reply 6 1 .17
>SQL*Net more data from client 1 0 0
>18 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> Rem System wide wait events for background processes (PMON, SMON,
>etc)
>SVRMGR> select n1.event "Event Name",
> 2> n1.event_count "Count",
> 3> n1.time_waited "Total Time",
> 4> round(n1.time_waited/n1.event_count, 2) "Avg Time"
> 5> from stats$bck_event n1
> 6> where n1.event_count > 0
> 7> order by n1.time_waited desc;
>Event Name Count Total Time Avg Time
>-------------------------------- ------------- ------------- -------------
>rdbms ipc message 2519 294103 116.75
>pmon timer 465 139965 301
>smon timer 14 128860 9204.29
>db file parallel write 697 115065 165.09
>log file parallel write 1711 6936 4.05
>direct path read 192 1453 7.57
>control file parallel write 131 322 2.46
>file open 57 131 2.3
>db file sequential read 87 80 .92
>db file scattered read 65 69 1.06
>log file single write 8 48 6
>control file sequential read 130 34 .26
>log file sync 8 29 3.63
>direct path write 192 18 .09
>file identify 8 9 1.13
>log file sequential read 4 9 2.25
>latch free 2 7 3.5
>buffer busy waits 4 5 1.25
>18 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set charwidth 18;
>Charwidth 18
>SVRMGR> set numwidth 11;
>Numwidth 11
>SVRMGR> Rem Latch statistics. Latch contention will show up as a large
>value for
>SVRMGR> Rem the 'latch free' event in the wait events above.
>SVRMGR> Rem Sleeps should be low. The hit_ratio should be high.
>SVRMGR> select name latch_name, gets, misses,
> 2> round((gets-misses)/decode(gets,0,1,gets),3)
> 3> hit_ratio,
> 4> sleeps,
> 5> round(sleeps/decode(misses,0,1,misses),3) "SLEEPS/MISS"
> 6> from stats$latches
> 7> where gets != 0
> 8> order by name;
>LATCH_NAME GETS MISSES HIT_RATIO SLEEPS
>SLEEPS/MISS
>------------------ ----------- ----------- ----------- -----------
>-----------
>Active checkpoint 236 0 1 0
> 0
>Checkpoint queue l 433362 105 1 7
>.067
>Token Manager 908 0 1 0
> 0
>cache buffer handl 77853 3 1 0
> 0
>cache buffers chai 2961227 35 1 0
> 0
>cache buffers lru 312538 607 .998 120
>.198
>dml lock allocatio 343 0 1 0
> 0
>enqueue hash chain 994 0 1 0
> 0
>enqueues 2004 0 1 0
> 0
>file number transl 6 0 1 0
> 0
>ktm global data 38 0 1 0
> 0
>latch wait list 4 0 1 0
> 0
>library cache 199920 30 1 7
>.233
>library cache load 730 0 1 0
> 0
>list of block allo 803 0 1 0
> 0
>messages 8268 1 1 0
> 0
>modify parameter v 64 0 1 0
> 0
>multiblock read ob 13659 0 1 0
> 0
>ncodef allocation 22 0 1 0
> 0
>process allocation 41 0 1 0
> 0
>redo allocation 160020 8 1 2
>.25
>redo writing 3328 0 1 0
> 0
>row cache objects 163786 0 1 0
> 0
>sequence cache 239 0 1 0
> 0
>session allocation 1198 0 1 0
> 0
>session idle bit 169784 0 1 0
> 0
>session switching 22 0 1 0
> 0
>shared pool 11252 2 1 0
> 0
>sort extent pool 15 0 1 0
> 0
>transaction alloca 350 0 1 0
> 0
>undo global data 2987 0 1 0
> 0
>user lock 152 0 1 0
> 0
>32 rows selected.
>SVRMGR>
>SVRMGR> set numwidth 16
>Numwidth 16
>SVRMGR> Rem Statistics on no_wait gets of latches. A no_wait get does not
>SVRMGR> Rem wait for the latch to become free, it immediately times out.
>SVRMGR> select name latch_name,
> 2> immed_gets nowait_gets,
> 3> immed_miss nowait_misses,
> 4> round((immed_gets/immed_gets+immed_miss), 3)
> 5> nowait_hit_ratio
> 6> from stats$latches
> 7> where immed_gets + immed_miss != 0
> 8> order by name;
>LATCH_NAME NOWAIT_GETS NOWAIT_MISSES NOWAIT_HIT_RATIO
>------------------ ---------------- ---------------- ----------------
>Token Manager 44 0 1
>cache buffers chai 578522 35 36
>cache buffers lru 364872 851 852
>i/o slave adaptor 44 0 1
>latch wait list 4 0 1
>library cache 289 0 1
>multiblock read ob 1 0 1
>process allocation 41 0 1
>redo copy 160990 2 3
>row cache objects 44 0 1
>vecio buf des 44 0 1
>11 rows selected.
>SVRMGR>
>SVRMGR> Rem Buffer busy wait statistics. If the value for 'buffer busy
>wait' in
>SVRMGR> Rem the wait event statistics is high, then this table will
>identify
>SVRMGR> Rem which class of blocks is having high contention. If there are
>high
>SVRMGR> Rem 'undo header' waits then add more rollback segments. If there
>are
>SVRMGR> Rem high 'segment header' waits then adding freelists might help.
>Check
>SVRMGR> Rem v$session_wait to get the addresses of the actual blocks having
>SVRMGR> Rem contention.
>SVRMGR> select * from stats$waitstat
> 2> where count != 0
> 3> order by count desc;
>CLASS COUNT TIME
>------------------ ---------------- ----------------
>undo header 8 110
>data block 2 0
>2 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set numwidth 19;
>Numwidth 19
>SVRMGR> Rem Waits_for_trans_tbl high implies you should add rollback
>segments.
>SVRMGR> select * from stats$roll;
>UNDO_SEGMENT TRANS_TBL_GETS TRANS_TBL_WAITS
>UNDO_BYTES_WRITTEN SEGMENT_SIZE_BYTES XACTS
>SHRINKS WRAPS
>------------------- ------------------- -------------------
>------------------- ------------------- -------------------
>------------------- -------------------
> 0 15 0
> 0 442368
>0 0 0
> 2 127 0
>1101906 21282816
>-1 0 1
> 3 87 0
>409518 21282816
>1 0 0
> 4 111 0
>729150 21282816
>1 0 1
> 5 907 5
>13045660 21282816
>1 0 12
>5 rows selected.
>SVRMGR>
>SVRMGR> set charwidth 39
>Charwidth 39
>SVRMGR> Rem The init.ora parameters currently in effect:
>SVRMGR> select name, value from v$parameter where isdefault = 'FALSE'
> 2> order by name;
>NAME VALUE
>---------------------------------------
>---------------------------------------
>background_dump_dest /u01/app/oracle/admin/r1v1/bdump
>control_files /u03/oradata/r1v1/control02.ctl,
>/u04/o
>core_dump_dest /u01/app/oracle/admin/r1v1/cdump
>db_block_buffers 3200
>db_block_size 16384
>db_file_multiblock_read_count 32
>db_files 80
>db_name r1v1
>dml_locks 100
>global_names TRUE
>hash_join_enabled FALSE
>ifile
>/u01/app/oracle/admin/r1v1/pfile/config
>log_buffer 163840
>log_checkpoint_interval 10000
>max_dump_file_size 10240
>nls_date_format MM/DD/YYYY
>processes 50
>rollback_segments r01, r02, r03, r04
>sequence_cache_entries 10
>sequence_cache_hash_buckets 10
>shared_pool_size 6000000
>sort_area_retained_size 10240000
>sort_area_size 10240000
>timed_statistics TRUE
>user_dump_dest /u01/app/oracle/admin/r1v1/udump
>25 rows selected.
>SVRMGR>
>SVRMGR> set charwidth 15;
>Charwidth 15
>SVRMGR> set numwidth 8;
>Numwidth 8
>SVRMGR> Rem get_miss and scan_miss should be very low compared to the
>requests.
>SVRMGR> Rem cur_usage is the number of entries in the cache that are being
>used.
>SVRMGR> select * from stats$dc
> 2> where get_reqs != 0 or scan_reqs != 0 or mod_reqs != 0;
>NAME GET_REQS GET_MISS SCAN_REQ SCAN_MIS MOD_REQS COUNT
>CUR_USAG
>--------------- -------- -------- -------- -------- -------- --------
>--------
>dc_free_extents 59 45 0 0 33 179
>162
>dc_segments 2370 266 0 0 12 302
>297
>dc_rollback_seg 180 0 0 0 0 10
> 7
>dc_used_extents 33 33 0 0 33 88
>76
>dc_tablespace_q 6 1 0 0 6 23
> 1
>dc_users 2185 8 0 0 0 22
>17
>dc_user_grants 1962 11 0 0 0 61
>17
>dc_objects 729 170 0 0 12 341
>340
>dc_synonyms 96 38 0 0 0 45
>43
>dc_usernames 513 4 0 0 0 21
> 9
>dc_object_ids 47328 271 0 0 0 381
>376
>dc_sequences 17 2 0 0 4 8
> 7
>dc_sequence_gra 2 1 0 0 0 2
> 1
>dc_profiles 40 0 0 0 0 7
> 1
>dc_histogram_de 32 9 0 0 0 17
>15
>15 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set charwidth 80;
>Charwidth 80
>SVRMGR> set numwidth 10;
>Numwidth 10
>SVRMGR> Rem Sum IO operations over tablespaces.
>SVRMGR> select
> 2> table_space||' '
> 3> table_space,
> 4> sum(phys_reads) reads, sum(phys_blks_rd) blks_read,
> 5> sum(phys_rd_time) read_time, sum(phys_writes) writes,
> 6> sum(phys_blks_wr) blks_wrt, sum(phys_wrt_tim) write_time,
> 7> sum(megabytes_size) megabytes
> 8> from stats$files
> 9> group by table_space
> 10> order by table_space;
>TABLE_SPACE
> READS BLKS_READ READ_TIME
>WRITES BLKS_WRT WRITE_TIME MEGABYTES
>-------------------------------------------------------------------------------
>---------- ---------- ----------
>---------- ---------- ---------- ----------
>CD_IND
> 1339 39241 65580
>17201 17201 51806314 24116
>CD_IND_2
> 64669 64669 77334
>14956 14956 13623991 14679
>CD_IND_IDX
> 24 24 0
>24 24 0 10486
>CD_IND_IDX_2
> 45396 45396 25869
>12 12 0 5243
>EASTERN
> 98257 98257 20387
>15 15 1610 1049
>EXPERIAN
> 22 392
>17 4 4 0 2097
>EXPERIAN_IDX
> 6 6
>4 4 4 0 1049
>LAPS_DATA
> 4 4
>0 4 4 0 105
>LAPS_IDX
> 4 4
>0 4 4 0 105
>RBS
> 130 130 158
>1072 1072 589239 1573
>ROB_PLAY
> 4 4
>0 4 4 0 315
>SYSTEM
> 15717 42157 1487
>109 109 10886 294
>TEMP
> 20 20 0
>20 20 0 5245
>TOOLS
> 13 13
>7 8 8 0 131
>USERS
> 258 4630 443
>28 28 17002 3147
>15 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set charwidth 48;
>Charwidth 48
>SVRMGR> set numwidth 10;
>Numwidth 10
>SVRMGR> Rem I/O should be spread evenly accross drives. A big difference
>between
>SVRMGR> Rem phys_reads and phys_blks_rd implies table scans are going on.
>SVRMGR> select table_space, file_name,
> 2> phys_reads reads, phys_blks_rd blks_read, phys_rd_time
>read_time,
> 3> phys_writes writes, phys_blks_wr blks_wrt, phys_wrt_tim
>write_time,
> 4> megabytes_size megabytes
> 5> from stats$files order by table_space, file_name;
>TABLE_SPACE FILE_NAME
> READS BLKS_READ READ_TIME
>WRITES BLKS_WRT WRITE_TIME MEGABYTES
>------------------------------
>------------------------------------------------ ---------- ----------
>----------
>---------- ---------- ---------- ----------
>CD_IND /u02/oradata/r1v1/cd_ind_08.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u04/oradata/r1v1/cd_ind_10.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u04/oradata/r1v1/cd_ind_11.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u04/oradata/r1v1/cd_ind_12.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u05/oradata/r1v1/cd_ind_01.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u05/oradata/r1v1/cd_ind_02.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u05/oradata/r1v1/cd_ind_03.dbf
> 406 12804 31338
>7599 7599 2301324 2097
>CD_IND /u05/oradata/r1v1/cd_ind_04.dbf
> 485 14006 11385
>4900 4900 44763984 2097
>CD_IND /u05/oradata/r1v1/cd_ind_05.dbf
> 412 12395 22857
>4666 4666 4741006 2097
>CD_IND /u05/oradata/r1v1/cd_ind_06.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u05/oradata/r1v1/cd_ind_07.dbf
> 4 4
>0 4 4 0 2097
>CD_IND /u05/oradata/r1v1/cd_ind_09.dbf
> 4 4
>0 4 4 0 1049
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_01.dbf
> 9706 9706 12003
>1634 1634 1784743 2097
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_02.dbf
> 9085 9085 11535
>2054 2054 1913222 2097
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_03.dbf
> 12412 12412 16825
>4842 4842 3403695 2097
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_04.dbf
> 5190 5190 6603
>1316 1316 940839 2097
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_05.dbf
> 8871 8871 9728
>1780 1780 1838194 2097
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_06.dbf
> 7701 7701 8876
>1349 1349 1407503 2097
>CD_IND_2 /u06/oradata/r1v1/cd_ind_2_07.dbf
> 11704 11704 11764
>1981 1981 2335795 2097
>CD_IND_IDX /u01/oradata/r1v1/cd_ind_idx_2_04.dbf
> 4 4
>0 4 4 0 1049
>CD_IND_IDX /u03/oradata/r1v1/cd_ind_idx_03.dbf
> 4 4
>0 4 4 0 2097
>CD_IND_IDX /u04/oradata/r1v1/cd_ind_idx_05.dbf
> 4 4
>0 4 4 0 1049
>CD_IND_IDX /u05/oradata/r1v1/cd_ind_idx_01.dbf
> 4 4
>0 4 4 0 2097
>CD_IND_IDX /u05/oradata/r1v1/cd_ind_idx_02.dbf
> 4 4
>0 4 4 0 2097
>CD_IND_IDX /u06/oradata/r1v1/cd_ind_idx_04.dbf
> 4 4
>0 4 4 0 2097
>CD_IND_IDX_2 /u03/oradata/r1v1/cd_ind_idx_2_03.dbf
> 17619 17619
>6862 4 4 0 1049
>CD_IND_IDX_2 /u06/oradata/r1v1/cd_ind_idx_2_01.dbf
> 11660 11660
>8507 4 4 0 2097
>CD_IND_IDX_2 /u06/oradata/r1v1/cd_ind_idx_2_02.dbf
> 16117 16117
>10500 4 4 0 2097
>EASTERN /u05/oradata/r1v1/eastern.dbf
> 98257 98257 20387
>15 15 1610 1049
>EXPERIAN /u03/oradata/r1v1/exp_01.dbf
> 22 392
>17 4 4 0 2097
>EXPERIAN_IDX /u03/oradata/r1v1/exp_idx_01.dbf
> 6 6
>4 4 4 0 1049
>LAPS_DATA /u04/oradata/r1v1/laps_data01.dbf
> 4 4
>0 4 4 0 105
>LAPS_IDX /u04/oradata/r1v1/laps_idx01.dbf
> 4 4
>0 4 4 0 105
>RBS /u02/oradata/r1v1/rbs01.dbf
> 117 117 124
>646 646 522257 524
>RBS /u02/oradata/r1v1/rbs02.dbf
> 13 13 34
>426 426 66982 1049
>ROB_PLAY /u04/oradata/r1v1/rob_14.dbf
> 4 4
>0 4 4 0 315
>SYSTEM /u02/oradata/r1v1/system01.dbf
> 14296 36104 1350
>66 66 8092 84
>SYSTEM /u02/oradata/r1v1/system02.dbf
> 1421 6053 137
>43 43 2794 210
>TEMP /u02/oradata/r1v1/temp01.dbf
> 4 4
>0 4 4 0 1049
>TEMP /u02/oradata/r1v1/temp02.dbf
> 4 4
>0 4 4 0 1049
>TEMP /u02/oradata/r1v1/temp03.dbf
> 4 4
>0 4 4 0 1049
>TEMP /u02/oradata/r1v1/temp04.dbf
> 4 4
>0 4 4 0 1049
>TEMP /u02/oradata/r1v1/temp05.dbf
> 4 4
>0 4 4 0 1049
>TOOLS /u02/oradata/r1v1/tools01.dbf
> 9 9
>7 4 4 0 26
>TOOLS /u02/oradata/r1v1/tools02.dbf
> 4 4
>0 4 4 0 105
>USERS /u02/oradata/r1v1/users01.dbf
> 73 869
>176 8 8 761 1049
>USERS /u03/oradata/r1v1/users02.dbf
> 112 1938 162
>15 15 16232 1049
>USERS /u03/oradata/r1v1/users03.dbf
> 73 1823
>105 5 5 9 1049
>48 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> set charwidth 25
>Charwidth 25
>SVRMGR> Rem The times that bstat and estat were run.
>SVRMGR> select to_char(start_time, 'dd-mon-yy hh24:mi:ss') start_time,
> 2> to_char(end_time, 'dd-mon-yy hh24:mi:ss') end_time
> 3> from stats$dates;
>START_TIME END_TIME
>------------------ ------------------
>02-may-00 14:45:00 02-may-00 15:08:18
>1 row selected.
>SVRMGR>
>SVRMGR> set charwidth 75
>Charwidth 75
>SVRMGR> Rem Versions
>SVRMGR> select * from v$version;
>BANNER
>----------------------------------------------------------------
>Oracle8 Enterprise Edition Release 8.0.4.3.0 - Production
>PL/SQL Release 8.0.4.3.0 - Production
>CORE Version 4.0.4.0.0 - Production
>TNS for Solaris: Version 8.0.4.0.0 - Production
>NLSRTL Version 3.3.1.0.0 - Production
>5 rows selected.
>SVRMGR>
>SVRMGR>
>SVRMGR> spool off;
>
>
>
>Jared Still wrote:
> >
> > Sounds like you are having a time of it.
> >
> > Unfortunately, there isn't enough info
> > here to work with.
> >
> > There are *way* too many questions to ask
> > for me to put it all in an email, maybe someone
> > else has the time right now?
> >
> > Has your DBA run bstat/estat? This would go
> > a long way in helping to discern what the
> > problems might be.
> >
> > There are plenty of folks here that could help
> > you and your DBA to interpret the data from it.
> >
> > Does your DBA know you are asking about this
> > on a mail list?
> >
> > He might not appreciate something he percieves
> > as an end run.
> >
> > Why not mention this list to him, and see if he
> > is aggreable to running bstat/estat and posting
> > the results here for dissection.
> >
> > Jared
> >
> > On Mon, 1 May 2000, R Bresner wrote:
> >
> > > Howdy all,
> > >
> > > I just started work at a leetle place which does data
> > > warehousing, and my current project involves a 40GB database
> > > with some 19.5million rows. So, I'm not surprised when simple
> > > operations take a long, long, (and did I mention LONG?)
> > > time to finish.
> > > But, last week there was a problem with a control file
> > > (did I mention I'm not a DBA, and I'm just parroting
> > > what I heard?) which was causing the Oracle DB writer
> > > process to suck up CPU wildly as it wrote many messages
> > > to an alert file.
> > > And, my simple operations took even longer than normal.
> > > ( Many hours longer. )
> > > I watched the DBA guy fix the problem, and so I could
> > > now be classified as one of those people who only knows half
> > > the story so I assume I know everything, and from what I
> > > know, it still is running slow. The DBA guy says that the
> > > slowness I'm experiencing is back to normal slowness, (did
> > > I mention they're bIG BIG databases?)
> > >
> > > I'd ask for some benchmark comparisons, but I don't know
> > > anything about the Oracle server... Let's just assume its
> > > a VERY good machine, since I heard it was expensive and
> > > relatively new.
> > >
> > > You see, last week when the DB writer was sucking up CPU wildly
> > > everyone panic'd and said "Something must be DONE!" This week,
> > > that same db writer is still sucking up CPU, and now they're
> > > saying, "Oh, that's normal."
> > > They're saying that because there are no new messages in the
> > > alert file.
> > >
> > > I'm asking, is that _REALLY_ normal? I kick off a simple update:
> > > sqlplus @my_update &
> > >
> > > and it appears in my top as taking up between 0.15% and 5.00%, while
> > > the dbwr has it's own CPU to itself, and is churning away at a keen
> > > 33%. ( 3CPUs, ya see ).
> > >
> > > I admit up front, I'm no DBA, and I don't know what I'm mumbling
> > > about. I just want to get out of work earlier, ya see.
> > >
> > > If it matters, we're running Oracle server 8.0.4 on some machine
> > > over in that room there.
> > >
> > > Any explanation would be appreciated.
> > > Thanks
> > > --
> > > Author: R Bresner
> > > INET: wawb_at_escape.net
> > >
> > > Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
> > > San Diego, California -- Public Internet access / Mailing Lists
> > > --------------------------------------------------------------------
> > > To REMOVE yourself from this mailing list, send an E-Mail message
> > > to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
> > > the message BODY, include a line containing: UNSUB ORACLE-L
> > > (or the name of mailing list you want to be removed from). You may
> > > also send the HELP command for other information (like subscribing).
Received on Tue May 02 2000 - 21:08:56 CDT