sitemap

RSS地图

收藏本站

设为首页

Oracle研究中心

当前位置:Oracle研究中心 > 运维DBA >

【学习笔记】buffer cache internal dbwr写脏块以batch的方式来完成

时间:2016-12-16 10:34   来源:Oracle研究中心   作者:网络   点击:

天萃荷净 Oracle研究中心学习笔记:分享一篇关于Oracle数据库buffer cache internal的研究笔记,详细介绍dbwr写脏块以batch的方式来完成。

本站文章除注明转载外,均为本站原创: 转载自love wife & love life —Roger 的Oracle技术博客
本文链接地址: 关于dbwr/lgwr的一点知识

昨天在看oracle performance firefighting第6章时,主要是讲buffer cache internal,作者提到dbwr进程在写脏块时是以batch的方式来完成的,这里我在vmware环境验证一下。如下是简单过程,供大家参考!

[ora10g@oracleplus~]$ ps -ef|grep -v grep|grep dbw
ora10g   15187     1  0 16:47          00:00:01 ora_dbw0_roger

[root@oracleplus~]# strace -fr -o /tmp/1.log -p 15187
Process 15187 attached - interrupt TO quit
Process 15187 detached

SQL> DELETE FROM t1 WHERE rownum < 1001;

SQL> commit;
Commit complete.

SQL> DELETE FROM t1 WHERE rownum < 1001;
1000 ROWS deleted.

SQL> commit;
Commit complete.

SQL> ALTER system switch logfile;
System altered.

SQL> ALTER system checkpoint;
System altered.

下面是strace 的log信息,如下:

15187      3.001043 gettimeofday({1356586724, 836311}, NULL) = 0
..........
15187      0.000066 gettimeofday({1356586724, 836815}, NULL) = 0
15187      0.000077 times(NULL)         = 455657245
15187      0.000060 gettimeofday({1356586724, 836944}, NULL) = 0
15187      0.000072 open("/proc/15181/stat", O_RDONLY) = 28
15187      0.000143 read(28, "15181 (oracle) S 1 15181 15181 0"..., 999) = 193
15187      0.000098 close(28)           = 0
15187      0.000074 gettimeofday({1356586724, 837332}, NULL) = 0
15187      0.000068 gettimeofday({1356586724, 837400}, NULL) = 0
15187      0.000076 times(NULL)         = 455657245
..........
15187      0.000066 gettimeofday({1356586724, 838014}, NULL) = 0
15187      0.000088 times(NULL)         = 455657245
15187      0.000068 gettimeofday({1356586724, 838171}, NULL) = 0
15187      0.000068 gettimeofday({1356586724, 838238}, NULL) = 0
15187      0.000072 semtimedop(2326528, 0x1, 0, {4294901769, 0}) = -1 EAGAIN (Resource temporarily unavailable)
15187      3.000635 gettimeofday({1356586727, 838950}, NULL) = 0
15187      0.000072 gettimeofday({1356586727, 839017}, NULL) = 0
15187      0.000060 gettimeofday({1356586727, 839077}, NULL) = 0
15187      0.000065 gettimeofday({1356586727, 839142}, NULL) = 0
15187      0.000075 gettimeofday({1356586727, 839218}, NULL) = 0
15187      0.000086 getrusage(RUSAGE_SELF, {ru_utime={0, 127980}, ru_stime={0, 705892}, ...}) = 0
15187      0.000076 getrusage(RUSAGE_SELF, {ru_utime={0, 127980}, ru_stime={0, 705892}, ...}) = 0
15187      0.000070 gettimeofday({1356586727, 839447}, NULL) = 0
...........
15187      0.000062 gettimeofday({1356586727, 840369}, NULL) = 0
15187      0.000057 times(NULL)         = 455657545
15187      0.000050 gettimeofday({1356586727, 840476}, NULL) = 0
15187      0.000057 gettimeofday({1356586727, 840533}, NULL) = 0
15187      0.000061 semtimedop(2326528, 0x1, 0, {4294901769, 0}) = 0
15187      2.983820 gettimeofday({1356586730, 824412}, NULL) = 0
15187      0.000050 gettimeofday({1356586730, 824459}, NULL) = 0
15187      0.000032 gettimeofday({1356586730, 824489}, NULL) = 0
15187      0.000029 gettimeofday({1356586730, 824518}, NULL) = 0
15187      0.000030 gettimeofday({1356586730, 824548}, NULL) = 0

