KVMのパケットドロップをoprofileで眺めてみた

# はじめに
最近入社したインフラ担当のyzkagaです。
Advent Calendarに何か書こうと思ったらネタがない。。
そんな折りにKVMのゲスト側でパケットドロップが発生すると言う事態に遭遇したので、それをoprofileで眺めてみようと思った次第です。

プロファイルする前にはドロップ発生有無によって分かりやすい差が出る事を期待していました。が、断定出来るほどの事は得られません。。
その為に眺めると言う表現になっています。
今更ネタを変えるには時間がっーー

# 何が起こっていたのか？
ある調子の良くないKVMのゲストサーバーを見ているとパケットドロップが発生している事を確認。

```lang:ifconfig
eth1    Link encap:Ethernet  HWaddr XX:XX:XX:XX:XX:XX  
          inet addr:XX.XX.XX.XX  Bcast:XX.XX.XX.XX  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:75791 errors:0 dropped:1503 overruns:0 frame:0
          TX packets:75853 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
```

RXでdroppedが出ている。。

そして、この原因がKVMのNIC設定でvirtioを指定していなかった事でした。
下記は望ましい設定の例です。

```lang:/etc/libvirt/qemu/guest_srv.xml
    <interface type='bridge'>
      <mac address='XX:XX:XX:XX:XX:XX'/>
      <source bridge='br01'/>
      <model type='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x0'/>
    </interface>
```
問題の発生したゲストの設定では**＜model type='virtio'/＞**の指定がありませんでした。
対象のゲストを停止して、**＜model type='virtio'/＞**を追加、起動する事でテスト環境ではdroppedの発生は無くなりました。
**＜model type='virtio'/＞**
この設定をつければ良い。と言うところで本来は話が終わります。

しかし、ネタの為に何が起こったか簡単にでも確認しようと無駄に測定を行ったのが次節以降の内容になります。

# まずは負荷測定をしてみる
以下の構成で負荷をかけてみる事にします。

|ホスト名  |役割      |
|:-------:|:-------:|
|kvmHost_srv|KVMホスト (CPU 32core、memory 128GM) |
|guest_srv  |kvmHost_srv上で動作するゲスト (CPU 4core、memory 16GB) |
|client_srv |負荷(ab)を実行するホスト (CPU 2core、memory 4GB) |

guest_srv上のapacheに対してclient_srvからabで負荷をかけてみます。
kvmHost_srv上で動作しているインスタンスはguest_srv 1台のみです。

まずは**virtio**指定の無い、NGパターンから測定。

```lang:client_srv
ab -n 15000 -c 150 http://guest_srv/health
```

guest_srvを起動してguest_srvからabを実行します。
起動直後なので、dropはありません。
ではab実行後のguest_srvのifconfgです。

```
eth1    Link encap:Ethernet  HWaddr XX:XX:XX:XX:XX:XX  
          inet addr:XX.XX.XX.XX  Bcast:XX.XX.XX.XX  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:75791 errors:0 dropped:720 overruns:0 frame:0
          TX packets:75853 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:5431844 (5.1 MiB)  TX bytes:11495694 (10.9 MiB)
          Interrupt:10 Base address:0xa000 
```

サクッとdropが発生。
同様のテストを**virtio**指定の有る、OKパターンで実施するとdropは発生しませんでした。

ではabの実行時間に差はあるのか？
timeコマンドでabの実行時間を3回ずつ確認しました。

|OKパターン||
|:--:|:--:|
|1回目|3.982sec|
|2回目|3.970sec|
|3回目|3.958sec|
|3回平均|3.97sec|

|NGパターン||
|:--:|:--:|
|1回目|4.178sec|
|2回目|4.873sec|
|3回目|4.248sec|
|3回平均|4.43sec|

サンプル数が少ないのですが、OKパターンの方が速いとは言えそうです。
この測定時、NGパターンでは毎回dropが発生し、OKパターンではdropは発生していません。

# oprofileで測定してみる
oprogileではイベントごとのサンプリングを取得し、プロフィルする事が可能です。
ではguest_srv、kvmHost_srv上でそれぞれoprofileを起動します
vmlinuxはvmlinuzから抽出するか、yumでkernel-debuginfoから取得します。

```
lang:guest_srv / kvmHost_srv
# oprofile --init
# oprofile --vmlinux=/tmp/vmlinux
# oprofile --start
```

プロファイルを開始してからクライアントより負荷をかけます。

```lang:client_srv
ab -n 15000 -c 150 http://guest_srv/index.html
```

最後にプロファイルを終了させて、レポートを表示させます。

```
lang:guest_srv / kvmHost_srv
# oprofile --stop
# oprofile --dump
# opreport -l -p /lib/modules/X.X.XX-X
```

レポートはこの様な形で出力されます。
今回はざっくりの測定なので、oprofile中に占める実行の割合、%の値だけを見ていきます。

```lang:oprofile__guest_srv(drop発生時)
＃opreport -l -p /lib/modules/X.X.XX-X/kernel/|head -6
samples  %        image name               app name                 symbol name
111414   92.9721  vmlinux                  vmlinux                  kvm_clock_read
577       0.4815  vmlinux                  vmlinux                  add_disk
496       0.4139  libXXX-1.so.0            libXXX-1.so.0            /usr/lib64/libXXX-1.so.0
410       0.3421  httpd.worker             httpd.worker             /usr/sbin/httpd.worker
313       0.2612  vmlinux                  vmlinux                  migrate_task
```

色々情報がありますが、考えられそうなパターンだけに絞って確認してみます。
1 KVMゲスト側のNICドライバあたりで処理がかかっている？
2 KVMホスト側で処理がかかっている？
3 KVMホスト側のNICドライバで処理がかかっている？(コレは可能性薄そうか)

