ねら~ITエンジニア雑記

やきうのお兄ちゃんが綴るOracle Databaseメインのブログ

ASM使用時 に DISK_ASYNCH_IOパラメータ を変えて、LGWR/DBWRプロセスのシステムコールを見てみる。

まず REDOログ/データファイル の格納場所を確認、どちらもASM上に配置されています。

SET PAGESIZE 100
SET LINESIZE 170
COLUMN MEMBER FORMAT A80
SELECT GROUP#, MEMBER FROM V$LOGFILE;

    GROUP# MEMBER
---------- -----------------------------------------------
         1 +ASM_DG/orcl/onlinelog/group_1.1409.883145191
         2 +ASM_DG/orcl/onlinelog/group_2.860.883145197
:
        19 +ASM_DG/orcl/onlinelog/group_19.881.883139299
        20 +ASM_DG/orcl/onlinelog/group_20.1093.883139311

COLUMN FILE_NAME FORMAT A80
SELECT FILE_ID, FILE_NAME FROM DBA_DATA_FILES;

   FILE_ID FILE_NAME
---------- -----------------------------------------------
         1 +ASM_DG/orcl/datafile/system.1676.883138497
         2 +ASM_DG/orcl/datafile/sysaux.1165.883137731
:
         8 +ASM_DG/orcl/datafile/users.1257.883137643

次に初期パラ確認、DISK_ASYNCH_IO=TRUE(Non Blocking I/O)から確認です。

SHOW PARAMETER ASYNC

NAME              TYPE         VALUE
----------------- ------------ -------------
disk_asynch_io    boolean      TRUE
tape_asynch_io    boolean      TRUE

LGWRプロセス/DBWRプロセスにstraceを仕掛けます。

# ps -ef | grep -i lgwr
grid      3050     1  0 Nov03 ?        00:01:08 asm_lgwr_+ASM1
oracle    5657     1  0 Nov03 ?        00:10:33 ora_lgwr_orcl1
root     32040 29572  0 11:28 pts/0    00:00:00 grep -i lgwr
# strace -p 5657 -ff -o /tmp/lgwr_strace_async_true.log
Process 5657 attached

# ps -ef | grep -i dbw
grid      3046     1  0 Nov03 ?        00:01:03 asm_dbw0_+ASM1
oracle    5653     1  0 Nov03 ?        00:03:32 ora_dbw0_orcl1
root     32137 31863  0 11:29 pts/1    00:00:00 grep -i dbw
# strace -p 5653 -ff -o /tmp/dbwr_strace_async_true.log
Process 5653 attached

トランザクションを実行します。

DROP TABLE TBL_A PURGE;
CREATE TABLE TBL_A (C1 NUMBER);
INSERT INTO TBL_A
 SELECT LEVEL
   FROM DUAL
CONNECT BY LEVEL <= 100000;
COMMIT;

strace のログを見てみます。Non Blocking I/O の
システムコール(io_submit/io_getevents) が 出ているやで 彡(゚)(゚)

★LGWRプロセスのシステムコールを確認
cat lgwr_strace_async_true.log.5657
:
gettimeofday({1448245846, 974961}, NULL) = 0
io_submit(139669291659264, 1, {{data:0x7f07479db320, pwrite, filedes:258, … ★
gettimeofday({1448245846, 975302}, NULL) = 0
io_getevents(139669291659264, 1, 128, {{0x7f07479db320, 0x7f07479db320,  … ★
gettimeofday({1448245846, 976476}, NULL) = 0


★DBWRプロセスのシステムコールを確認
cat dbwr_strace_async_true.log.5653

gettimeofday({1448245833, 172325}, NULL) = 0
io_submit(140143598940160, 1, {{data:0x7f75b5b08ab0, pwrite, filedes:256, … ★
gettimeofday({1448245833, 172587}, NULL) = 0

gettimeofday({1448245833, 172885}, NULL) = 0
io_getevents(140143598940160, 1, 128, {{0x7f75b5b08ab0, 0x7f75b5b08ab0, … ★
gettimeofday({1448245833, 173776}, NULL) = 0

初期パラを変更します。DISK_ASYNCH_IO=FALSE(Blocking I/O) に変えるやで。

ALTER SYSTEM SET DISk_ASYNCH_IO=FALSE SCOPE=SPFILE SID='*';
srvctl stop database -d orcl
srvctl start database -d orcl

SHOW PARAMETER ASYNC

NAME              TYPE         VALUE
----------------- ------------ -------------
disk_asynch_io    boolean      FALSE
tape_asynch_io    boolean      TRUE

再度 LGWRプロセス/DBWRプロセス に strace を仕掛けます。

# ps -ef | grep -i lgwr
oracle    1587     1  0 11:41 ?        00:00:00 ora_lgwr_orcl1
root      1855 29572  0 11:41 pts/0    00:00:00 grep -i lgwr
grid      3050     1  0 Nov03 ?        00:01:08 asm_lgwr_+ASM1
# strace -p 1587 -ff -o /tmp/lgwr_strace_async_false.log
Process 1587 attached

# ps -ef | grep -i dbw
oracle    1583     1  0 11:41 ?        00:00:00 ora_dbw0_orcl1
root      1887 31863  0 11:41 pts/1    00:00:00 grep -i dbw
grid      3046     1  0 Nov03 ?        00:01:03 asm_dbw0_+ASM1
# strace -p 1583 -ff -o /tmp/dbwr_strace_async_false.log
Process 1583 attached

トランザクションを実行します。

DROP TABLE TBL_A PURGE;
CREATE TABLE TBL_A (C1 NUMBER);
INSERT INTO TBL_A
 SELECT LEVEL
   FROM DUAL
CONNECT BY LEVEL <= 100000;
COMMIT;

strace のログ、Blocking I/O の システムコール(pwrite) が
出ているのを確認できたやで 彡(^)(^)

★LGWRプロセスのシステムコールを確認
cat lgwr_strace_async_false.log.1587
:
gettimeofday({1448246741, 606228}, NULL) = 0
pwrite(257, "\1\"\0\0\231\24\0\0'\"\0\0\20\200\317\362`\0\0\0\4\0f\t\277Q\273\370\1\0\0\0"..., 512, … ★
gettimeofday({1448246741, 608097}, NULL) = 0

gettimeofday({1448246742, 609641}, NULL) = 0
pwrite(257, "\1\"\0\0\232\24\0\0'\"\0\0\20\200\316\362`\0\0\0\4\0f\t\301Q\273\370\1\0\0\0"..., 512, … ★
gettimeofday({1448246742, 611510}, NULL) = 0


★DBWRプロセスのシステムコールを確認
cat dbwr_strace_async_false.log.1583

gettimeofday({1448246730, 194573}, NULL) = 0
pwrite(258, "#\242\0\0\202\200\0\2)Q\273\370f\t\25\4\216\305\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192, … ★
gettimeofday({1448246730, 195959}, NULL) = 0

参考記事/マニュアルは下記。ablogはん、流石やで(;`・ω・)

ablog - disk_asynch_io=false ならASMに対して同期I/O(pwrite)になる
id:yohei-a:20151115:1447590289

ablog - 同期と非同期について考えてみた
id:yohei-a:20111210:1323504855

Oracle Databaseリファレンス 11gリリース2 (11.2) B56311-11
DISK_ASYNCH_IO
http://docs.oracle.com/cd/E16338_01/server.112/b56311/initparams079.htm#CHDFBEHC