Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Usenet -> c.d.o.server -> last latch ratio (redo copy) and general performance advice
Hi ! With (a lot of) help from others listers, I eliminated many bad performance spots in my db, but I found one very hard to fix, a high redo copy ratio : in 3 gets, 3 misses. And in the last days I was monitoring this, and constantly this ratio was high. What can I do ? OBS : I tried the common medicines : lowering log files size, good number of them, lowering and raising the log_simultaneous_copies (with 2 processors, I tried values of 1, 4, 8 and 16, but no avail), and so the log_small_entry_max_size parameters : today i'm using the defalt of 80, but I tried raise and lower without success. Any ideaas more ?
SVRMGR>
SVRMGR> set charwidth 12
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 76 1 76 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 24 .875 40 .925 0 0 SQL AREA 115955 .286 592757 .72 121 2 TABLE/PROCED 109791 .995 168865 .995 183 0 TRIGGER 268 .996 268 .993 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
--------------------------- ------------ ------------ ------------ ------------ CPU used by this session 308478 56.07 373.01 31.61 CPU used when call started 308475 56.07 373 31.61 CR blocks created 3218 .58 3.89 .33 DBWR buffers scanned 94430 17.16 114.18 9.68 DBWR checkpoints 2 0 0 0 DBWR free buffers found 32092 5.83 38.81 3.29 DBWR lru scans 665 .12
.8 .07
DBWR make free requests 226 .04
.27 .02
DBWR summed scan depth 94430 17.16 114.18 9.68 DBWR timeouts 3226 .59 3.9 .33
OS Involuntary context swit 2407678 437.6 2911.34 246.71 OS Maximum resident set siz 5474604 995.02 6619.84 560.98 OS Page faults 7303 1.33 8.83 .75 OS Page reclaims 173704 31.57 210.04 17.8 OS System time used 9884 1.8 11.95 1.01 OS User time used 191840 34.87 231.97 19.66 OS Voluntary context switch 361172 65.64 436.73 37.01 SQL*Net roundtrips to/from 346851 63.04 419.41 35.54 background checkpoints comp 2 0 0 0 background checkpoints star 2 0 0 0 background timeouts 9715 1.77 11.75 1 bytes received via SQL*Net 37152923 6752.62 44924.94 3807.04 bytes sent via SQL*Net to c 21665202 3937.7 26197.34 2220.02 calls to get snapshot scn: 370139 67.27 447.57 37.93 calls to kcmgas 6066 1.1 7.33 .62 calls to kcmgcs 1205 .22 1.46 .12 calls to kcmgrs 452188 82.19 546.78 46.34 change write time 672 .12
.81 .07
cleanouts and rollbacks - c 179 .03
.22 .02
cleanouts only - consistent 218 .04
.26 .02
cluster key scan block gets 83780 15.23 101.31 8.58 cluster key scans 8802 1.6 10.64 .9 commit cleanout failures: b 1 0 0 0 commit cleanout failures: c 20 0
.02 0
commit cleanout number succ 32901 5.98 39.78 3.37 consistent changes 9996 1.82 12.09 1.02 consistent gets 51996765 9450.52 62873.96 5328.08 cursor authentications 26548 4.83 32.1 2.72 data blocks consistent read 9988 1.82 12.08 1.02 db block changes 299421 54.42 362.06 30.68 db block gets 401703 73.01 485.74 41.16 deferred (CURRENT) block cl 13184 2.4 15.94 1.35 enqueue conversions 1067 .19 1.29 .11 enqueue deadlocks 2 0 0 0 enqueue releases 28906 5.25 34.95 2.96 enqueue requests 28904 5.25 34.95 2.96 enqueue timeouts 2 0 0 0 enqueue waits 305 .06
.37 .03
execute count 384092 69.81 464.44 39.36 free buffer requested 31169 5.67 37.69 3.19 immediate (CR) block cleano 397 .07
.48 .04
immediate (CURRENT) block c 16682 3.03 20.17 1.71 logons cumulative 827 .15 1 .08 logons current 6 0
.01 0
messages received 6062 1.1 7.33 .62 messages sent 6062 1.1 7.33 .62 no work - consistent read g 50925444 9255.81 61578.53 5218.31 opened cursors cumulative 102903 18.7 124.43 10.54 opened cursors current 240 .04
.29 .02
parse count 183356 33.33 221.71 18.79 parse time cpu 33295 6.05 40.26 3.41 parse time elapsed 36609 6.65 44.27 3.75 physical reads 23183 4.21 28.03 2.38 physical writes 7845 1.43 9.49 .8
recursive calls 993899 180.64 1201.81 101.84 recursive cpu usage 51348 9.33 62.09 5.26 redo blocks written 70825 12.87 85.64 7.26 redo buffer allocation retr 2 0 0 0 redo entries 156929 28.52 189.76 16.08 redo log space requests 2 0 0 0 redo log space wait time 53 .01
.06 .01
redo size 34095940 6197.01 41228.46 3493.79 redo small copies 25360 4.61 30.67 2.6 redo synch time 9123 1.66 11.03 .93 redo synch writes 5594 1.02 6.76 .57 redo wastage 971435 176.56 1174.65 99.54 redo write time 8624 1.57 10.43 .88 redo writer latching time 5 0
.01 0
redo writes 6151 1.12 7.44 .63 rollback changes - undo rec 1803 .33 2.18 .18 rollbacks only - consistent 3042 .55 3.68 .31 session connect time 336152878247 61096488.23 406472646.01 34445422.51 session cursor cache count 361 .07
.44 .04
session cursor cache hits 61953 11.26 74.91 6.35 session logical reads 52384491 9520.99 63342.79 5367.81 session pga memory 81045516 14730.19 97999.41 8304.69 session pga memory max 81497760 14812.39 98546.26 8351.04 session uga memory 4445392 807.96 5375.32 455.52 session uga memory max 42050040 7642.68 50846.48 4308.85 sorts (memory) 26381 4.79 31.9 2.7 sorts (rows) 232664 42.29 281.33 23.84 table fetch by rowid 46830622 8511.56 56627.11 4798.71 table fetch continued row 20 0
.02 0
table scan blocks gotten 487963 88.69 590.04 50 table scan rows gotten 1647865 299.5 1992.58 168.86 table scans (long tables) 3 0 0 0 table scans (short tables) 57603 10.47 69.65 5.9 total number commit cleanou 33366 6.06 40.35 3.42 transaction rollbacks 3 0 0 0 user calls 344289 62.58 416.31 35.28 user commits 5502 1 6.65 .56 user rollbacks 87 .02
.11 .01
write requests 1314 .24 1.59 .13
SVRMGR> SVRMGR> SVRMGR> set numwidth 27 Numwidth 27
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 specificlimit
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
0
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 AvgTime
-------------------------------- ------------- ------------- ------------- SQL*Net message from client 349193 5665959 16.23 pipe get 5871 2927176 498.58 dispatcher timer 195 979761 5024.42 virtual circuit status 325 975239 3000.74 enqueue 1112 254545 228.91 log file sync 5566 9099 1.63 SQL*Net more data from client 1230 2652 2.16 db file sequential read 17538 2144
.12
latch free 2449 1523
.62
SQL*Net message to client 349199 430 0 db file scattered read 459 174
.38
log file switch completion 2 53 26.5 SQL*Net break/reset to client 52 16
.31
write complete waits 1 5 5 SQL*Net more data to client 71 3
.04
library cache pin 1 3 3 control file sequential read 70 0 0 buffer busy waits 2 0 0
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 AvgTime
-------------------------------- ------------- ------------- ------------- Null event 28108 3895172 138.58 rdbms ipc message 15190 3813614 251.06 smon timer 33 990010 30000.3 pmon timer 3245 975556 300.63 log file parallel write 6153 8622 1.4 db file parallel write 1314 1013
.77
control file parallel write 62 181 2.92 log file sync 33 62 1.88 db file single write 30 31 1.03 db file scattered read 12 7
.58
rdbms ipc reply 2 7 3.5 db file sequential read 42 4
.1
latch free 20 4
.2
log file single write 4 4 1 control file sequential read 61 0 0 log file sequential read 2 0 0
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((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 228 0 1 0 0 cache buffers chai 104567193 1015 1 40 .039 cache buffers lru 28023 2 1 0 0 dml lock allocatio 41661 0 1 0 0 enqueue hash chain 63211 28 1 137 4.893 enqueues 70673 0 1 0 0 ktm global data 33 0 1 0 0 latch wait list 4023 0 1 0 0 library cache 3222376 2456 .999 1442 .587 library cache load 1588 0 1 0 0 list of block allo 13493 0 1 0 0 messages 48434 5 1 2 .4 modify parameter v 827 1 .999 2 2 multiblock read ob 1076 0 1 0 0 process allocation 827 0 1 0 0 redo allocation 184442 43 1 0 0 redo copy 3 3 0 2 .667 row cache objects 3515598 945 1 258 .273 sequence cache 5473 0 1 0 0 session allocation 23263 4 1 4 1 session idle bit 697974 26 1 4 .154 session switching 156 0 1 0 0 shared pool 1362455 658 1 575 .874 sort extent pool 33 0 1 0 0 system commit numb 587281 36 1 3 .083 transaction alloca 21337 1 1 0 0 undo global data 22591 6 1 0 0 user lock 1680 0 1 0 0 virtual circuit qu 699 0 1 0 0
Numwidth 16
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 ------------------ ---------------- ---------------- ---------------- cache buffers chai 270523 1 2 cache buffers lru 75505 11 12 library cache 447325 133 134 multiblock read ob 1 0 1 process allocation 826 1 2 redo copy 143858 19 20 row cache objects 25215 10 117 rows selected.
SVRMGR> Rem contention. SVRMGR> select * from stats$waitstat 2> where count != 0 3> order by count desc; CLASS COUNT TIME ------------------ ---------------- ---------------- undo block 2 01 row selected.
SVRMGR> SVRMGR> SVRMGR> set numwidth 19; Numwidth 19
------------------- ------------------- ------------------- ------------------- ------------------- ------------------- ------------------- ------------------- 0 42 0 0 241664 0 0 0 1 1480 0 850143 67129344 0 0 0 6 3174 0 5460036 67129344 0 0 0 7 1829 0 1951380 67129344 0 0 0 8 2506 0 1612773 67129344 0 0 0 9 1681 0 972540 67129344 0 0 0 10 1513 0 845216 67129344 0 0 0 11 1468 0 808837 67129344 0 0 0 12 1534 0 841434 67129344 1 0 0 13 1559 0 1139185 67129344 -1 0 0
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;
mts_dispatchers (ADDRESS=(PARTIAL=yes) (PROTOCOL=ipc)),1 mts_listener_address (ADDRESS=(PROTOCOL=ipc)(KEY=prod))
nls_date_format DD-MM-RRRRHH24:MI:SS
rollback_segments rs1, rs2, rs3, rs4, rs5, rs6,rs7, rs8,
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
dc_tablespaces 1805 2 0 0 0 13 4 dc_free_extents 14427 3 2 0 6 475 452 dc_segments 320786 226 0 0 2 1194 1190 dc_rollback_seg 990 0 0 0 0 18 16 dc_used_extents 2 2 0 0 2 188 186 dc_tablespace_q 2 1 0 0 2 9 2 dc_users 18185 3 0 0 0 20 19 dc_user_grants 7418 3 0 0 0 48 17 dc_objects 105792 468 0 0 0 2902 2899 dc_tables 144849 8 0 0 0 1121 1109 dc_columns 10041371 105 221077 8 0 10812 10806 dc_table_grants 8009 305 0 0 0 8956 8936 dc_indexes 223225 260 101922 226 0 911 888 dc_constraint_d 58502 1054 8229 124 0 1131 1127 dc_constraint_d 3 1 2639 100 0 3 2 dc_synonyms 1791 134 0 0 0 213 202 dc_usernames 3234 3 0 0 0 20 12 dc_object_ids 222885 270 0 0 0 391 384 dc_sequences 154 7 0 0 111 14 8 dc_sequence_gra 19 14 0 0 0 123 14 dc_tablespaces 2 1 0 0 2 9 3 dc_profiles 827 0 0 0 0 3 1 dc_histogram_de 19 19 0 0 0 109 94
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
sys_at_prod::SQL>select * from v$log order by sequence#;
GROUP# THREAD# SEQUENCE# BYTES MEMBERS ARC STATUS
3 1 2685 15728640 1 NO INACTIVE 6442918 08/23/00 21:41:35 4 1 2686 15728640 1 NO INACTIVE 6443052 08/23/00 21:48:07 5 1 2687 15728640 1 NO INACTIVE 6445061 08/24/00 10:15:35 6 1 2688 15728640 1 NO INACTIVE 6446444 08/24/00 10:48:38 7 1 2689 15728640 1 NO INACTIVE 6448767 08/24/00 12:05:20 1 1 2690 15728640 1 NO CURRENT GROUP# THREAD# SEQUENCE# BYTES MEMBERS ARC STATUS
7 rows selected.
Machine Environment:
F50 Risc/6000 AIX 4.3.3 2 Risc processors User: uid=201(oracle) gid=201(dba) Current Directory: /oracle/soft/dba_scripts Machine: {
AIX bbvrs03 3 4 006077104C00 [From uname -a] bbvrs03 [From hostname]
time(seconds) unlimited file(blocks) 4194303 data(kbytes) 131072 stack(kbytes) 32768 memory(kbytes) 32768 coredump(blocks) 4194303 nofiles(descriptors) 2000
kthr memory page faults cpu
PATH=/usr/bin:/etc:/usr/sbin:/usr/ucb::/usr/local/bin:/oracle/soft/bin:/ usr/bin/X11:/sbin:.:/usr/lbin:/oracle/soft/bin
PS1=$ORACLE_SID:$PWD> PWD=/oracle/soft/dba_scripts SHELL=/bin/ksh TERM=vt100 TZ=GRNLNDST3 USER=oracle _=/usr/bin/env
IPC status from /dev/mem as of Wed Aug 23 10:08:48 GRNLNDST 2000 T ID KEY MODE OWNER GROUP CREATOR CGROUP NSEMS OTIME CTIME Semaphores: s 524288 0x580520ba --ra-ra-ra- root system root system 1 14:14:55 14:14:55 s 262145 0x440520ba --ra-ra-ra- root system root system 2 14:14:55 14:14:55 s 131074 00000000 --ra-ra-ra- imnadm imnadm imnadm imnadm 4 no-entry 21:13:34 s 3 0x6205291a --ra-r--r-- root system root system 1 21:12:51 21:12:51 s 4 00000000 --ra-ra-ra- imnadm imnadm imnadm imnadm 1 no-entry 21:13:34 s 5 00000000 --ra-ra-ra- imnadm imnadm imnadm imnadm 40 no-entry 21:13:34 s 6 00000000 --ra-ra-ra- imnadm imnadm imnadm imnadm 4 no-entry 21:13:34 s 7 0x450410df --ra-ra-ra- imnadm imnadm imnadm imnadm 2 21:13:40 21:13:38 s 8 00000000 --ra-ra-ra- imnadm imnadm imnadm imnadm 2 21:13:40 21:13:38 s 9 00000000 --ra-ra-ra- imnadm imnadm imnadm imnadm 2 no-entry 21:13:38 s 10 0x01052899 --ra------- root system root system 1 9:15:41 21:23:07 s 11 0x0101c6e8 --ra-ra-ra- root dba root dba 1 10:06:52 10:06:50 [From ipcs -sa]
}
Shared Mem: {
IPC status from /dev/mem as of Wed Aug 23 10:08:48 GRNLNDST 2000 T ID KEY MODE OWNER GROUP CREATOR CGROUP NATTCH SEGSZ CPID LPID ATIME DTIME CTIME Shared Memory: m 262144 0x580520ba --rw-rw-rw- root system root system 1 134217728 3704 3704 14:14:55 no-entry 14:14:55 m 1 0x470410d9 --rw-r--r-- imnadm imnadm imnadm imnadm 0 48 12644 12644 21:13:34 21:13:34 21:13:34 m 2 0x580410d9 --rw-r--r-- imnadm imnadm imnadm imnadm 0 4096 12644 12644 21:13:34 21:13:34 21:13:34 m 3 0x4d0410d9 --rw-r--r-- imnadm imnadm imnadm imnadm 0 4096 12644 12644 21:13:34 21:13:34 21:13:34 m 4 0x490410d9 --rw-r--r-- imnadm imnadm imnadm imnadm 0 4096 12644 12644 21:13:34 21:13:34 21:13:34 m 5 0x500410d9 --rw-r--r-- imnadm imnadm imnadm imnadm 0 3222 12644 12644 21:13:34 21:13:34 21:13:34 m 6 0x450410df --rw-rw-rw- imnadm imnadm imnadm imnadm 1 96 13416 13416 21:13:39 21:13:40 21:13:38 m 7 0x430410df --rw-rw-rw- imnadm imnadm imnadm imnadm 1 97708 13416 13416 21:13:39 21:13:40 21:13:38 m 8 0x420410df --rw-rw-rw- imnadm imnadm imnadm imnadm 1 36028 13416 13416 21:13:39 21:13:40 21:13:38 m 9 0x410410df --rw-rw-rw- imnadm imnadm imnadm imnadm 1 42148 13416 13416 21:13:39 21:13:40 21:13:38 m 10 0x440410df --rw-rw-rw- imnadm imnadm imnadm imnadm 1 2844 13416 13416 21:13:39 21:13:40 21:13:38 m 262155 0x0827c4a3 --rw-r----- oracle dba oracle dba 24 305647616 31418 25010 10:08:48 10:08:48 8:05:48 m 12 0x0d052a07 --rw-rw-rw- root system root system 4 1440 13438 36484 9:15:37 9:15:38 21:22:00 [From ipcs -ma]
}
/etc/oratab: {
prod:/oracle/soft:Y
}
Tracing: { dbx adb trace crash }
Sent via Deja.com http://www.deja.com/
Before you buy.
Received on Thu Aug 24 2000 - 13:13:27 CDT