从上面信息,你可以看出dbwr进程有个3s 唤醒的机制。下面的写的过程:

15187      0.000053 pwrite64(19, " \242\0\0\t\0\200\0\226\250Z\0\0\0\3\4\32!\0\0\0\0\0\0"..., 16384, 73728) = 16384
15187      0.012150 times(NULL)         = 455657846
15187      0.000029 times(NULL)         = 455657846
15187      0.000028 pwrite64(19, "\6\242\0\0\f\0\200\0\212\250Z\0\0\0[\4\326|\0\0\1\0\0\0"..., 401408, 98304) = 401408
15187      0.033914 times(NULL)         = 455657849
15187      0.000049 times(NULL)         = 455657849
15187      0.000042 pwrite64(22, "\2\242\0\0\21\1\200\1\212\250Z\0\0\0\t\4\255\314\0\0\r"..., 65536, 2236416) = 65536
15187      0.005040 times(NULL)         = 455657850
15187      0.000043 times(NULL)         = 455657850
15187      0.000041 pwrite64(22, "\2\242\0\0009\1\200\1\215\250Z\0\0\0\20\4,\333\0\0\r\0"..., 196608, 2564096) = 196608
15187      0.002547 times(NULL)         = 455657850
15187      0.000043 times(NULL)         = 455657850
15187      0.000041 pwrite64(22, "\2\242\0\0a\1\200\1\226\250Z\0\0\0#\4@o\0\0\r\0\35\0\266"..., 65536, 2891776) = 65536
15187      0.001136 times(NULL)         = 455657850
15187      0.000048 times(NULL)         = 455657850
15187      0.000041 pwrite64(22, "\2\242\0\0y\1\200\1\232\250Z\0\0\0\22\4\2017\0\0\r\0\35"..., 65536, 3088384) = 65536
15187      0.001148 times(NULL)         = 455657850
15187      0.000040 times(NULL)         = 455657850
15187      0.000041 pwrite64(22, "\2\242\0\0\t\2\200\1\235\250Z\0\0\0#\4\322\252\0\0\r\0"..., 131072, 4268032) = 131072
15187      0.002228 times(NULL)         = 455657850
15187      0.000042 times(NULL)         = 455657850
15187      0.000040 pwrite64(22, "\2\242\0\0\t\4\200\1\244\250Z\0\0\0\f\4\220\1\0\0\r\0\35"..., 393216, 8462336) = 393216
15187      0.005446 times(NULL)         = 455657851
15187      0.000089 gettimeofday({1356586730, 896216}, NULL) = 0
............
15187      0.000028 times(NULL)         = 455657859
15187      0.001268 times(NULL)         = 455657859
15187      0.000043 pwrite64(19, "\6\242\0\0=\0\200\0\271\250Z\0\0\0N\4\233\336\0\0\1\0\0"..., 319488, 499712) = 319488
15187      0.002363 times(NULL)         = 455657860
15187      0.000023 times(NULL)         = 455657860
15187      0.000021 pwrite64(22, "\2\242\0\0009\4\200\1\270\250Z\0\0\0\"\0048\201\0\0\r\0"..., 655360, 8855552) = 655360
15187      0.006413 times(NULL)         = 455657860
15187      0.000030 times(NULL)         = 455657860
15187      0.000024 pwrite64(22, "\2\242\0\0\t\7\200\1\333\250Z\0\0\0\4\4/\322\0\0\r\0\35"..., 90112, 14753792) = 90112
15187      0.004406 times(NULL)         = 455657861
15187      0.000054 gettimeofday({1356586730, 995576}, NULL) = 0
............
15187      0.000028 times(NULL)         = 455657869
15187      0.001211 times(NULL)         = 455657869
15187      0.000041 pwrite64(19, "\6\242\0\0d\0\200\0\337\250Z\0\0\0S\4h\33\0\0\1\0\0\0-"..., 311296, 819200) = 311296
15187      0.016860 times(NULL)         = 455657870
15187      0.000046 times(NULL)         = 455657870
15187      0.000024 pwrite64(19, "\6\242\0\0\213\0\200\0\3\251Z\0\0\0M\0042\240\0\0\1\0\0"..., 16384, 1138688) = 16384
15187      0.016186 times(NULL)         = 455657872
15187      0.000024 times(NULL)         = 455657872
15187      0.000022 pwrite64(22, "\2\242\0\0\24\7\200\1\337\250Z\0\0\0#\4\212\323\0\0\r\0"..., 704512, 14843904) = 704512
15187      0.007923 times(NULL)         = 455657873
15187      0.000065 gettimeofday({1356586731, 116795}, NULL) = 0
15187      0.000044 gettimeofday({1356586731, 116838}, NULL) = 0