では、まずはguest_srvのNICあたりをパケットドロップ有り、無し時に分けて確認します。
これ以降の測定は３回実行していますが、その中で大きく値が変わる事は無かったので2回目の測定結果を記載しています。

```lang:oprofile__guest_srv(drop発生時)
＃opreport -l -p /lib/modules/X.X.XX-X/kernel/| grep virt
54        0.0451  virtio_ring.ko           virtio_ring.ko           virtqueue_get_buf
23        0.0192  virtio_ring.ko           virtio_ring.ko           virtqueue_kick_prepare
18        0.0150  virtio_ring.ko           virtio_ring.ko           virtqueue_add_buf
16        0.0134  virtio_net.ko            virtio_net.ko            virtnet_poll
10        0.0083  virtio_net.ko            virtio_net.ko            start_xmit
9         0.0075  virtio_net.ko            virtio_net.ko            free_old_xmit_skbs
6         0.0050  virtio_ring.ko           virtio_ring.ko           detach_buf
5         0.0042  virtio_ring.ko           virtio_ring.ko           virtqueue_enable_cb
4         0.0033  virtio_net.ko            virtio_net.ko            xmit_skb
4         0.0033  virtio_pci.ko            virtio_pci.ko            vp_notify
2         0.0017  virtio_ring.ko           virtio_ring.ko           virtqueue_kick
```

```lang:oprofile__guest_srv(drop無し時)
＃opreport -l -p /lib/modules/X.X.XX-X/kernel/| grep virt
54        0.0451  virtio_ring.ko           virtio_ring.ko           virtqueue_get_buf
23        0.0192  virtio_ring.ko           virtio_ring.ko           virtqueue_kick_prepare
18        0.0150  virtio_ring.ko           virtio_ring.ko           virtqueue_add_buf
16        0.0134  virtio_net.ko            virtio_net.ko            virtnet_poll
10        0.0083  virtio_net.ko            virtio_net.ko            start_xmit
9         0.0075  virtio_net.ko            virtio_net.ko            free_old_xmit_skbs
6         0.0050  virtio_ring.ko           virtio_ring.ko           detach_buf
5         0.0042  virtio_ring.ko           virtio_ring.ko           virtqueue_enable_cb
4         0.0033  virtio_net.ko            virtio_net.ko            xmit_skb
4         0.0033  virtio_pci.ko            virtio_pci.ko            vp_notify
2         0.0017  virtio_ring.ko           virtio_ring.ko           virtqueue_kick
```

で、ゲスト側のvirtioを確認したけど、ここでの値だと全く差が無い。
ここで差が出ているかと思っていたんだけど。。
次、ホスト側のKVMなんて、そこまで差が出てるんだろうか？
それにKVMまで詳細にプロファイルをする元気も意味も無いぞ。。
そもそも正しい設定をすれば良いだけですからね。

何はともあれ、ホスト側でもプロファイルを実施した結果が以下になります。

```lang:oprofile__kvmHost_srv(drop発生時)
＃opreport -l -p /lib/modules/X.X.XX-X/kernel/| head -8
6195285  75.1526  kvm-intel.ko             kvm-intel.ko             vmx_vcpu_run
190204    2.3073  vmlinux                  vmlinux                  mwait_idle_with_hints
122187    1.4822  vmlinux                  vmlinux                  __domain_mapping
54689     0.6634  kvm.ko                   kvm.ko                   kvm_arch_vcpu_ioctl_run
44318     0.5376  vmlinux                  vmlinux                  ftrace_define_fields_sched_stat_runtime
32708     0.3968  oprofile.ko              oprofile.ko              sync_buffer
32328     0.3922  vmlinux                  vmlinux                  queue_rq_affinity_store
```

```lang:oprofile__kvmHost_srv(drop無し時)
＃opreport -l -p /lib/modules/X.X.XX-X/kernel/| head -8
samples  %        image name               app name                 symbol name
6463567  74.9576  kvm-intel.ko             kvm-intel.ko             vmx_vcpu_run
200429    2.3244  vmlinux                  vmlinux                  mwait_idle_with_hints
122187    1.4170  vmlinux                  vmlinux                  __domain_mapping
57464     0.6664  kvm.ko                   kvm.ko                   kvm_arch_vcpu_ioctl_run
47026     0.5454  vmlinux                  vmlinux                  ftrace_define_fields_sched_stat_runtime
34531     0.4005  vmlinux                  vmlinux                  queue_rq_affinity_store
34382     0.3987  oprofile.ko              oprofile.ko              sync_buffer
```

ドロップ発生時は若干、kvm-intel.koの数値(%)が上がっていますが。。。
確かに値は変わっているんですが、もっとサンプル数を増やすなり、更にプロファイル進めないと断定も出来ないですね。

ホスト側のNIC測定結果については割愛しますが、こちらはドロップ発生有無に関わらず特に値に変化は見られませんでした。

# まとめ
特にまとめるような結果も得られてなくて恐縮ですが、強引にまとめです！
締め切りギリギリで時間と気合いが足り無いのです。。
それらがあれば、kvm-intel.ko について更にプロフィルも…と言ったかもしれませんが。。

ドロップ発生時にはゲスト側でそれなりに分かりやすい変化があるのかな？と思って測定したのが誤りでした。
結果、値を見るとKVMホスト側では処理がかかったようにも感じます。ですがエラーの為に処理がかかったと言うよりは、パケットの再受信でコストがかかったようにも思えます。
今回のようなざっくりしたプロファイルでは、何とも判断し難いまとめにしかなりませんでした。。
どうせなら、もっと記事向けの面白い値が取れるようなものを題材にすれば良かったと反省をして終わりにさせて頂きます。