被误读的buffer busy waits

讨论主题：
1、你能重现buffer busy waits等待吗？

2、重现buffer busy waits等待之后，你抓住产生buffer busy waits 的原凶了吗？

3、加大log buffer会减少buffer busy waits等待吗？

4、找到原凶之后如何优化buffer busy waits等待？

1、你能重现buffer busy waits等待吗？
测试DB版本11g：
SQL> select * from v$version where rownum=1;

BANNER

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production

（一）、用Dtrace +mdb跟踪模拟buffer busy waits等待事件
SQL> select sid from v$mystat where rownum=1;

   SID

   125

SQL> select spid from v$session s,v$process b where s.paddr=b.addr and s.sid in(select sid from v$mystat where rownum=1);

SPID

1887
SQL> select rowid,name from t1 where id=1;
ROWID NAME

AAASTVAAGAAAACnAAA BBBBBB
SQL> select dbms_rowid.rowid_relative_fno(rowid),dbms_rowid.rowid_block_number(rowid) from t1;
DBMS_ROWID.ROWID_RELATIVE_FNO(ROWID) DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID)

                               6                                  167

SQL> select hladdr from x$bh where file#=6 and dbablk=167;

HLADDR

00000003A41E4080
00000003A41E4080

（二）、再开一个窗口用mdb设mdb断点
-bash-3.2# mdb -p 1887

（三）、再回到125号会话：对 rowid='AAASTVAAGAAAACnAAA'这条记录做修改
update t1 set name='BBBBBB' where rowid='AAASTVAAGAAAACnAAA';
这时已被阻塞

（四）、接第二步骤开始用mdb跟踪
Loading modules: [ ld.so.1 libc.so.1 ]

sskgslcas :b
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
sskgsldecr :b
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgsldecr
mdb: target stopped at:
sskgsldecr: lock subq %rsi,(%rdi)
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
:c
mdb: stop at sskgsldecr
mdb: target stopped at:
sskgsldecr: lock subq %rsi,(%rdi)
:c
mdb: stop at sskgslcas
mdb: target stopped at:
sskgslcas: movq %rsi,%rax
::step
mdb: target stopped at:
sskgslcas+3: lock cmpxchgq %rdx,(%rdi)

（五）、打开144号会话：查询rowid='AAASTVAAGAAAACnAAA'的这行记录
SQL> conn gyj/gyj
Connected.
SQL> select distinct sid from v$mystat;

   SID

   144

SQL> select * from t1 where rowid='AAASTVAAGAAAACnAAA';

这时查询被阻塞

（六）、打开138号会话：观察等待事件
SQL> select sid,event,total_waits,time_waited_micro from v$session_event where lower(event) like 'buffer%';

   SID EVENT

TOTAL_WAITS TIME_WAITED_MICRO

   144 buffer busy waits
      1           7005803

重现了buffer busy waits等待事件

2、重现buffer busy waits等待之后，你抓住产生buffer busy waits 的原凶了吗？

buffer busy waits 的原凶是：写阻塞读的原因！

3、加大log buffer会减少buffer busy waits等待吗？
一、当log_buffer=5210112时分别在两会话上跑SQL，产生buffer busy waits等事
1.查当前的log_buffer大小,即为5M
sys@OCM> show parameter log_buffer;
NAME TYPE VALUE

log_buffer integer 5210112

2.分别在两会话上跑sql
begin
for i in 1 .. 500000 loop
update t1 set id=id+0 where rowid='AAAS1wAADAAAAFUAAA';
commit;
end loop;
end;
/
declare
m_name varchar2(50);
begin
for i in 1..500000 loop

 select name into m_name from gyj.t1 where rowid='AAAS1wAADAAAAFUAAA';

end loop;
end;
/

3.产生的buffer busy waits等事
sys@OCM> sys@OCM> select sid,event,total_waits,time_waited_micro from v$session_event where event in('log buffer
space','buffer busy waits') and sid in(141,24);

   SID EVENT                                                            TOTAL_WAITS TIME_WAITED_MICRO

    24 buffer busy waits                                                      14915          13445559
    24 log buffer space                                                          41          12871945
   141 buffer busy waits                                                       1866            554125
   141 log buffer space                                                          31          14763344

二、当log_buffer=40960000时分别在两会话上跑SQL，产生buffer busy waits等事

1. 修改log_buffer=5210112为20480000
   sys@OCM> alter system set log_buffer=20480000 scope=spfile;
   sys@OCM> startup force;
   sys@OCM> show parameter log_buffer
   NAME TYPE VALUE

   ---

   log_buffer integer 20480000

2.分别在两会话上跑sql
begin
for i in 1 .. 500000 loop
update t1 set id=id+0 where rowid='AAAS1wAADAAAAFUAAA';
commit;
end loop;
end;
/
declare
m_name varchar2(50);
begin
for i in 1..500000 loop

 select name into m_name from gyj.t1 where rowid='AAAS1wAADAAAAFUAAA';

end loop;
end;
/
3.产生buffer busy waits等事
sys@OCM> select sid,event,total_waits,time_waited_micro from v$session_event where event in('log buffer
space','buffer busy waits') and sid in(142,20);

   SID EVENT                                                            TOTAL_WAITS TIME_WAITED_MICRO

    20 buffer busy waits                                                      17259           7585360
   142 buffer busy waits                                                       4902           1343520

三、对步骤一与步骤二对比
sys@OCM> sys@OCM> select sid,event,total_waits,time_waited_micro from v$session_event where event in('log buffer
space','buffer busy waits') and sid in(141,24);

   SID EVENT                                                            TOTAL_WAITS TIME_WAITED_MICRO

    24 buffer busy waits                                                      14915          13445559
    24 log buffer space                                                          41          12871945
   141 buffer busy waits                                                       1866            554125
   141 log buffer space                                                          31          14763344

sys@OCM> select sid,event,total_waits,time_waited_micro from v$session_event where event in('log buffer
space','buffer busy waits') and sid in(142,20);

   SID EVENT                                                            TOTAL_WAITS TIME_WAITED_MICRO

    20 buffer busy waits                                                      17259           7585360
   142 buffer busy waits                                                       4902           1343520

比较TIME_WAITED_MICRO，明显是步骤一的比步骤二的大。步骤一的log_buffer=5M ，步骤二的log_buffer=20M
说明步骤二的buffer busy waits的等待时间少。即增大log_buffer可以减少buffer busy wait等待的时间。

4、找到原凶之后如何优化buffer busy waits等
buffer busy waits优化的重点是写,即写操作的时间更快一点或着写操作的次数更少一点！！！