先来看下linux的函数pwrite64,如下:

ssize_t pwrite(int fd, const void *buf, size_t count, off_t offset);

前面的19其实就是我们的数据文件,22是我们的undotbs文件。 最后一列的数字就是每次dbwr所写脏块到disk的大小(应该是bytes).

如下是fd信息:

lr-x------  1 ora10g oinstall 64 Dec 26 21:40 0 -> /dev/null
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 9 -> /home/ora10g/product/10.2/dbs/hc_roger.dat
l-wx------  1 ora10g oinstall 64 Dec 26 21:40 8 -> /home/ora10g/admin/roger/bdump/alert_roger.log
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 7 -> /home/ora10g/product/10.2/dbs/lkinstroger (deleted)
l-wx------  1 ora10g oinstall 64 Dec 26 21:40 6 -> /home/ora10g/admin/roger/bdump/alert_roger.log
l-wx------  1 ora10g oinstall 64 Dec 26 21:40 5 -> /home/ora10g/admin/roger/udump/roger_ora_15178.trc
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 4 -> /dev/null
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 3 -> /dev/null
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 27 -> /home/ora10g/oradata/roger/temp04.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 26 -> /home/ora10g/oradata/roger/temp03.dbf
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 25 -> /home/ora10g/product/10.2/rdbms/mesg/oraus.msb
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 24 -> /home/ora10g/oradata/roger/temp02.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 23 -> /home/ora10g/oradata/roger/sqlt_01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 22 -> /home/ora10g/oradata/roger/undotbs2_01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 21 -> /home/ora10g/oradata/roger/users01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 20 -> /home/ora10g/oradata/roger/sysaux01.dbf
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 2 -> /dev/null
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 19 -> /home/ora10g/oradata/roger/roger01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 18 -> /home/ora10g/oradata/roger/system01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 17 -> /home/ora10g/oradata/roger/control03.ctl
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 16 -> /home/ora10g/oradata/roger/control02.ctl
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 15 -> /home/ora10g/oradata/roger/control01.ctl
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 14 -> /home/ora10g/product/10.2/dbs/lkROGER
lrwx------  1 ora10g oinstall 64 Dec 26 21:40 13 -> /home/ora10g/product/10.2/dbs/hc_roger.dat
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 12 -> /home/ora10g/product/10.2/rdbms/mesg/oraus.msb
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 11 -> /dev/zero
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 10 -> /dev/zero
lr-x------  1 ora10g oinstall 64 Dec 26 21:40 1 -> /dev/null

从上面跟踪dbwr进程,我们可以得到什么结论? 那就是dbwr进程在将LRU-W 链表上的脏块写入到disk的过程中,是batch的方式写入的,其实这个想想也应该是这样,如若不然,那dbwr效率就太差了,难道每次写1个block?

这显然是不可能的。 观察最后一列的数值,你或许已经发现一个问题了,那就是这些数值都是block_size的整数倍。

这是无容置疑的问题,因为写入肯定是以block为单位。 这些数值大小不同,那么说明dbwr进程在写入的时候是存在一定的机制,或许是通过参数来控制(比如每次写100个block),确实是这样。在8i之前是有个参数_db_block_write_batch,在后面的版本中已经被废弃了,由新的参数_db_large_dirty_queue 来进行控制. 该参数在10g,11g中默认值为25.

SQL> SHOW USER
USER IS "ROGER"

SQL> SHOW parameter db_large

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
_db_large_dirty_queue                INTEGER     25

我对该参数是这样的理解的,当LRU-W上的脏块超过25时,那么dbwr进程一次性最少写25个,当然也可能写的更多。但是如果说脏块没有那么多,比如只有8个,那么就有多少写多少。

根据这个来看,我想lgwr进程在写log buffer到logfile的过程中,应该也是以batch的方式进行的。这里我们也可以来进行验证。

