NVMeディスクで書き込みより読み出しが遅いのはなんでだろう

2018-05-12: [Direct I/O](#direct-io)に関して追記
2018-05-14: [nvmecontrol perftest](#nvmecontrol-perftest)と[ファイルシステム経由](#ファイルシステム経由)に関して追記
2018-05-17: [続編](https://qiita.com/mzaki/items/183e2d5751f4bf4c9450)を投稿
2018-05-19: [解決編](https://qiita.com/mzaki/items/68d3bf4ddec95b17e337)を投稿

#動機
最近NVMeディスクをインストールしたのだけど、軽い気持ちで性能測定したら書き込みはカタログスペック通りなのに、読み出しが書き込みより遅かった。不思議。

#前提
HP Z440 Workstation  

* CPU: Xeon E5-1620v3 (3.50GHz)
* MEM: 64GB DDR4 (2133MHz, ECC, Registered)
* NVMe: [WD Black PCIe SSD 256GB (WDS256G1X0C)](http://products.wdc.com/library/SpecSheet/ENG/2879-800086.pdf)

OSはFreeBSD 11.1-RELEASE-p10で、NVMeの他にZFSでミラー構成になったHDDが付いています。[デバイスの詳細](#デバイスの詳細)は末尾に。

#カタログスペック
* Sequential Read  2,050 MB/s (Q=32, T=1)
* Sequential Write   700 MB/s (Q=32, T=1)

#準備
このNVMeディスクは大部分をZFSで使っているので、一時的にスワップパーティションをオフにして測定に用いることにする。

```shell-session
# swapinfo
Device          1K-blocks     Used    Avail Capacity
/dev/nvd0p3       2097152        0  2097152     0%
# swapoff -a
# swapinfo
Device          1K-blocks     Used    Avail Capacity```
# uptime
10:26PM  up 3 hrs, 1 users, load averages: 0.06, 0.09, 0.07
# nvmecontrol logpage -p 2 nvme0 | grep ^Temp
Temperature:                    337 K, 63.85 C, 146.93 F
```

ほぼ無負荷のまま放置して、定常状態で64℃というのはちょっと熱すぎるな。

#測定
まずはHDDに1Gのランダムデータを準備してキャッシュに載せる。

```shell-session
# dd if=/dev/random of=/home/mzaki/testdata bs=1M count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 6.597921 secs (162739423 bytes/sec)
# dd if=/home/mzaki/testdata of=/dev/null bs=1M count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 0.116707 secs (9200332728 bytes/sec)
```

キャッシュに載ってると9200MB/sも出るのか。まず書き込み。

```shell-session
# dd if=/home/mzaki/testdata of=/dev/nvd0p3 bs=1M count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 1.527102 secs (703123770 bytes/sec)
# shutdown -r now
```

シーケンシャルな書き込みは703MB/sということで、カタログスペック通りかな。再起動後ふたたびスワップを無効化して同じデータを読み込み。

```shell-session
# dd if=/dev/nvd0p3 of=/dev/null bs=1M count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 2.050148 secs (523738768 bytes/sec)
# nvmecontrol logpage -p 2 nvme0 | grep ^Temp
Temperature:                    337 K, 63.85 C, 146.93 F
```

あれー、読み込みは524MB/sしか出ないぞ？別に温度が上がってるわけでもないし。なんだこれ？

※実際には温度の影響があった（2018-05-19追記）

#Direct I/O
Direct I/Oじゃないからではないかという指摘があり検討してみた。

Direct I/Oというのは[open(2)](https://www.freebsd.org/cgi/man.cgi?sektion=2&query=open)のときにO_DIRECTを付けると、読み書きのキャッシュをしないようにするというもの。よくLinux方面でddに`oflag=direct`付けろって言われる奴です。ただFreeBSDは（たしか3.0くらいで）「kernelレベルでバッファリングを提供する」という意味での[block deviceを廃止](https://www.freebsd.org/doc/en/books/arch-handbook/driverbasics-block.html)しており、常にraw deviceとして振る舞うはず。あとはO_SYNCを付けて同期書き込みを指示するというのも検討の対象になるかもしれない。

ここで検討の障壁として、FreeBSDの[dd(1)](https://www.freebsd.org/cgi/man.cgi?sektion=1&query=dd)にはO_DIRECTやらO_SYNCをいじるためのオプションが存在しない、ということがある。GNU ddをコンパイルすればいいのかもしれないけど、無精な私はpkgを探してsysutils/ddptがGNU ddスタイルのフラグを受け付けることを見つけた。というわけでddptで再度測定。

```shell-session
# ddpt if=/home/mzaki/testdata of=/dev/nvd0p3 bs=1M count=1024 oflag=direct,sync
1024+0 records in
1024+0 records out
time to transfer data: 1.518513 secs at 707.10 MB/sec
# ddpt if=/home/mzaki/testdata of=/dev/nvd0p3 bs=1M count=1024 oflag=direct,sync,nowrite
1024+0 records in
0+0 records out
time to transfer data: 0.236437 secs at 4541.34 MB/sec
# ddpt if=/dev/nvd0p3 of=/dev/null bs=1M count=1024 iflag=direct,sync
1024+0 records in
0+0 records out
time to read data: 2.064107 secs at 520.20 MB/sec
```

見ての通りdd(1）のときとほぼ同じ結果となった。書き込み性能が不当に高評価されているわけではなく、やはり「Direct I/Oじゃないから」説は関係なさそう。

ちなみにbufferを1Gにしてみても読み出し性能は少ししか改善しなかった。

```shell-session
# ddpt if=/dev/nvd0p3 of=/dev/null bs=1024M count=1 iflag=direct,sync
1+0 records in
0+0 records out
time to read data: 1.965627 secs at 546.26 MB/sec
```

#ファイルシステム経由
ちなみにデバイスドライバ直接ではなく、ファイルシステム経由での読み書きだとどうなるか。このNVMeディスク上にあるZFSプールを使って読み書きしてみよう。

```shell-session
# zpool status zroot
  pool: zroot
 state: ONLINE
  scan: none requested
config:

        NAME        STATE     READ WRITE CKSUM
        zroot       ONLINE       0     0     0
          nvd0p4    ONLINE       0     0     0

errors: No known data errors
# zfs list zroot/tmp
NAME        USED  AVAIL  REFER  MOUNTPOINT
zroot/tmp  1.87G   223G  1.87G  /tmp
```

上と同様に準備したHDD上のテストデータをNVMe上の/tmpに書き込む。まずnowriteフラグを付け数回実行して確実にキャッシュに読み込まれていることを確認しているが、以下ではそれぞれ最後の1回だけ表示している。ファイルシステムへの書き込み性能は3400MB/sほどで、direct指定の有無は関係がなかった。一方syncを指定すると顕著に遅くなることから、3400MB/sというのはZFSのオンメモリキャッシュに対する書き込み性能だと考えられる。とするとdirect指定ってなんなんだろう？

```shell-session
# rm -f /tmp/testdata
# ddpt if=/home/mzaki/testdata of=/tmp/testdata bs=1m count=1024 oflag=nowrite
1024+0 records in
0+0 records out
time to transfer data: 0.147262 secs at 7291.37 MB/sec
# ddpt if=/home/mzaki/testdata of=/tmp/testdata bs=1m count=1024
1024+0 records in
1024+0 records out
time to transfer data: 0.311718 secs at 3444.59 MB/sec
# ddpt if=/home/mzaki/testdata of=/tmp/testdata bs=1m count=1024 oflag=direct,nowrite
1024+0 records in
0+0 records out
time to transfer data: 0.140797 secs at 7626.17 MB/sec
# ddpt if=/home/mzaki/testdata of=/tmp/testdata bs=1m count=1024 oflag=direct
1024+0 records in
1024+0 records out
time to transfer data: 0.309365 secs at 3470.79 MB/sec
# ddpt if=/home/mzaki/testdata of=/tmp/testdata bs=1m count=1024 oflag=sync,nowrite
1024+0 records in
0+0 records out
time to transfer data: 0.146672 secs at 7320.70 MB/sec
# ddpt if=/home/mzaki/testdata of=/tmp/testdata bs=1m count=1024 oflag=sync
1024+0 records in
1024+0 records out
time to transfer data: 6.255113 secs at 171.66 MB/sec
```

次に読み出してみる。以下は毎回再起動して定常状態になってから実行している。ファイルシステムからの読み出し性能は1500MB/sくらいで、やはりdirect指定の有無は関係がなかった。やっぱり書き込みの方が読み込みより速いなぁ。HDD上のファイルシステムから読み出すよりも非常に速いのは予想通り。

```shell-session
# ddpt if=/tmp/testdata of=/dev/null bs=1m count=1024
1024+0 records in
0+0 records out
time to read data: 0.725800 secs at 1479.39 MB/sec
# ddpt if=/tmp/testdata of=/dev/null bs=1m count=1024 iflag=direct
1024+0 records in
0+0 records out
time to read data: 0.723009 secs at 1485.10 MB/sec
# ddpt if=/home/mzaki/testdata of=/dev/null bs=1m count=1024
1024+0 records in
0+0 records out
time to read data: 6.081462 secs at 176.56 MB/sec
```

ここでZFSのprefetchを無効にしてみると1000MB/sくらいに性能が低下した。HDDの場合も性能低下がはっきりしている。

```shell-session
# sysctl vfs.zfs.prefetch_disable=1
vfs.zfs.prefetch_disable: 0 -> 1
# ddpt if=/tmp/testdata of=/dev/null bs=1m count=1024
1024+0 records in
0+0 records out
time to read data: 1.018453 secs at 1054.29 MB/sec
# ddpt if=/home/mzaki/testdata of=/dev/null bs=1m count=1024
1024+0 records in
0+0 records out
time to read data: 8.260707 secs at 129.98 MB/sec
```

#nvmecontrol perftest
[nvme(4)](https://www.freebsd.org/cgi/man.cgi?sektion=4&query=nvme)にはデバイスドライバ内蔵の[性能測定コード](https://svnweb.freebsd.org/base/head/sys/dev/nvme/nvme_test.c?view=markup)があり、`nvmecontrol perftest`で実行できる。ソースコードを斜め読みした感じでは、スレッド毎に特定のセクタをひたすら繰り返し読み書きしているみたい。

使用中のデバイスなので書き込みはできないけど、読み出しを測定してみると、IOPSはブロックサイズ4kで至適で、それを超えるとIOPSが下がり、スループットはカタログ値をやや超えた2200MB/sで頭打ちになる。少なくともハードウェアに近い低レベルのところではカタログ通りの読み出し性能が出ている。

```shell-session
# for size in 512 1024 2048 4096 8192 16384 32768 65536 131072; do nvmecontrol perftest -n 16 -o read -s $size -t 10 nvme0ns1; sleep 10; done
Threads: 16 Size:    512  READ Time:  10 IO/s:   93490 MB/s:   45
Threads: 16 Size:   1024  READ Time:  10 IO/s:   93653 MB/s:   91
Threads: 16 Size:   2048  READ Time:  10 IO/s:   93562 MB/s:  182
Threads: 16 Size:   4096  READ Time:  10 IO/s:  101982 MB/s:  398
Threads: 16 Size:   8192  READ Time:  10 IO/s:   72682 MB/s:  567
Threads: 16 Size:  16384  READ Time:  10 IO/s:   55116 MB/s:  861
Threads: 16 Size:  32768  READ Time:  10 IO/s:   51139 MB/s: 1598
Threads: 16 Size:  65536  READ Time:  10 IO/s:   34957 MB/s: 2184
Threads: 16 Size: 131072  READ Time:  10 IO/s:   17643 MB/s: 2205
```

ここでデバイスドライバ直接ではなくbioを経由してアクセスするよう指示すると、おおよそ600MB/sくらいで頭打ちになる。これがdd(1)で見ている読み出し性能をキャップしているのかな。

```shell-session
# for size in 512 1024 2048 4096 8192 16384 32768 65536 131072; do nvmecontrol perftest -n 16 -i bio -o read -s $size -t 10 nvme0ns1; sleep 10; done
Threads: 16 Size:    512  READ Time:  10 IO/s:  126572 MB/s:   61
Threads: 16 Size:   1024  READ Time:  10 IO/s:  125864 MB/s:  122
Threads: 16 Size:   2048  READ Time:  10 IO/s:  144136 MB/s:  281
Threads: 16 Size:   4096  READ Time:  10 IO/s:  143932 MB/s:  562
Threads: 16 Size:   8192  READ Time:  10 IO/s:   62477 MB/s:  488
Threads: 16 Size:  16384  READ Time:  10 IO/s:   34321 MB/s:  536
Threads: 16 Size:  32768  READ Time:  10 IO/s:   18876 MB/s:  589
Threads: 16 Size:  65536  READ Time:  10 IO/s:    9739 MB/s:  608
Threads: 16 Size: 131072  READ Time:  10 IO/s:    4908 MB/s:  613
```

[続きはWebで](https://qiita.com/mzaki/items/183e2d5751f4bf4c9450)。

#デバイスの詳細
```log:dmesgから抜粋
pcib1: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pcib1: _OSC returned error 0x10
pci1: <ACPI PCI bus> on pcib1
pcib2: <ACPI PCI-PCI bridge> irq 47 at device 1.0 on pci1
pci2: <ACPI PCI bus> on pcib2
nvme0: <Generic NVMe Device> mem 0xf3100000-0xf3103fff irq 26 at device 0.0 on pci2
nvd0: <WDC WDS256G1X0C-00ENX0> NVMe namespace
nvd0: 244198MB (500118192 512 byte sectors)
```

```shell-session
# nvmecontrol devlist
 nvme0: WDC WDS256G1X0C-00ENX0
    nvme0ns1 (244198MB)
# nvmecontrol identify nvme0
Controller Capabilities/Features
================================
Vendor ID:                  15b7
Subsystem Vendor ID:        1b4b
Serial Number:              18********89
Model Number:               WDC WDS256G1X0C-00ENX0
Firmware Version:           B35900WD
Recommended Arb Burst:      2
IEEE OUI Identifier:        44 1b 00
Multi-Interface Cap:        00
Max Data Transfer Size:     131072

Admin Command Set Attributes
============================
Security Send/Receive:       Supported
Format NVM:                  Supported
Firmware Activate/Download:  Supported
Abort Command Limit:         5
Async Event Request Limit:   8
Number of Firmware Slots:    2
Firmware Slot 1 Read-Only:   No
Per-Namespace SMART Log:     No
Error Log Page Entries:      64
Number of Power States:      5

NVM Command Set Attributes
==========================
Submission Queue Entry Size
  Max:                       64
  Min:                       64
Completion Queue Entry Size
  Max:                       16
  Min:                       16
Number of Namespaces:        1
Compare Command:             Not Supported
Write Uncorrectable Command: Supported
Dataset Management Command:  Supported
Volatile Write Cache:        Present
# nvmecontrol identify nvme0ns1
Size (in LBAs):              500118192 (476M)
Capacity (in LBAs):          500118192 (476M)
Utilization (in LBAs):       500118192 (476M)
Thin Provisioning:           Not Supported
Number of LBA Formats:       2
Current LBA Format:          LBA Format #00
LBA Format #00: Data Size:   512  Metadata Size:     0
LBA Format #01: Data Size:  4096  Metadata Size:     0
# gpart show nvd0
=>       40  500118112  nvd0  GPT  (238G)
         40     409600     1  efi  (200M)
     409640       1024     2  freebsd-boot  (512K)
     410664        984        - free -  (492K)
     411648    4194304     3  freebsd-swap  (2.0G)
    4605952  495511552     4  freebsd-zfs  (236G)
  500117504        648        - free -  (324K)

```