はじめに
最近入社したインフラ担当のyzkagaです。
Advent Calendarに何か書こうと思ったらネタがない。。
そんな折りにKVMのゲスト側でパケットドロップが発生すると言う事態に遭遇したので、それをoprofileで眺めてみようと思った次第です。
プロファイルする前にはドロップ発生有無によって分かりやすい差が出る事を期待していました。が、断定出来るほどの事は得られません。。
その為に眺めると言う表現になっています。
今更ネタを変えるには時間がっーー
何が起こっていたのか？
ある調子の良くないKVMのゲストサーバーを見ているとパケットドロップが発生している事を確認。
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を指定していなかった事でした。
下記は望ましい設定の例です。
<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パターンから測定。
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
プロファイルを開始してからクライアントより負荷をかけます。
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中に占める実行の割合、%の値だけを見ていきます。
＃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回目の測定結果を記載しています。
＃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
＃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まで詳細にプロファイルをする元気も意味も無いぞ。。
そもそも正しい設定をすれば良いだけですからね。
何はともあれ、ホスト側でもプロファイルを実施した結果が以下になります。
＃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
＃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ホスト側では処理がかかったようにも感じます。ですがエラーの為に処理がかかったと言うよりは、パケットの再受信でコストがかかったようにも思えます。
今回のようなざっくりしたプロファイルでは、何とも判断し難いまとめにしかなりませんでした。。
どうせなら、もっと記事向けの面白い値が取れるようなものを題材にすれば良かったと反省をして終わりにさせて頂きます。