下面是跟踪lgwr进程的log信息:

15189      0.000089 pwrite64(20, "\1\"\0\0\201\\\0\0006\0\0\0\20\200\257Kh\0\0\0\4\0\0\0"..., 512, 12124672) = 512
15189      0.000812 times(NULL)         = 455850968
15189      0.000056 gettimeofday({1356588662, 66906}, NULL) = 0
15189      0.000124 times(NULL)         = 455850968
15189      0.000135 gettimeofday({1356588662, 67170}, NULL) = 0
15189      0.000066 getrusage(RUSAGE_SELF, {ru_utime={0, 99984}, ru_stime={1, 914708}, ...}) = 0
15189      0.000076 getrusage(RUSAGE_SELF, {ru_utime={0, 99984}, ru_stime={1, 914708}, ...}) = 0
15189      0.000073 gettimeofday({1356588662, 67379}, NULL) = 0
............
15189      0.000053 gettimeofday({1356588662, 68331}, NULL) = 0
15189      0.000054 times(NULL)         = 455850968
15189      0.000047 gettimeofday({1356588662, 68432}, NULL) = 0
15189      0.000082 gettimeofday({1356588662, 68517}, NULL) = 0
15189      0.000063 semtimedop(2326528, 0x1, 0, {4294901770, 0}) = -1 EAGAIN (Resource temporarily unavailable)
15189      3.000784 gettimeofday({1356588665, 69361}, NULL) = 0
15189      0.000046 gettimeofday({1356588665, 69403}, NULL) = 0
15189      0.000037 gettimeofday({1356588665, 69440}, NULL) = 0
15189      0.000041 gettimeofday({1356588665, 69482}, NULL) = 0
15189      0.000035 gettimeofday({1356588665, 69516}, NULL) = 0
15189      0.000035 gettimeofday({1356588665, 69551}, NULL) = 0
15189      0.000037 times(NULL)         = 455851268
15189      0.000032 gettimeofday({1356588665, 69620}, NULL) = 0
15189      0.000080 gettimeofday({1356588665, 69701}, NULL) = 0
15189      0.000037 times(NULL)         = 455851268
15189      0.000044 gettimeofday({1356588665, 69780}, NULL) = 0
.............
15189      0.000040 gettimeofday({1356588665, 70114}, NULL) = 0
15189      0.000033 times(NULL)         = 455851268
15189      0.000050 gettimeofday({1356588665, 70197}, NULL) = 0
15189      0.000036 gettimeofday({1356588665, 70232}, NULL) = 0
15189      0.000037 semtimedop(2326528, 0x1, 0, {4294901770, 0}) = -1 EAGAIN (Resource temporarily unavailable)
15189      3.000737 gettimeofday({1356588668, 71016}, NULL) = 0
.............
15189      0.000075 gettimeofday({1356588668, 71377}, NULL) = 0
15189      0.000056 times(NULL)         = 455851568
15189      0.000045 gettimeofday({1356588668, 71474}, NULL) = 0
15189      0.000048 gettimeofday({1356588668, 71523}, NULL) = 0
15189      0.000049 times(NULL)         = 455851568
15189      0.000059 times(NULL)         = 455851568
15189      0.000041 gettimeofday({1356588668, 71672}, NULL) = 0
15189      0.000056 times(NULL)         = 455851568
15189      0.000044 pwrite64(20, "\1\"\0\0\202\\\0\0006\0\0\0\20\200\277\303h\0\0\0\4\1\0"..., 512, 12125184) = 512
.............
.............
15189      0.002495 pwrite64(20, "\1\"\0\0\350\\\0\0006\0\0\0\20\200\7MH\2\0\0\5\0\0\0\37"..., 224768, 12177408) = 224768
15189      0.017379 times(NULL)         = 455853263
15189      0.000036 gettimeofday({1356588685, 22580}, NULL) = 0
15189      0.000044 times(NULL)         = 455853263
15189      0.000041 gettimeofday({1356588685, 22666}, NULL) = 0
............
15189      0.000488 gettimeofday({1356588685, 23606}, NULL) = 0
15189      0.000062 times(NULL)         = 455853264
15189      0.000056 times(NULL)         = 455853264
15189      0.000028 gettimeofday({1356588685, 23749}, NULL) = 0
15189      0.000035 times(NULL)         = 455853264
15189      0.000028 pwrite64(20, "\1\"\0\0\237^\0\0006\0\0\0\20\200\355\252`\0\0\0\5\1\0"..., 174080, 12402176) = 174080
15189      0.004423 times(NULL)         = 455853264

