Home » RDBMS Server » Server Administration » help: large "cache buffers lru chain" misses, performance badly affected
| help: large "cache buffers lru chain" misses, performance badly affected [message #55223] |
Sun, 12 January 2003 04:27  |
Gunaseelan Nagarajan
Messages: 2
Registered: January 2003
|
Junior Member |
|
|
hi,
i am having a very huge number of latch free waits
and timeouts, the ratio is 1:1 in the v$system_event.
exploring further i got many rows like this..
sid: 155
seq#: 1388
event: latch free
p1text: address
p1: 14790640
...
there is a huge number of "latch frees" with almost
equal number of "buffer busy waits". Then in v$latch_children the maximum misses and "spins" were for "cache buffers lru chain". I am assuming that this is the bottleneck and is the key to solve the problem. but i dont know how to interpret the "addr" column.
here is a report when the system was fully used..
please help,
Nagarjan.
SVRMGR>
SVRMGR>
SVRMGR> Rem *******************************************************************
SVRMGR> Rem Output statistics
SVRMGR> Rem *******************************************************************
SVRMGR>
SVRMGR> spool report.txt;
MGR-03512: spool file "report_jan_10_13_02.txt" is already open
SVRMGR>
SVRMGR> set charwidth 12
Charwidth 12
SVRMGR> set numwidth 10
Numwidth 10
SVRMGR> Rem Select Library cache statistics. The pin hit rate shoule 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 6333 1 6333 1 0 0
CLUSTER 0 1 0 1 0 0
INDEX 0 1 0 1 0 0
OBJECT 0 1 0 1 0 0
PIPE 0 1 0 1 0 0
SQL AREA 2200 .946 27394 .991 9 3 *** muss 0 sein ****
TABLE/PROCED 1482 .998 17949 1 0 0
TRIGGER 97 1 97 1 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
--------------------------- ------------ ------------ ------------ ------------
CR blocks created 211 .1 .49 1.44
Current blocks converted fo 17 .01 .04 .12
DBWR buffers scanned 900363 430.38 2084.17 6124.92
DBWR free buffers found 898630 429.56 2080.16 6113.13
DBWR lru scans 573 .27 1.33 3.9
DBWR make free requests 573 .27 1.33 3.9
DBWR summed scan depth 900363 430.38 2084.17 6124.92
OS Block input operations 1014 .48 2.35 6.9
OS Block output operations 1190 .57 2.75 8.1
OS Integral unshared data s 175361 83.82 405.93 1192.93
OS Integral unshared stack 1654 .79 3.83 11.25
OS Involuntary context swit 28648 13.69 66.31 194.88
OS Maximum resident set siz 653752 312.5 1513.31 4447.29
OS Page faults 145 .07 .34 .99
OS Page reclaims 64784 30.97 149.96 440.71
OS System time used 1128 .54 2.61 7.67
OS User time used 10087 4.82 23.35 68.62
OS Voluntary context switch 22015 10.52 50.96 149.76
SQL*Net roundtrips to/from 7367 3.52 17.05 50.12
background timeouts 144 .07 .33 .98
bytes received via SQL*Net 2197996 1050.67 5087.95 14952.35
bytes sent via SQL*Net to c 10254116 4901.59 23736.38 69755.89
calls to get snapshot scn: 14676 7.02 33.97 99.84
calls to kcmgas 2162 1.03 5 14.71
calls to kcmgcs 78 .04 .18 .53
calls to kcmgrs 20029 9.57 46.36 136.25
cleanouts and rollbacks - c 54 .03 .13 .37
cleanouts only - consistent 29 .01 .07 .2
cluster key scan block gets 288 .14 .67 1.96
cluster key scans 12 .01 .03 .08
commit cleanout failures: c 1 0 0 .01
commit cleanout number succ 3906 1.87 9.04 26.57
consistent changes 285 .14 .66 1.94
consistent gets 19564665 9352.13 45288.58 133092.96
cursor authentications 3123 1.49 7.23 21.24
data blocks consistent read 285 .14 .66 1.94
db block changes 18592 8.89 43.04 126.48
db block gets 29567 14.13 68.44 201.14
deferred (CURRENT) block cl 852 .41 1.97 5.8
dirty buffers inspected 1 0 0 .01
enqueue releases 4607 2.2 10.66 31.34 ** high enqueue **
enqueue requests 4603 2.2 10.66 31.31
enqueue waits 3 0 .01 .02
execute count 14381 6.87 33.29 97.83
free buffer inspected 69649 33.29 161.22 473.8 **** free buffers not found immediately***
free buffer requested 756690 361.71 1751.6 5147.55
immediate (CR) block cleano 83 .04 .19 .56
immediate (CURRENT) block c 1254 .6 2.9 8.53
logons cumulative 432 .21 1 2.94
logons current 6 0 .01 .04
messages received 1252 .6 2.9 8.52
messages sent 1252 .6 2.9 8.52
no work - consistent read g 17955920 8583.14 41564.63 122149.12
opened cursors cumulative 5894 2.82 13.64 40.1
opened cursors current 50 .02 .12 .34
parse count 5907 2.82 13.67 40.18
physical reads 756064 361.41 1750.15 5143.29
physical writes 1734 .83 4.01 11.8
recursive calls 106624 50.97 246.81 725.33 ** ok for pl/sql databases? **
redo blocks written 2306 1.1 5.34 15.69
redo entries 9861 4.71 22.83 67.08
redo size 1836232 877.74 4250.54 12491.37
redo small copies 9861 4.71 22.83 67.08 ** should be less than 10% of entries? **
redo synch writes 271 .13 .63 1.84
redo wastage 471967 225.61 1092.52 3210.66
redo writes 980 .47 2.27 6.67
rollbacks only - consistent 176 .08 .41 1.2
session logical reads 19592602 9365.49 45353.25 133283.01
session pga memory 345673816 165236.05 800170.87 2351522.56
session pga memory max 384138656 183622.68 889209.85 2613188.14
session uga memory -6899968 -3298.26 -15972.15 -46938.56
session uga memory max 189067616 90376.49 437656.52 1286174.26
sorts (memory) 1013 .48 2.34 6.89
sorts (rows) 1364824 652.4 3159.31 9284.52
summed dirty queue length 2 0 0 .01
table fetch by rowid 8598813 4110.33 19904.66 58495.33
table fetch continued row 72122 34.48 166.95 490.63 ** row chaining ***
table scan blocks gotten 1370227 654.98 3171.82 9321.27
table scan rows gotten 9252489 4422.8 21417.8 62942.1
table scans (long tables) 266 .13 .62 1.81
table scans (short tables) 1072 .51 2.48 7.29
total number commit cleanou 3953 1.89 9.15 26.89
user calls 6505 3.11 15.06 44.25
user commits 2092 1 4.84 14.23
write requests 264 .13 .61 1.8
85 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 the db_block_write_batch init.ora parameter,
SVRMGR> Rem then consider increasing the value of db_block_write_batch and
SVRMGR> Rem 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
---------------------------
.00757575757575757575757576
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 break/reset to client 28 0 0
SQL*Net message from client 8723 0 0
SQL*Net message to client 8736 0 0
SQL*Net more data from client 23 0 0
SQL*Net more data to client 4005 0 0
buffer busy waits 293 0 0
control file sequential read 19 0 0
db file scattered read 37666 0 0
db file sequential read 317893 0 0
enqueue 3 0 0
latch free 21540 0 0
log file sync 164 0 0
write complete waits 2 0 0
13 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
-------------------------------- ------------- ------------- -------------
db file parallel write 268 0 0
db file scattered read 4 0 0
db file sequential read 6 0 0
latch free 217 0 0
log file parallel write 993 0 0
pmon timer 122 0 0
rdbms ipc message 1038 0 0
smon timer 1 0 0
8 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(decode(gets-misses,0,1,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
------------------ ----------- ----------- ----------- ----------- -----------
cache buffer handl 6 0 1 0 0
cache buffers chai 38265564 5383 1 11659 2.166
cache buffers lru 756326 9726 .987 9569 .984
dml lock allocatio 4778 0 1 0 0
enqueue hash chain 9193 0 1 0 0
enqueues 10498 0 1 0 0
ktm global data 1 0 1 0 0
latch wait list 390 0 1 0 0
library cache 221237 181 .999 225 1.243
library cache load 2 0 1 0 0
list of block allo 4326 0 1 0 0
messages 5795 1 1 1 1
modify parameter v 432 1 .998 3 3
multiblock read ob 114549 43 1 59 1.372
process allocation 432 0 1 0 0
redo allocation 12515 21 .998 69 3.286
row cache objects 32434 1 1 1 1
sequence cache 1329 0 1 0 0
session allocation 3891 0 1 0 0
session idle bit 14078 0 1 0 0
session switching 40 0 1 0 0
shared pool 11786 15 .999 27 1.8
sort extent pool 1 0 1 0 0
system commit numb 23942 1 1 0 0
transaction alloca 6851 0 1 0 0
undo global data 6768 0 1 0 0
user lock 1696 0 1 0 0
27 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(decode(immed_gets-immed_miss,0,1,immed_gets-immed_miss)/
5> decode(immed_gets,0,1,immed_gets),
6> 3)
7> nowait_hit_ratio
8> from stats$latches
9> where immed_gets != 0
10> order by name;
LATCH_NAME NOWAIT_GETS NOWAIT_MISSES NOWAIT_HIT_RATIO
------------------ ---------------- ---------------- ----------------
cache buffers chai 1199177 70261 .941
cache buffers lru 861164 109334 .873
library cache 99 1 .99
process allocation 432 0 1
row cache objects 17 0 1
5 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
------------------ ---------------- ----------------
data block 291 0
segment header 1 0
undo header 1 0
3 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 2 0 0 202752 0 0 0
2 1234 0 151087 16105472 0 0 1
3 1210 0 252185 16105472 0 0 2
4 1144 0 243093 16103424 -1 0 2
5 1097 0 142476 16103424 0 0 2
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
--------------------------------------- ---------------------------------------
always_anti_join NESTED_LOOPS
audit_trail NONE
background_dump_dest /oracle/app/oracle/admin/IBOnline/bdump
cache_size_threshold 1638
checkpoint_process TRUE
compatible 7.2.0.0
control_files /oracle/oradata/IBOnline/control01.ctl,
core_dump_dest /oracle/app/oracle/admin/IBOnline/cdump
cpu_count 2
db_block_buffers 16384
db_block_lru_latches 1
db_block_size 2048
db_file_multiblock_read_count 20
db_files 200
db_name IBOnline
distributed_transactions 80
dml_locks 400
enqueue_resources 617
gc_db_locks 16384
gc_freelist_groups 50
gc_releasable_locks 16384
ifile /oracle/app/oracle/admin/IBOnline/pfile
log_buffer 2560000
log_checkpoint_interval 3000000000
log_simultaneous_copies 0
max_dump_file_size 10240
mts_max_dispatchers 0
mts_max_servers 0
mts_servers 0
mts_service IBOnline
optimizer_mode CHOOSE
processes 260
remote_login_passwordfile NONE
rollback_segments r01, r02, r03, r04
sequence_cache_entries 100
sequence_cache_hash_buckets 54
sessions 291
shared_pool_size 512000000
sort_area_retained_size 2048000
sort_area_size 2048000
sort_direct_writes AUTO
spin_count 32
temporary_table_locks 291
transactions 320
transactions_per_rollback_segment 16
user_dump_dest /oracle/app/oracle/admin/IBOnline/udump
46 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 262 1 0 0 2 304 264
dc_segments 1145 0 0 0 0 1003 1001
dc_rollback_seg 12 0 0 0 0 8 7
dc_users 3924 0 0 0 0 15 12
dc_user_grants 2604 0 0 0 0 42 8
dc_objects 924 0 0 0 0 992 991
dc_tables 1294 0 0 0 0 578 577
dc_columns 7374 0 926 0 0 4378 4362
dc_table_grants 43 0 0 0 0 3277 3261
dc_indexes 713 0 450 0 0 609 593
dc_constraint_d 1 0 13 0 0 453 447
dc_constraint_d 0 0 1 0 0 86 72
dc_synonyms 29 0 0 0 0 55 53
dc_usernames 911 0 0 0 0 12 11
dc_object_ids 1311 0 0 0 0 609 607
dc_sequences 25 0 0 0 25 25 17
dc_histogram_de 152 0 0 0 0 132 127
17 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
------------------------------------------------------------------------------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
INDICES 5785 5785 0 171 171 0 1611
INDICES2 75467 75466 0 23 23 0 944
INDICESJAN8 676 676 0 150 150 0 629
INDICESJAN9 6440 6440 0 221 221 0 944
RBS 26 26 0 472 472 0 702
REPOSITORY 0 0 0 0 0 0 41
SYSTEM *** full table scan **** 93417 319660 0 601 601 0 1007
TEMP 0 0 0 0 0 0 68
TOOLS 0 0 0 0 0 0 16
USERS *** full table scan **** 174784 354857 0 106 106 0 1887
UTLSTAT 0 0 0 0 0 0 5
11 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
------------------------------ ------------------------------------------------ ---------- ---------- ---------- ---------- ---------- ---------- ----------
INDICES /oracle/oradata/IBOnline/indices.dbf 5785 5785 0 171 171 0 1611
INDICES2 /oracle/oradata/IBOnline/indices2.dbf 75467 75466 0 23 23 0 944
INDICESJAN8 /oracle/oradata/IBOnline/indicesJan8.dbf 676 676 0 150 150 0 629
INDICESJAN9 /oracle/oradata/IBOnline/indicesJan9.dbf 6440 6440 0 221 221 0 944
RBS /oracle/oradata/IBOnline/RBSJan.dbf 0 0 0 0 0 0 629
RBS /oracle/oradata/IBOnline/rbs01.dbf 26 26 0 472 472 0 73
REPOSITORY /oracle/oradata/IBOnline/rep01.dbf 0 0 0 0 0 0 41
SYSTEM /oracle/oradata/IBOnline/system01.dbf 3.4 ratio 93417 319660 0 601 601 0 1007
TEMP /oracle/oradata/IBOnline/temp01.dbf 0 0 0 0 0 0 68
TOOLS /oracle/oradata/IBOnline/tools01.dbf 0 0 0 0 0 0 16
USERS /oracle/oradata/IBOnline/users01.dbf 2.0 ratio 174784 354857 0 106 106 0 1887
UTLSTAT /oracle/oradata/IBOnline/tsUTL.dbf 0 0 0 0 0 0 5
12 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
------------------------- -------------------------
10-jan-03 13:08:28 10-jan-03 13:10:55
1 row selected.
SVRMGR>
SVRMGR> set charwidth 75
Charwidth 75
SVRMGR> Rem Versions
SVRMGR> select * from v$version;
BANNER
----------------------------------------------------------------
Oracle7 Server Release 7.3.2.3.0 with the 64-bit option - Produc
PL/SQL Release 2.3.2.3.0 - Production
CORE Version 3.5.2.0.0 - Production
TNS for DEC OSF/1 AXP: Version 2.3.2.1.0 - Production
NLSRTL Version 3.2.2.0.0 - Production
5 rows selected.
SVRMGR>
SVRMGR>
SVRMGR> spool off;
|
|
|
|
|
|
Goto Forum:
Current Time: Sat Dec 28 07:56:39 CST 2024
|
] 
Blog
Search
Help
Members
Register
Login
Home
