Transcript Document
IO Waits Kyle Hailey [email protected] http://perfvision.com/ftp/sb #.2 Waits Covered in this Section 1. 2. 3. 4. 5. 6. 7. 8. 9. 10. 11. 12. 13. 14. db file sequential read db file scattered read db file parallel read read by other session direct path read direct path write direct path read temp direct path write temp direct path write (lob) file open file identify Local write wait data file init write sort segment request Copyright 2006 Kyle Hailey Standard I/O Direct I/O Special Cases #.3 Buffer Cache Locks REDO Lib Cache Buffer Cache Network I/O Copyright 2006 Kyle Hailey IO Waits SGA Log Library Buffer Cache Buffer Cache DBWR User1 Data Files Copyright 2006 Kyle Hailey #.4 #.5 Standard Table/Index IO 1. db file sequential read Single block read 2. db file scattered read Multi block read 3. db file parallel read Non-contiguous multi block read 4. read by other session Wait for another session to do the io Copyright 2006 Kyle Hailey db file sequential read Buffer Cache #.6 The top wait Single Block Read Data via Index and/or Rowid Rollback Select * from emp where empno = 9999; Index on emp.empno Shadow Process 1) 2) 3) Search Buffer Cache for the block by rowid Fails Reads of disk • File • Block Copyright 2006 Kyle Hailey Note: “sequential” means A sequence like a rowid db file scattered read Multi Block Read Buffer Cache Full Table Scan Index Fast Full Scans SQL> select * from all_objects; Shadow Process 1) 2) 3) Search Buffer Cache for the blocks Fails Reads off disk • File • Block • Multi Block Read Count Copyright 2006 Kyle Hailey Note: Scattered Means Blocks are read and scattered throughout buffer cache #.7 db file parallel read Buffer Cache Shadow Process Process issues multiple single block reads in parallel Documentation says only for recovery But seems to happen for normal read ops Async Call – wait for all reads to complete Examples Not contiguous multi block read Index full or range scan Where values in Select * from emp where Empno in (1,2,3,4,5,6); 1) Search Buffer Cache for the blocks 2) Fails 3) Reads that block off Disk Copyright 2006 Kyle Hailey #.8 Read by other Session Buffer Cache Multiple sessions reading the same data that requires IO Ex) to users doing a full table scan at the same time S1 S2 1. 2. 3. 4. Block not found in cache Read block from disk Found other session already reading block from disk Wait for the other session to finish IO Copyright 2006 Kyle Hailey #.9 #.10 Db file Sequential Read: Statspack Top 5 Timed Events ~~~~~~~~~~~~~~~~~~ % Total Event Waits Time (s) Ela Time ------------------------ ------------ ----------- -------db file scattered read 7,549 5 52.26 CPU time 2 23.29 db file sequential read 884 2 19.11 control file sequential read 154 0 2.68 control file parallel write 255 0 1.87 What SQL ? What Object ? Copyright 2006 Kyle Hailey Db file sequential read Copyright 2006 Kyle Hailey #.11 db file scattered Read Copyright 2006 Kyle Hailey #.12 Read by other session Copyright 2006 Kyle Hailey #.13 IO – Further Investigation select parameter1, parameter2, parameter3 from v$event_name NAME ----------------------read by other session db file sequential read db file scattered read direct path read direct path read temp direct path write direct path write temp db file parallel read P1 ----------file# file# file# file number file number file number file number files P2 --------block# block# block# first dba first dba first dba first dba blocks P3 -------class# blocks blocks block cnt block cnt block cnt block cnt requests P1 and P2 are the same, file# , block# We can use P1, P2, P3 from ASH to get more info Exception: db file parallel read – p1,p2,p3 not useful Copyright 2006 Kyle Hailey #.14 ASH – sequential reads select event, ash.p3, o.object_name objn, o.object_type otype, CURRENT_FILE# filen, CURRENT_BLOCK# blockn, ash.SQL_ID from v$active_session_history ash, all_objects o where event like 'db file sequential read' and o.object_id (+)= ash.CURRENT_OBJ# order by sample_time; EVENT P3 OBJN OTYPE FILEN BLOCKN SQL_ID ----------------------- -- ------------------------- ----- ----- ------ ------------db file sequential read 1 49890 MGMT_METRICS_1HOUR_ INDEX 3 41737 db file sequential read 1 50908 MGMT_DB_SGA_ECM TABLE 3 28489 35at43xqj7bs0 db file sequential read 1 55303 TOTO TABLE 1 60218 7xftj55rvjw9s Copyright 2006 Kyle Hailey #.15 ASH – scattered reads select event, ash.p3, o.object_name objn, o.object_type otype, CURRENT_FILE# filen, CURRENT_BLOCK# blockn, ash.SQL_ID from v$active_session_history ash, all_objects o where event like 'db file scattered read' and o.object_id (+)= ash.CURRENT_OBJ# order by sample_time; EVENT P3 OBJN OTYPE FILEN BLOCKN SQL_ID ---------------------- -- ------------------------- ----- ----- ------ ------------db file scattered read 8 9078 WRH$_SYSMETRIC_HISTO TABLE 3 52363 db file scattered read 5 8781 WRI$_ALERT_HISTORY TABLE 3 2676 db file scattered read 8 57 OBJAUTH$ TABLE 1 33993 3t2mk1prj24hu Copyright 2006 Kyle Hailey #.16 IO by TBS & File #.17 select io.cnt, round(io.cnt/(&v_minutes*60),2) aas, io.event, io.p1 p1, f.tablespace_name from ( select count(*) cnt, substr(event,0,25) event, ash.p1 p1 from v$active_session_history ash where ( event like 'db file s%' or event like 'direct%' ) and sample_time > sysdate - &v_minutes/(60*24) group by event , CNT AAS EVENT P1 TABLESPACE ash.p1 ---- --- ----------------------- --- ---------) io, 1 .00 db file sequential read 1 SYSTEM dba_data_files f 2 .00 db file sequential read 3 SYSAUX where 38 .06 db file sequential read 6 SOE 179 .30 db file sequential read 7 SOEINDEX f.file_id = io.p1 Order by io.cnt ; IO by Object #.18 select count(*) cnt, CURRENT_OBJ#||' '||o.object_name objn, o.object_type otype from v$active_session_history ash, all_objects o where ( event like 'db file s%' or event like 'direct%' ) and o.object_id (+)= ash.CURRENT_OBJ# and sample_time > sysdate - &1/(60*24) and session_state='WAITING' group by CURRENT_OBJ#, o.object_name , o.object_type Order by count(*) CNT AAS OBJN OTYPE ---- ------- ------------------------- --------------79 .00 52949 ORDER_ITEMS TABLE PARTITION 97 .00 -1 130 .00 53117 ORD_STATUS_IX INDEX 498 .01 53120 CUST_EMAIL_IX INDEX 512 .01 0 1632 .03 53112 ITEM_ORDER_IX INDEX IO by Object/tbs/wait Select io.cnt cnt, io.aas aas, io.event event, substr(io.obj,1,20) obj, io.p1 p1, f.tablespace_name tablespace_name from ( select count(*) cnt, round(count(*)/(&v_minutes*60),2) aas, substr(event,0,15) event, obj, P1 CNT AASnvl(o.object_name,decode(CURRENT_OBJ#,-1,0,CURRENT_OBJ#)) EVENT OBJ --- ---ash.p1, --------------- ----------------- --otypesequent ORDER_ITEMS_PK 1 .02o.object_type db file 7 from v$active_session_history ash, 1 .02 db file sequent 0 3 o 2 .03 all_objects db file scatter WAIT_OBJECTS 1 where db ( event like 'db file s%' or event like 'direct%' ) 2 .03 file sequent ORDER_ITEMS 6 and o.object_id (+)= ash.CURRENT_OBJ# 3 .05 db file sequent CUST_EMAIL_IX 7 and sample_time > sysdate &v_minutes/(60*24) 4 .07 db file sequent CUST_LNAME_IX 7 group by 6 .10 db file sequent ORD_ORDER_DATE_IX 7 substr(event,0,15) 13 .22 db file , sequent ITEM_ORDER_IX 7 CURRENT_OBJ#, o.object_name , 25 .42 db file sequent 0 2 o.object_type , ash.p1 ) io, dba_data_files f where f.file_id = io.p1 Order by io.cnt; #.19 TABLESPACE_NAME --------------SOEINDEX SYSAUX SYSTEM SOE SOEINDEX SOEINDEX SOEINDEX SOEINDEX UNDOTBS1 IO by SQL select sum(cnt) over ( partition by io.sql_id order by sql_id ) tcnt, io.sql_id, io.cnt cnt, io.aas aas, io.objn objn, io.obj obj, io.p1 p1, f.tablespace_name tablespace_name from ( select sql_id, count(*) cnt, round(count(*)/(&v_minutes*60),2) aas, CURRENT_OBJ# objn, nvl(o.object_name,decode(CURRENT_OBJ#,-1,0,CURRENT_OBJ#)) obj, o.object_type otype, ash.p1 from v$active_session_history ash ,all_objects o where ( event like 'db file s%' or event like 'direct%' ) and o.object_id (+)= ash.CURRENT_OBJ# and sample_time > sysdate - &v_minutes/(60*24) group by CURRENT_OBJ#, o.object_name , o.object_type , ash.p1, sql_id ) io, dba_data_files f where f.file_id = io.p1 Order by tcnt, io.sql_id, io.cnt TCNT SQL_ID CNT AAS OBJN ---- ------------- --- --- ----30 0yas01u2p9ch4 1 .01 53113 1 .01 53079 28 .16 53112 58 6v6gm0fd1rgrz 4 .02 54533 54 .30 0 OBJ P1 TABLESPAC --------------- -- --------ITEM_PRODUCT_IX 7 SOEINDEX ORDER_ITEMS_UK 7 SOEINDEX ITEM_ORDER_IX 7 SOEINDEX WAIT_OBJECTS 1 SYSTEM 0 2 UNDOTBS1 #.20 Missing Object IDs dba_extents – get object name select segment_name, segment_type from dba_extents where file_id = P1 and P2 between block_id and block_id + blocks – 1; Dba_extents is notoriously slow Options Create a table as select – use table recreate as object extents change Catch blocks in x$bh when waits occur Copyright 2006 Kyle Hailey #.21 Copy of dba_extents Enter value for file: 3 Enter value for block: 6619 OWNER SEGMENT_NAME SEGMENT_TYPE --------------- -------------------- -----------------WMSYS LOG_TAB_PK INDEX Elapsed: 00:00:41.25 create table myextents as select * from dba_extents Table created. Elapsed: 00:01:25.73 CNT OWN --- ---11 SYS 993 SYS 150 rows SEGMENT_NAME SEGMENT_TYPE ---------------- -----------SMON_SCN_TO_TIME CLUSTER _SYSSMU7$ TYPE2 UNDO selected. Elapsed: 00:00:01.03 #.22 #.23 IO Solutions 1. Check average read times per file Should be between 5-20 ms Data in Statspack under “File IO Stats” 2. Check Cache buffer Hit ratio Check db_cache_advice 9i and higher Data in Statspack under “Buffer Pool Advisory” Want to optimize data caching 3. Tune High IO SQL Copyright 2006 Kyle Hailey #.24 Step 1a: Ave Read Time File IO Stats DB/Inst:labsf03 Snaps: 1-2 Tablespace Filename ------------------------ ---------------------------------------------------Av Mx Av Av Rd Rd Av Av Buffer BufWt Reads Reads/s (ms) Bkt Blks/Rd Writes Writes/s Waits (ms) ---------- ---- ------- ----- --- ------- ------------ -------- ---------- -SYSTEM /u01/app/oracle/oradata/labsf03/system01.dbf 445 15 0.4 16 1.0 1,157 39 2,744 93.3 USERS /u01/app/oracle/oradata/labsf03/users01.dbf 223 7 0.5 ### 1.0 9,725 324 4 100.0 IO should be under 20ms Fastest possible is around 7ms Faster speeds are due to read caching Copyright 2006 Kyle Hailey Step 1c: Ave Read Time #.25 select to_char(begin_interval_time,'yyyy-mm-dd hh24:mi') snap_time, file#, readtim/nullif(phyrds,0) avg_read_ms, phyrds from DBA_HIST_FILESTATXS f, dba_hist_snapshot s where f.snap_id=s.snap_id ; SNAP_TIME FILE# AVG_READ_MS PHYRDS ---------------- ---------- ----------- ---2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 2008-01-05 12:00 12:00 13:00 13:00 13:00 13:00 13:00 13:00 13:00 13:00 13:00 13:00 IO should be under 20ms Fastest possible is around 7ms Faster speeds are due to read caching Copyright 2006 Kyle Hailey 9 10 1 2 3 4 5 6 7 8 9 10 36.67 32.31 11.63 56.37 17.38 9.39 38.78 28.29 27.44 42.56 36.67 32.31 39 39 178224 2014 50668 565321 41 41 39 39 39 39 #.26 Step 1c: Ave Read Time select to_char(begin_time,'yyyy-mm-dd hh24:mi') begin_time, file_id fid, average_read_time *10 avgrd_ms, average_write_time *10 avgwr_ms, physical_reads pr, physical_writes pw BEGIN_TIME FID AVGRD_MS AVGWR_MS from ---------------- ---- -------- -------5.2 2.5 V$FILEMETRIC_HISTORY f 2008-01-30 12:25 1 2008-01-30 12:25 5 80.0 20.0 order by begin_time; 2008-01-30 12:25 2 36.7 2.0 PR PW ---------- ---------100 24 2 2 3 218 2008-01-30 12:25 4 22.8 1.8 89 2754 2008-01-30 12:25 3 22.9 2.6 14 47 IO should be under 20ms Fastest possible is around 7ms Faster speeds are due to read caching Copyright 2006 Kyle Hailey #.27 Step 2 : Buffer Pool Advisory Buffer Pool Advisory Size for Size Buffers for Read Estimated P Est (M) Factor Estimate Factor Physical Reads --- -------- ------ ------------ ------ -------------D 56 .1 6,986 2.3 58,928 D 112 .2 13,972 1.6 42,043 D 224 .4 27,944 1.0 25,772 D 336 .6 41,916 1.0 25,715 D 448 .8 55,888 1.0 25,715 D 596 1.0 74,351 1.0 25,715 D 728 1.2 90,818 1.0 25,715 D 840 1.4 104,790 1.0 25,715 D 952 1.6 118,762 1.0 25,715 D 1,064 1.8 132,734 1.0 25,715 Copyright 2006 Kyle Hailey Step 3: Find Top I/O SQL select count(*),sql_id, event from v$active_session_history where event in ('db file sequential read', 'db file scattered read', 'db file parallel read') group by sql_id, event order by count(*); COUNT(*) --------10 335 343 481 549 1158 1311 1523 1757 SQL_ID ------------8hk7xvhua40va 3hatpjzrqvfn7 0uuqgjq7k12nf 75621g9y3xmvd 0bzhqhhj9mpaa 41zu158rqf4kf 0yas01u2p9ch4 EVENT -----------------------db file sequential read db file sequential read db file sequential read db file scattered read db file sequential read db file sequential read db file sequential read db file sequential read db file sequential read Copyright 2006 Kyle Hailey #.28 Step 3: OEM find top SQL Copyright 2006 Kyle Hailey #.29 #.30 IO Solutions Check File IO response times Buffer Cache Hit Ratio Always Check SQL to Tune Copyright 2006 Kyle Hailey #.31 IO Configuration Issues Unix Buffer Cache Disk Spindles Raid 5 Copyright 2006 Kyle Hailey Unix File Buffer Cache Machine Memory Unix File Cache If average IO read times are under 7ms them probably coming from Unix File Cache Copyright 2006 Kyle Hailey SGA #.32 IO Histograms IO at > 1ms comes From Unix File Cache Copyright 2006 Kyle Hailey #.33 #.34 IO Throughput IO Operations/Sec 150 IOPS/sec optimistic Large Disks – Few IOPS Small Disks – Many IOPS Copyright 2006 Kyle Hailey #.35 Disk 2Gb vs 70GB Seagate Barracuda 4LP Seagate Cheetah 73LP Capacity Rotation Speed Rotational Delay(avg) 2.16GB 7200rpm 4.1ms 73.4GB 10000rpm 3ms Time to read 32Kb Seek Time (avg) 6ms 9.4ms 3ms 4.9 Total time for Single I/O I/O per second (conservative) 19.5ms 51 10.9ms 92 IOPs/sec per 100GB 2550 126 Copyright 2006 Kyle Hailey #.36 Raid 5 http://www.miracleas.com/BAARF/BAARF2.html B – Battle A – Against A – Any R – Raid F - Five Copyright 2006 Kyle Hailey Direct I/O WAITS Direct I/O : This mechanism lets the client bypass the buffer cache for I/O intensive operations. The disk blocks are written into and read from process private memory. direct path read : Parallel Query direct path write sqlldr loading/reading LOBs parallel DMLs create table as select create index direct path read temp , direct path write temp Sorting Copyright 2006 Kyle Hailey #.37 #.38 Direct IO Shadow Process PGA Buffer Cache Sort Area Direct Path PQO Reads X Copyright 2006 Kyle Hailey direct path read Parallel Query See v$px_session select parameter1, parameter2, parameter3 from v$event_name where name='direct path read'; PARAMETER1 PARAMETER2 PARAMETER3 ---------- ---------- ---------file number first dba block cnt Shadow Process PGA Buffer Cache PQO X _serial_direct_read = true Copyright 2006 Kyle Hailey #.39 Further Investigation ASH select session_id sid, QC_SESSION_ID qsid, ash.p3, CURRENT_OBJ#||' '||o.object_name objn, o.object_type otype, CURRENT_FILE# fn, CURRENT_BLOCK# blockn, ash.SQL_ID from v$active_session_history ash, all_objects o where event like 'direct path read' and o.object_id (+)= ash.CURRENT_OBJ# Order by sample_time; ----- ----SID QSID P3 --- ---- -149 152 8 144 152 8 60 152 8 54 152 6 149 152 8 144 152 8 60 152 8 ---- ----------- ------ -- ------ -----------OBJN OTYPE FN BLOCKN SQL_ID ----- ------ -- ------ ------------TOTO TABLE 1 194072 4gp8tg0b2s722 TOTO TABLE 1 192304 4gp8tg0b2s722 TOTO TABLE 1 190592 4gp8tg0b2s722 TOTO TABLE 1 201274 4gp8tg0b2s722 TOTO TABLE 1 198552 4gp8tg0b2s722 TOTO TABLE 1 200464 4gp8tg0b2s722 TOTO TABLE 1 196784 Copyright 2006 Kyle Hailey 4gp8tg0b2s722 #.40 PQO - ASH #.41 select ash.SQL_ID, QC_SESSION_ID qsid, count(*) cnt, count (distinct session_id) deg, nvl(o.object_name,to_char(CURRENT_OBJ#)) obj, o.object_type otype, decode(session_state, 'WAITING',event,'CPU') event from v$active_session_history ash, SQL_ID QSID CNT DEG OBJ OTYPE EVENT all_objects o ------------- ---- ---- --- ------------ ----- ------------------------123 42 4 WAIT_OBJECTS TABLE direct path read where 6rvy3wj2u0h6u o.object_id (+)= ash.CURRENT_OBJ# 123 3 WAIT_OBJECTS TABLE CPU and qc_session_id is not null 3 4 0 db file sequential read group by qc_session_id, 123 sql_id, 96 o.object_name, 123 9 4 0 read by other session o.object_type, CURRENT_OBJ#, event, session_state 123 2 2 0 CPU Order by qc_session_id, sql_id 7p3jt75phub2d 144 386 4 WAIT_OBJECTS TABLE PX Deq Credit: send blkd 144 144 144 144 144 144 4 37 3 70 21 12 3 1 2 1 4 4 WAIT_OBJECTS WAIT_OBJECTS WAIT_OBJECTS WAIT_OBJECTS 0 0 TABLE TABLE TABLE TABLE PX qref latch db file sequential read direct path read CPU PX Deq Credit: send blkd db file sequential read #.42 direct path write Occurs when: insert /*+ APPEND */ sql*loader direct=y Create table as select Shadow Process select parameter1, parameter2, parameter3 from v$event_name where name='direct path write'; PARAMETER1 PARAMETER2 PARAMETER3 ---------- ---------- ---------file number first dba block cnt DBWR PGA DATA Buffer Cache Copyright 2006 Kyle Hailey Direct Path Read Temp Direct Path Write Temp Sorting Write to Temp Read from Temp select parameter1, parameter2, parameter3 from v$event_name where name in ('direct path write temp‘, ‘direct path read temp’); PARAMETER1 ---------file number file number PARAMETER2 ---------first dba first dba Shadow Process PGA TEMP DATA #.43 Buffer Cache Copyright 2006 Kyle Hailey PARAMETER3 ---------block cnt block cnt #.44 Further investigation “real time“ can use Select Note: SQL_ID doesn’t seem filled in for v$sort_usage.sql_id su.username, su.segtype, s.sql_id, su.blocks from v$sort_usage su, v$session s Where s.saddr = su.session_addr and s.serial# = su.session_num; USERNAME SEGTYPE SQL_ID BLOCKS --------- ------- ------------- -----SYS SORT 3xp88dstadjs4 109440 Copyright 2006 Kyle Hailey file open Args P1 fib P2 iov P3 0 Wait on an open file The time it takes to open the file Times should be order of a block read To tune, try pre-opening files Leave sessoins connected High reconnection rates can exacerbate Can try holding log files open (see script from Steve Adams) Copyright 2006 Kyle Hailey #.46 #.47 file identify The time it takes to identify a file so that it can be opened later. Datafile should be identified just once Logfiles are identified every checkpoint Reduce checkpoints Arguments p1 fib p2 filename p3 opcode (1 test for create, 2 get details) Copyright 2006 Kyle Hailey #.48 Data file init write When autoextend is set and many extensions are happening Copyright 2006 Kyle Hailey #.49 Local Write Wait Truncating a table Wait for Data Cache to be cleared of all blocks of truncated table Wait by shadow for DBWR If a problem try GTT Reduce fast_start_mttr_target Copyright 2006 Kyle Hailey Further Investigation #.50 select * from v$event_name where name = ‘local write wait' NAME P1 P2 P3 ----------------- ----- ------ ----local write wait file# block# select ash.p1,ash.p2, ash.SQL_ID, count(*) from v$ash ash where event='local write wait' P1 P2 SQL_ID COUNT group by --- -- ------------- ----201 2 0q8k9xfmz0k2k 194 ash.p1,ash.p2, ash.SQL_ID; 201 201 201 Copyright 2006 Kyle Hailey 5 0q8k9xfmz0k2k 6 0q8k9xfmz0k2k 4 0q8k9xfmz0k2k 34 9 10 Temporary File #’s SQL> select file# from v$datafile; FILE# ---------Wait Temporary File#’s = 1 Db_files + file# 2 3 SQL> show parameters db_files 4 5 NAME VALUE ---------- ------------6 db_files 200 7 8 SQL> select file# from v$tempfile; FILE# ---------2 File# 201 = v$tempfile 1 1 Copyright 2006 Kyle Hailey #.51 #.52 Local Write Wait:extent allocation CREATE TEMPORARY TABLESPACE "NEWTEMP" TEMPFILE '/d3/temp01.dbf' SIZE 100M AUTOEXTEND ON EXTENT MANAGEMENT LOCAL UNIFORM SIZE 64K; ALTER DATABASE DEFAULT TEMPORARY TABLESPACE newtemp; select a.*, b.* from dba_objects a, dba_objects b order by a.owner Copyright 2006 Kyle Hailey Local Write Waits Copyright 2006 Kyle Hailey #.53 #.54 Local Write Wait: Solutions Truncating a table Reduce cache size Use GTT Temporary Table Space Allocations Increase extent size Copyright 2006 Kyle Hailey #.55 Summary I/O Buffer Cache IO db file sequential read db file scattered read db file parallel read Tune I/O’s should be 5-15ms Check Buffer Cache Advisory Tune SQL Copyright 2006 Kyle Hailey #.56 Summary Direct I/O direct path read : PQO direct path write : direct path operations direct path read temp: sorts direct path write temp: sorts direct path write (lob) : stored NOCACHE Copyright 2006 Kyle Hailey #.57 IO Summary Other sort segment request : SMON occupied file open : log files or session reconnects file identify : log files or session reconnects local write wait – Temp extensions Truncates data file init write – data file extension Copyright 2006 Kyle Hailey