上面涉及到一个linux 函数semtimedop,是用来操作pv的,这里我们不管。重点看下面的pwrite64的操作。

fd 20是我们的redo文件,如下:

[ora10g@oracleplusfd]$ ls -ltr
total 29
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 4 -> /dev/null
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 3 -> /dev/null
l-wx------  1 ora10g oinstall 64 Dec 26 22:12 2 -> /home/ora10g/admin/roger/bdump/roger_lgwr_15189.trc
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 1 -> /dev/null
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 0 -> /dev/null
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 9 -> /home/ora10g/product/10.2/dbs/hc_roger.dat
l-wx------  1 ora10g oinstall 64 Dec 26 22:12 8 -> /home/ora10g/admin/roger/bdump/alert_roger.log
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 7 -> /home/ora10g/product/10.2/dbs/lkinstroger (deleted)
l-wx------  1 ora10g oinstall 64 Dec 26 22:12 6 -> /home/ora10g/admin/roger/bdump/alert_roger.log
l-wx------  1 ora10g oinstall 64 Dec 26 22:12 5 -> /home/ora10g/admin/roger/udump/roger_ora_15178.trc
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 28 -> /home/ora10g/product/10.2/rdbms/mesg/oraus.msb
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 27 -> /home/ora10g/oradata/roger/temp02.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 26 -> /home/ora10g/oradata/roger/sqlt_01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 25 -> /home/ora10g/oradata/roger/undotbs2_01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 24 -> /home/ora10g/oradata/roger/users01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 23 -> /home/ora10g/oradata/roger/sysaux01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 22 -> /home/ora10g/oradata/roger/roger01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 21 -> /home/ora10g/oradata/roger/system01.dbf
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 20 -> /home/ora10g/oradata/roger/redo03.log
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 19 -> /home/ora10g/oradata/roger/redo02.log
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 18 -> /home/ora10g/oradata/roger/redo01.log
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 17 -> /home/ora10g/oradata/roger/control03.ctl
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 16 -> /home/ora10g/oradata/roger/control02.ctl
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 15 -> /home/ora10g/oradata/roger/control01.ctl
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 14 -> /home/ora10g/product/10.2/dbs/lkROGER
lrwx------  1 ora10g oinstall 64 Dec 26 22:12 13 -> /home/ora10g/product/10.2/dbs/hc_roger.dat
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 12 -> /home/ora10g/product/10.2/rdbms/mesg/oraus.msb
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 11 -> /dev/zero
lr-x------  1 ora10g oinstall 64 Dec 26 22:12 10 -> /dev/zero

说明当前lgwr进程正在写redo03.log,最后一列的数据是每次lgwr写到redo logfile的大小,单位是byte.可以看到,每次的写入都是512 byte的整数倍. 可见lgwr写buffer到redo logfile也是以batch的形式来完成的。

我猜测这里oracle应该也是有相关参数来控制的,不过在10g中我没有发现。 这里要说明一下的是并不是_log_io_size参数,该参数默认log buffer的1/3,虽然显示设置是0.

最后来个简单的总结:

1. dbwr进程在将LRU-W链表上的脏块写入到disk的过程中,是以batch的形式来完成的,每次写入多少,这个是通过参数_db_large_dirty_queue来进行控制(8i以后版本是这样).

2. lgwr进程在将log buffer中的数据写入到logfile中时,也是以batch的信息,每次写入logfile block_size的整数倍。
每次写入的大小是不一定的,可能是存在一个自动调节的机制。

3. 不管是dbwr还是lgwr进程,每次写入数据的大小都受限制于操作系统,换句话讲,操作所支持的每次最大io是1m,那么既然你LRU-W上有5m的脏块,你也不能一次性写完,你必须分成多次写完。

--------------------------------------ORACLE-DBA----------------------------------------

最权威、专业的Oracle案例资源汇总之【学习笔记】buffer cache internal dbwr写脏块以batch的方式来完成

本文由大师惜分飞原创分享,网址:http://www.oracleplus.net/arch/1403.html

Oracle研究中心

关键词:

buffer cache internal

dbwr写脏块以batch的方式