关于等待事件"read by other session"

在查看数据库负载的时候,发现早上10点开始到12点的这两个钟头,系统负载异常的高。于是抓取了一个awr报告。
Snap Id Snap Time Sessions Cursors/Session
Begin Snap: 24027 18-Dec-14 10:00:43 3065 6.6
End Snap: 24033 18-Dec-14 11:00:48 3441 6.5
Elapsed:   60.08 (mins)    
DB Time:   3,650.67 (mins)    
可以从profile里看到,系统的IO负载还是很高的。

Load Profile

Per Second Per Transaction Per Exec Per Call
DB Time(s): 60.8 1.2 0.02 0.01
DB CPU(s): 10.2 0.2 0.00 0.00
Redo size: 1,835,598.3 35,780.1    
Logical reads: 1,910,437.0 37,238.9    
Block changes: 4,923.1 96.0    
Physical reads: 182,370.1 3,554.8    
Physical writes: 1,670.7 32.6    
User calls: 7,331.1 142.9    
Parses: 2,128.1 41.5    
Hard parses: 8.4 0.2    
W/A MB processed: 48.0 0.9    
Logons: 3.5 0.1    
Executes: 3,911.2 76.2    
Rollbacks: 1.5 0.0    
Transactions: 51.3      

等待事件的情况如下:

Top 5 Timed Foreground Events

Event Waits Time(s) Avg wait (ms) % DB time Wait Class
db file sequential read 24,806,147 91,539 4 41.79 User I/O
read by other session 20,260,140 37,030 2 16.91 User I/O
DB CPU   36,766   16.79  
direct path read 3,090,582 30,292 10 13.83 User I/O
log file sync 191,401 7,738 40 3.53 Commit
看完awr报告,大概能够定位是sql的问题了,直接生成了一个addm报告,作为参考。最后确认发现的几个问题sql已经在修复了,还没有部署到生产中。
今天想仔细的分析一下,毕竟很多东西都是在实践中总结出来的。
对于read by other session自己还是比较陌生的。
从metalink的描述来看。这个等待事件是在10g之后对于buffer busy waits 的一个细分。(MOS ID "Read By Other Session" Wait Event (Doc ID 732891.1))
This wait event occurs when we are trying to access a buffer in the buffer cache but we find that the buffer is currently being read from disk by another user so we need to wait for that to complete before we can access it.  In previous versions, this wait was classified under the "buffer busy waits" event. However, in Oracle 10.1 and higher, the wait time is now broken out into the "read by other session" wait event.

Excessive waits for this event are typically due to several processes repeatedly reading the same blocks, e.g. many sessions scanning the same index or performing full table scans on the same table. Tuning this issue is a matter of finding and eliminating this contention. 


对于这个等待事件可以结合awr和ash来进行排查。
首先我们在awr报告中已经得知这个等待事件,一般都会存在sequential read。但是通过awr不能清晰的定位出哪些sql语句和这个等待事件相关。
使用ash可以把时间段有针对性的调整在一个合理的范围。如果问题已经发生了一段时间,我们可以通过历史数据能够大体定位。
Top SQL with Top Events
SQL ID Planhash Sampled # of Executions % Activity Event % Event Top Row Source % RwSrc SQL Text
guqd44uzkyy56 3622987757 73 8.72 direct path read 6.48 TABLE ACCESS - FULL 6.48 SELECT /*+leading(CYC_CUST) p...
        db file sequential read 1.30 INDEX - RANGE SCAN 0.80
a6a7y2bsmmpjb 2808023112 4 8.54 CPU + Wait for CPU 4.42 INDEX - UNIQUE SCAN 1.41 SELECT COUNT(1) FROM (/* 
        db file sequential read 2.28 INDEX - UNIQUE SCAN 1.74
        read by other session 1.56 INDEX - UNIQUE SCAN 1.56
fg5mc598u799u 2134445868 6 7.24 db file sequential read 3.58 TABLE ACCESS - BY INDEX ROWID 2.61 select /*+ leading (bpm_ai bpm...
        read by other session 2.14 TABLE ACCESS - BY INDEX ROWID 1.88
        db file parallel read 1.12 TABLE ACCESS - BY INDEX ROWID 1.12
6h6dj1tnz3gwt 1565267664 35 5.03 direct path read 4.71 TABLE ACCESS - FULL 4.71 SELECT /*+parallel(CYC_PAY...
6w3p95uqduya3 561414009 71 4.27 direct path read 3.87 TABLE ACCESS - FULL 3.87 SELECT SUB.CUSTOMER_ID FROM SU...
对于read by other session,和热点块也是相关的。
我们可以使用下面的sql语句来查看一下指定时间段内的等待事件的细节。
通过ash中的Top Event P1/P2/P3 Values能够直接找到。
Event % Event P1 Value, P2 Value, P3 Value % Activity Parameter 1 Parameter 2 Parameter 3
db file sequential read 43.11 "1","3386","1" 0.04 file# block# blocks
direct path read 25.62 "5","756618","127" 0.07 file number first dba block cnt
read by other session 3.98 "46","1609148","1" 0.07 file# block# class#
db file scattered read 2.53 "3","116107","126" 0.04 file# block# blocks
db file parallel read 2.50 "2","2","2" 0.51 files blocks requests

或者通过如下的sql语句来看看对应的热点块。
SQL> SELECT relative_fno, owner, segment_name, segment_type FROM dba_extents
       WHERE file_id = 46
       AND 1609148 BETWEEN block_id AND block_id + blocks - 1;
RELATIVE_FNO OWNER                          SEGMENT_NAME                                                                      SEGMENT_TYPE
------------ ------------------------------ --------------------------------------------------------------------------------- ------------------
          20   APPO                            PAYMENT_DETAILS_PK                                                            INDEX PARTITION
    
a6a7y2bsmmpjb这条sql语句在文章(巧用rowid简化sql查询 http://blog.itpub.net/23718752/viewspace-1240404/)已经做了讨论。
但是不知道什么原因被遗漏了,和客户做了确认。
fg5mc598u799u这条sql语句是在产品线中统一规划的,已经使用Hint稳定了执行计划,但是涉及的几个表都是千万的大表,查询中使用了并行,同时需要在多台服务器中同时执行这条语句。这样的话,就会存在多个session执行
多个并行查询。从这个角度来说发生read by other session也是意料之中的。因为这个查询是一个分页查询,从操作上也可以做一些优化,目前是每隔10分钟做一次查询,然后查取1000条相关的数据。和业务部分协调的结果是,每隔半个小时执行一次查询,每次查取3000条数据。

可能一个等待事件中能够体现出一个表象。更多的细节还需要排查确认,很多优化工作不止能从数据库层面做,还可以从业务层面调整。

关于IO诊断的一些问题,可以参考 Troubleshooting I/O Related Waits (Doc ID 223117.1)
上一篇:ECS训练营进阶版第三天-SLB负载均衡实践


下一篇:加速Splunk:NetApp SANtricity为你简化分析流