Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Usenet -> c.d.o.server -> Re: Help: large "cache buffers lru chain", large performace degradation
Hi,
here is a report.
SVRMGR> SVRMGR> SVRMGR> Rem ******************************************************************* SVRMGR> Rem Output statistics SVRMGR> Rem ******************************************************************* SVRMGR> SVRMGR> spool report.txt;
Charwidth 12 SVRMGR> set numwidth 10 Numwidth 10
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 RELOADSINVALIDATI
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
Charwidth 27 SVRMGR> set numwidth 12; Numwidth 12
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"
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 PerSecond
--------------------------- ------------ ------------ ------------ ------------ 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
SVRMGR> SVRMGR> SVRMGR> set numwidth 27 Numwidth 27
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
SVRMGR> SVRMGR> SVRMGR> set charwidth 32; Charwidth 32 SVRMGR> set numwidth 13; Numwidth 13
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 00
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 00
SVRMGR> SVRMGR> SVRMGR> set charwidth 18; Charwidth 18 SVRMGR> set numwidth 11; Numwidth 11
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 SLEEPSSLEEPS/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
Numwidth 16
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 15 rows selected.
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 03 rows selected.
SVRMGR> SVRMGR> SVRMGR> set numwidth 19; Numwidth 19
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
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
Charwidth 15 SVRMGR> set numwidth 8; Numwidth 8
2> where get_reqs != 0 or scan_reqs != 0 or mod_reqs != 0; NAME GET_REQS GET_MISS SCAN_REQ SCAN_MIS MOD_REQS COUNTCUR_USAG
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_WRTWRITE_TIME MEGABYTES
ydias_at_hotmail.com (dias) wrote in message news:<55a68b47.0301112355.18c30a8d_at_posting.google.com>...
> Hi, > > More information are required to address the problem (report from > utlbstat/estat will help). > > I don't think it's a contention problem, but the problem could be the > size of the cache buffer, values of parameters like > DB_BLOCK_LRU_LATCHES, the number of db writers, ... > > Regards > > Dias > > xml_naga_at_yahoo.com (Nagarajan) wrote in message news:<b2ea4548.0301111034.2c6c2ce3_at_posting.google.com>... > > Hello All, > > > > I am running Oracle 7.3.2 on alpha. It runs Oracle Web server and > > there are around 10000 hits per day. All the data is stored in > > the database and the processing of the requests is done through > > pl/sql routines. Lately there is a very severe performance degradation > > during peak usage, checking the v$session event gives the following > > information > > > > large number of total_waits and total_timeouts for the following > > > > latch free (4 - 4259) > > rdbms ipc message (29853 - 94551) > > > > there are many timeouts for db file sequential read but are within > > 12 - 600 > > > > The v$session event table gives the following information > > (the noticable ones) > > > > event total_wait total_timeout > > ----------------- ------------------------------- > > latch free 1192651 1166887 > > rdbms ipc mess 148032 69677 > > buffer busy waits 133389 354 > > free buffer waits 9932 1563 > > > > i noticed that the "latch free" keeps on increasing and the > > timeouts also along with it. The other values dont have > > so many timeouts (less than 1%). > > > > After checking v$latch_children during a test, the > > "cache buffers lru chain" has the highest number of > > misses etc. There are also many "cache buffers chains". > > > > i am trying to find out which table/index is causing the > > contention. for cache buffer chains i can use the addr > > field. how do i find out which one is causing the > > "cache buffers lru chain" contention. I assume that > > this is the key to the performance problem as the > > spin_gets (484253) and sleeps are very huge.. > > > > > > please help me, i have to get the stuff ready by monday. > > > > Nagarajan > > > > here is the complete list, i have truncated the list of cache > > buffer chains so as not to flood ur inboxes > > > > select name, gets, misses, sleeps, immediate_gets, immediate_misses, > > spin_gets, sleep1, sleep2, sleep3 > > from v$latch_children where spin_gets > 0 order by spin_gets desc; > > > > cache buffers lru chain > > 180240447 1049798 671406 192973662 > > 1910294 484253 489808 > > 56810 18927 > > library cache > > 12661385 11555 11847 2665 > > 6 2362 7525 > > 1191 477 > > library cache > > 15074864 11052 12581 2268 > > 3 1785 6931 > > 1679 657 > > library cache > > 13968181 10177 11589 2750 > > 3 1697 6616 > > 1282 582 > > cache buffers chains > > 5039816 3997 5745 108882 > > 479 666 2643 > > 197 491 > > enqueue hash chains > > 2306325 1271 1196 0 > > 0 181 1033 > > 35 22 > > cache buffers chains > > 2837592 335 454 57844 > > 35 116 170 8 > > 41 > > cache buffers chains > > 11146893 438 849 105638 > > 202 114 212 > > 20 92 > > cache buffers chains > > 1622348 402 361 68978 > > 6 66 328 3 > > 5 > > cache buffers chains > > 1592862 446 691 107171 > > 160 60 279 > > 35 72 > > session idle bit > > 4391326 56 2 0 > > 0 54 2 0 > > 0 > > cache buffers chains > > 2094997 571 782 109789 > > 538 53 417 > > 36 65 > > cache buffers chains > > 1818946 449 532 109442 > > 367 50 348 > > 17 34 > > cache buffers chains > > 1638259 347 335 67506 > > 9 50 281 7 > > 9 > > cache buffers chains > > 5775628 209 233 90179 > > 374 42 135 > > 17 15 > > cache buffers chains > > 3188060 182 228 91522 > > 60 42 114 8 > > 18 > > cache buffers chains > > 2653185 354 470 58812 > > 165 38 260 > > 22 34 > > enqueue hash chains 941922 > > 237 344 0 > > 0 28 180 8 > > 21 > > cache buffers chains > > 1551617 419 1145 99846 > > 278 25 192 > > 46 156 > > cache buffers chains > > 1617436 184 308 113526 > > 105 25 103 > > 17 39 > > cache buffers chains > > 2800498 69 47 96765 > > 11 24 44 0 > > 1 > > cache buffers chains > > 3179040 213 757 67610 > > 96 23 75 > > 15 100 > > cache buffers chains > > 1555371 281 932 103544 > > 202 22 111 > > 24 124 > > cache buffers chains > > 2142326 152 268 130211 > > 173 20 80 > > 17 35 > > cache buffers chains > > 2018044 130 187 99380 > > 63 19 86 8 > > 17 > > cache buffers chains > > 2085800 158 200 116984 > > 110 17 113 > > 11 17 > > session idle bit > > 1197386 17 1 0 > > 0 16 1 0 > > 0 > > cache buffers chains 304860 > > 49 82 95018 > > 25 16 18 7 > > 8 > > cache buffers chains > > 1973394 66 69 78858 > > 13 16 42 3 > > 5 > > cache buffers chains 652235 > > 113 158 79930 > > 63 15 74 10 > > 14 > > cache buffers chains 811224 > > 55 61 104705 > > 13 15 32 4 > > 4 > > cache buffers chains > > 2149861 97 213 127421 > > 85 15 56 4 > > 22 > > cache buffers chains 282177 > > 79 187 75056 > > 43 15 31 8 > > 25 > > cache buffers chains 764360 > > 75 128 102809 > > 10 14 43 6 > > 12 > > cache buffers chains 952109 > > 153 364 128074 > > 131 14 79 19 > > 41 > > cache buffers chains 390959 > > 65 89 128312 > > 19 12 37 7 > > 9 > > cache buffers chains 276696 > > 32 25 93251 > > 61 12 16 3 > > 1 > > cache buffers chains > > 1436718 170 485 133018 > > 234 12 64 > > 19 75 > > cache buffers chains 418530 > > 56 143 86907 > > 22 12 21 1 > > 22 > > cache buffers chains 557647 > > 58 60 86454 > > 9 11 39 5 > > 3 > > cache buffers chains 277561 > > 39 53 95364 > > 24 10 22 2 > > 5 > > cache buffers chains 567162 > > 37 41 96044 > > 28 10 20 4 > > 3 > > cache buffers chains 224516 > > 38 39 55662 > > 22 10 21 4 > > 3 > > cache buffers chains 401777 > > 89 176 92838 > > 83 10 40 17 > > 22Received on Sun Jan 12 2003 - 04:42:29 CST