2020.06.23
カテゴリ： ソフト開発日誌
SMR 記録方式の HDD WD WD60EZAZ を linux (Lubuntu 20.04)でベンチマークテストしている。ベンチマークプログラムが kill -9 (SIGKILL) も効かない状態でハングする。ランダムアクセステストで kernel の cache は有効な状態、ベンチマークプログラムは root 権限で動作している。raw block device をアクセスするためだ。
ps uaxww でハングアップしている状態を見てみる。STAT が DL+ となった。"Waiting in uninterruptible disk sleep" (割り込み不可の状態でディスク I/O 完了待ち)だ。
root 権限でプログラムを動かしたとしても、uninterruptible 状態が長時間続く様な動作を kernel がすることはまずあり得ない。
Linux Kernel で uninterruptible あるいはその逆の interruptible というのは誤解を招きやすい表現の一つだ。この場面において、純粋に「割り込み (interrupt) を受け付けない」という意味ではなく、Userland process が呼び出した「system call 処理中に signal を受け付けない」状態ということだ。どんな signal も受け付けない。signal 9 (SIGKILL) も含まれる。
/proc/ pid directory 内にあるいくつかの process status を見てみる。 stat と status も D state で止まっていることを示していた。
ps コマンドで得た情報は確かだ。
ベンチマークプログラムはどこまで進んでいたのだろうか。ログ出力が途切れていたので、 活動状況を類推できる fd/* file descriptor 使用状態(open している状態)
stdin, stdout, stderr だけだった。ほぼプログラムは終了している状態と考えられる。
ん？ stack ってなんだ。 system call を発行してから kenel 内でどこまで進んでいるか見ることができる call stack だった。
各 kernel 関数のリンク先は Lubuntu 20.04 で使っている 5.4.0-37 に近い 5.4.47 のソースにリンク している。sync() を起点として submit_bio_wait で止まっている。「まぁ、そうだろう」と思う状況だ。
真に止まっている場所は submit_bio_wait 内から呼び出した wait_for_completion_io か少し進んだ先のはず。ここで、 TASK_UNINTERRUPTIBLE 状態で止まるように wait_for_common_io を呼び出している。signal を受け付けない訳だ。
厄介だ。call stack の流れは、 ext4_sync_fs
途中で途切れてしまったベンチマークテストの結果 を見てみると、kenel cache を経由したアクセスで、完了まで 100 秒以上経過している場合がある。63 回だ。出始めの SSD に良く見られたプチフリーズとよく似ている。より悪い挙動かもしれない。
Linux kernel 5.x から /sys/block/ block_device_name /queue/io_timeout と言う ms (ミリ秒) 単位でタイムアウトを設定できるノード(リンク先は kernel 内の store 実装) が増えたようだ。各 Controller 毎にバラバラに実装されていた timeout を統一的に扱うノードなのだろうか？ SSD や SMR HDD といった癖があるデバイスが増え、実装する機運が高まったのかも。一方で各 Controller 毎にあった複雑な事情を吸収しきれず、complete しないゾンビののような BIO request (Block IO request) が生じやすい？
io_timeout ノードの設定を変えて SMR HDD を使えるようにできるだろうか？ なんだな、筋が悪い予感がする。以前プチフリ SSD を Linux で使うのを断念している。よく似た状況だ。
ps uaxww でハングアップしている状態を見てみる。STAT が DL+ となった。"Waiting in uninterruptible disk sleep" (割り込み不可の状態でディスク I/O 完了待ち)だ。
$ ps uaxww | grep ssdstress &
34176 0.0 6.4 1576728 1574484 pts/1 DL+ 613 1:30 ./ssdstress -f 6001175126016 -pn -xb -rn -my -b 4096 -i 1 -a 131072 -i exp -n 24576 -u 65536 -dn -dY -s 20200614 /dev/sdc
34176 0.0 6.4 1576728 1574484 pts/1 DL+ 613 1:30 ./ssdstress -f 6001175126016 -pn -xb -rn -my -b 4096 -i 1 -a 131072 -i exp -n 24576 -u 65536 -dn -dY -s 20200614 /dev/sdc
root 権限でプログラムを動かしたとしても、uninterruptible 状態が長時間続く様な動作を kernel がすることはまずあり得ない。
Linux Kernel で uninterruptible あるいはその逆の interruptible というのは誤解を招きやすい表現の一つだ。この場面において、純粋に「割り込み (interrupt) を受け付けない」という意味ではなく、Userland process が呼び出した「system call 処理中に signal を受け付けない」状態ということだ。どんな signal も受け付けない。signal 9 (SIGKILL) も含まれる。
/proc/ pid directory 内にあるいくつかの process status を見てみる。 stat と status も D state で止まっていることを示していた。
/proc/34176 # cat stat
34176 (ssdstress) D 34175 31200 31057 34817 31200 4194560 393297 0 1 0 6180 2875 0 0 20 0 1 0 23546681 1614569472 393621 18446744073709551615 94412556185600 94412556207685 140733693111200 0 0 0 0 0 0 1 0 0 17 3 0 0 3976146 0 0 94412556225760 94412556226828 94412566093824 140733693114159 140733693114281 140733693114281 140733693116396 0
/proc/34176 # cat status
Name:ssdstress
Umask:0022
State:D (disk sleep)
Tgid:34176
Ngid:0
Pid:34176
PPid:34175
TracerPid:0
Uid:0000
Gid:0000
FDSize:64
Groups:0
-- snip --
34176 (ssdstress) D 34175 31200 31057 34817 31200 4194560 393297 0 1 0 6180 2875 0 0 20 0 1 0 23546681 1614569472 393621 18446744073709551615 94412556185600 94412556207685 140733693111200 0 0 0 0 0 0 1 0 0 17 3 0 0 3976146 0 0 94412556225760 94412556226828 94412566093824 140733693114159 140733693114281 140733693114281 140733693116396 0
/proc/34176 # cat status
Name:ssdstress
Umask:0022
State:D (disk sleep)
Tgid:34176
Ngid:0
Pid:34176
PPid:34175
TracerPid:0
Uid:0000
Gid:0000
FDSize:64
Groups:0
-- snip --
ps コマンドで得た情報は確かだ。
ベンチマークプログラムはどこまで進んでいたのだろうか。ログ出力が途切れていたので、 活動状況を類推できる fd/* file descriptor 使用状態(open している状態)
/proc/34176/fd # ls -la
total 0
dr-x------ 2 root root 0 6 13 15:46 .
dr-xr-xr-x 9 root root 0 6 13 15:46 ..
lrwx------ 1 root root 64 6 13 15:46 0 -> /dev/pts/1
l-wx------ 1 root root 64 6 13 15:46 1 -> 'pipe:[233565]'
l-wx------ 1 root root 64 6 13 15:46 2 -> 'pipe:[233565]'
total 0
dr-x------ 2 root root 0 6 13 15:46 .
dr-xr-xr-x 9 root root 0 6 13 15:46 ..
lrwx------ 1 root root 64 6 13 15:46 0 -> /dev/pts/1
l-wx------ 1 root root 64 6 13 15:46 1 -> 'pipe:[233565]'
l-wx------ 1 root root 64 6 13 15:46 2 -> 'pipe:[233565]'
stdin, stdout, stderr だけだった。ほぼプログラムは終了している状態と考えられる。
ん？ stack ってなんだ。 system call を発行してから kenel 内でどこまで進んでいるか見ることができる call stack だった。
/proc/34176 # cat stactk
[<0>] submit_bio_wait +0x60/0x90
[<0>] blkdev_issue_flush +0x94/0xd0
[<0>] ext4_sync_fs +0x15d/0x200
[<0>] sync_fs_one_sb +0x23/0x30
[<0>] iterate_supers+0xa3/0x100
[<0>] ksys_sync +0x62/0xb0
[<0>] __ia32_sys_sync+0xe/0x20
[<0>] do_syscall_64+0x57/0x190
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[<0>] submit_bio_wait +0x60/0x90
[<0>] blkdev_issue_flush +0x94/0xd0
[<0>] ext4_sync_fs +0x15d/0x200
[<0>] sync_fs_one_sb +0x23/0x30
[<0>] iterate_supers+0xa3/0x100
[<0>] ksys_sync +0x62/0xb0
[<0>] __ia32_sys_sync+0xe/0x20
[<0>] do_syscall_64+0x57/0x190
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xa9
各 kernel 関数のリンク先は Lubuntu 20.04 で使っている 5.4.0-37 に近い 5.4.47 のソースにリンク している。sync() を起点として submit_bio_wait で止まっている。「まぁ、そうだろう」と思う状況だ。
真に止まっている場所は submit_bio_wait 内から呼び出した wait_for_completion_io か少し進んだ先のはず。ここで、 TASK_UNINTERRUPTIBLE 状態で止まるように wait_for_common_io を呼び出している。signal を受け付けない訳だ。
厄介だ。call stack の流れは、 ext4_sync_fs
途中で途切れてしまったベンチマークテストの結果 を見てみると、kenel cache を経由したアクセスで、完了まで 100 秒以上経過している場合がある。63 回だ。出始めの SSD に良く見られたプチフリーズとよく似ている。より悪い挙動かもしれない。
Linux kernel 5.x から /sys/block/ block_device_name /queue/io_timeout と言う ms (ミリ秒) 単位でタイムアウトを設定できるノード(リンク先は kernel 内の store 実装) が増えたようだ。各 Controller 毎にバラバラに実装されていた timeout を統一的に扱うノードなのだろうか？ SSD や SMR HDD といった癖があるデバイスが増え、実装する機運が高まったのかも。一方で各 Controller 毎にあった複雑な事情を吸収しきれず、complete しないゾンビののような BIO request (Block IO request) が生じやすい？
io_timeout ノードの設定を変えて SMR HDD を使えるようにできるだろうか？ なんだな、筋が悪い予感がする。以前プチフリ SSD を Linux で使うのを断念している。よく似た状況だ。
お気に入りの記事を「いいね！」で応援しよう
[ソフト開発日誌] カテゴリの最新記事
-
商用電源監視サーバー更新 - 閏年 2/29 以… 2024.05.31
-
Futaba M202MD10B アプリ と コマンドシー… 2023.09.05
-
Intel Core i5-10600K 偽物説 - 近所の HA… 2023.09.04
【毎日開催】
15記事にいいね！で1ポイント
カレンダー
サイド自由欄
コメント新着
© Rakuten Group, Inc.
