Open vSwitchでパケットロスのトラブルシューティング

Open vSwitch(OVS)を使った仮想マシン上で特定のサイトでWebページの読み込みができない事象が発生しました。仮想環境の構成は以下の通りです。

f:id:jianlan:20200612175353j:plain

VM側では下記のように外部セグメント(br-outside)と内部セグメント(br-inside)に接続されています。

jinglan@vm-linux:~$ ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: enp1s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 52:54:00:bf:71:af brd ff:ff:ff:ff:ff:ff
    inet 172.16.0.8/16 brd 172.31.255.255 scope global enp1s0
       valid_lft forever preferred_lft forever
    inet6 fe80::5054:ff:febf:71af/64 scope link
       valid_lft forever preferred_lft forever
3: enp7s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 52:54:00:ae:d2:98 brd ff:ff:ff:ff:ff:ff
    inet6 2400::feae/64 scope global dynamic mngtmpaddr
       valid_lft 2591933sec preferred_lft 604733sec
    inet6 fe80::d298/64 scope link
       valid_lft forever preferred_lft forever

まず、通信を確認します。

jinglan@vm-linux:~$ curl -k https://www.example.net/
<!DOCTYPE html>
<html><head>
  <title>TEST</title>
</head><body>
  <img src="img.png">
</body></html>

HTML自体は読み込むことができます。続いて、画像リソースを試します。

jinglan@vm-linux:~$ curl -k https://www.example.net/img.png
curl: (56) OpenSSL SSL_read: SSL_ERROR_SYSCALL, errno 104

要求がタイムアウトし読み込むことができません。念のため、pingによりロスが発生するか確認します。

jinglan@vm-linux:~$ ping www.example.net -c 20
PING www.example.net(www.example.net (2401::6)) 56 data bytes
(略)
--- www.example.net ping statistics ---
20 packets transmitted, 20 received, 0% packet loss, time 52ms
rtt min/avg/max/mdev = 25.105/25.518/26.138/0.326 ms
jinglan@vm-linux:~$

pingによるロスはないため通信経路上の可能性は低くなります。続いて、tsharkによるパケットキャプチャにより解析します。

jinglan@vm-linux:~$ sudo tshark -i enp7s0
Capturing on 'enp7s0'
    3 12.147649629 2400::feae ? 2401::6 TCP 94 37256 ? 443 [SYN] Seq=0 Win=64800 Len=0 MSS=1440 SACK_PERM=1 TSval=1001037672 TSecr=0 WS=64
    4 12.178062944 2401::6 ? 2400::feae TCP 96 443 ? 37256 [SYN, ACK] Seq=0 Ack=1 Win=28560 Len=0 MSS=1440 SACK_PERM=1 TSval=2917789360 TSecr=1001037672 WS=64
    5 12.178201144 2400::feae ? 2401::6 TCP 86 37256 ? 443 [ACK] Seq=1 Ack=1 Win=64832 Len=0 TSval=1001037702 TSecr=2917789360
    6 12.178781920 2400::feae ? 2401::6 ICMPv6 91 Echo (ping) request id=0x2d02, seq=9728, hop limit=64
    7 12.181938940 2400::feae ? 2401::6 TLSv1 603 Client Hello
    8 12.204432618 2401::6 ? 2400::feae ICMPv6 93 Echo (ping) reply id=0x2d02, seq=9728, hop limit=50 (request in 6)
    9 12.208828328 2401::6 ? 2400::feae TCP 88 443 ? 37256 [ACK] Seq=1 Ack=518 Win=29632 Len=0 TSval=2917789391 TSecr=1001037706
   10 12.209173463 2401::6 ? 2400::feae TLSv1.2 1426 Server Hello, Certificate, Server Key Exchange, Server Hello Done
   11 12.209221425 2400::feae ? 2401::6 TCP 86 37256 ? 443 [ACK] Seq=518 Ack=1339 Win=64128 Len=0 TSval=1001037733 TSecr=2917789392
   12 12.213361297 2400::feae ? 2401::6 TLSv1.2 179 Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
   13 12.237201720 2401::6 ? 2400::feae TLSv1.2 378 New Session Ticket, Change Cipher Spec, Encrypted Handshake Message
   14 12.260303449 2400::feae ? 2401::6 TLSv1.2 513 Application Data
   15 12.285520418 2401::6 ? 2400::feae TLSv1.2 864 [TCP Previous segment not captured] , Ignored Unknown Record
   16 12.285595307 2400::feae ? 2401::6 TCP 98 [TCP Dup ACK 14#1] 37256 ? 443 [ACK] Seq=1038 Ack=1629 Win=64128 Len=0 TSval=1001037810 TSecr=2917789422 SLE=10197 SRE=10973
   17 17.288850168 2401::6 ? 2400::feae TLSv1.2 119 Encrypted Alert
   18 17.288955979 2400::feae ? 2401::6 TCP 98 [TCP Dup ACK 14#2] 37256 ? 443 [ACK] Seq=1038 Ack=1629 Win=64128 Len=0 TSval=1001042813 TSecr=2917789422 SLE=10197 SRE=11005

挙動を見ると、後半に[TCP Previous segment not captured]とEncrypted Alert、TCP Dup ACKが確認できます。Encrypted Alertは、一部キャプチャができなかったため暗号化された通信を解析できなかったことを示します。TCP Dup ACKはパケットロスにおり再送を要求しています。方向を見るとクライアント側(2400::feae)からサーバ(2401::6)へ送っていることがわかります。

ethtoolを使いNICの状態を確認します。

jinglan@vm-linux:~$ sudo ethtool -S enp7s0
NIC statistics:
     rx_packets: 190518
     tx_packets: 592
     rx_bytes: 33578858
     tx_bytes: 15763799
     rx_broadcast: 4
     tx_broadcast: 0
     rx_multicast: 358
     tx_multicast: 8
     rx_errors: 0
     tx_errors: 0
     tx_dropped: 0
     multicast: 358
     collisions: 0
     rx_length_errors: 0
     rx_over_errors: 0
     rx_crc_errors: 0
     rx_frame_errors: 0
     rx_no_buffer_count: 0
     rx_missed_errors: 0
     tx_aborted_errors: 0
     tx_carrier_errors: 0
     tx_fifo_errors: 0
     tx_heartbeat_errors: 0
     tx_window_errors: 0
     tx_abort_late_coll: 0
     tx_deferred_ok: 0
     tx_single_coll_ok: 0
     tx_multi_coll_ok: 0
     tx_timeout_count: 0
     tx_restart_queue: 0
     rx_long_length_errors: 0
     rx_short_length_errors: 0
     rx_align_errors: 0
     tx_tcp_seg_good: 0
     tx_tcp_seg_failed: 0
     rx_flow_control_xon: 0
     rx_flow_control_xoff: 0
     tx_flow_control_xon: 0
     tx_flow_control_xoff: 0
     rx_csum_offload_good: 229
     rx_csum_offload_errors: 0
     rx_header_split: 0
     alloc_rx_buff_failed: 0
     tx_smbus: 0
     rx_smbus: 0
     dropped_smbus: 0
     rx_dma_failed: 0
     tx_dma_failed: 0
     rx_hwtstamp_cleared: 0
     uncorr_ecc_errors: 0
     corr_ecc_errors: 0
     tx_hwtstamp_timeouts: 0
     tx_hwtstamp_skipped: 0

rx_errorsやtx_errorsが共に0のためVM上ではパケットを破棄していません。

今度は、仮想環境のホスト側を調査します。ovs-vsctlでブリッジの状態を確認します。

jinglan@host:~$ sudo ovs-vsctl show
adb46660-6664-4346-ac81-faa417b0b793
    Bridge br-outside
        Port "enx18c2bf547ad4"
            Interface "enx18c2bf547ad4"
        Port br-outside
            Interface br-outside
                type: internal

OVSのブリッジは物理NICのenx18c2bf547ad4に接続されています。ブリッジのMACアドレステーブルを確認します。

jinglan@host:~$ sudo ovs-appctl fdb/show br-outside
 port  VLAN  MAC                Age
LOCAL     0  52:54:00:d6:aa:71   16
LOCAL     0  52:54:00:ae:d2:98    5
    1     0  00:12:e2:70:f1:f4    5
    1     0  00:12:e2:70:c9:75    1
LOCAL     0  52:54:00:99:77:84    1

ブリッジにVMのMACアドレスが見えており、正常に接続されていることが確認できます。続いてポートの状態を確認します。

jinglan@host:~$ sudo ovs-ofctl dump-ports br-outside
OFPST_PORT reply (xid=0x2): 2 ports
  port  enx18c2bf547ad4: rx pkts=15974409, bytes=20286845338, drop=0, errs=0, frame=0, over=0, crc=0
           tx pkts=10378604, bytes=1155053709, drop=0, errs=0, coll=0
  port LOCAL: rx pkts=15972192, bytes=20284180173, drop=0, errs=0, frame=0, over=0, crc=0
           tx pkts=10377874, bytes=1071920536, drop=0, errs=1284, coll=0

port LOCALにてerrsがカウントされています。VM側から再度問題のページにcurlで接続します。

jinglan@host:~$ sudo ovs-ofctl dump-ports br-outside
OFPST_PORT reply (xid=0x2): 2 ports
  port  enx18c2bf547ad4: rx pkts=15979540, bytes=20293414941, drop=0, errs=0, frame=0, over=0, crc=0
           tx pkts=10382454, bytes=1155449792, drop=0, errs=0, coll=0
  port LOCAL: rx pkts=15977305, bytes=20290722740, drop=0, errs=0, frame=0, over=0, crc=0
           tx pkts=10381724, bytes=1072285819, drop=0, errs=1302, coll=0

errsの値がカウントアップしています。ログからエラーの内容を確認してみます。

jinglan@host:~$ sudo tail /var/log/messages
Jun 12 14:28:35 host kernel: [414700.237408] br-outside: dropped over-mtu packet: 1502 > 1500
Jun 12 14:28:41 host kernel: [414705.869334] br-outside: dropped over-mtu packet: 1502 > 1500
Jun 12 14:29:18 host kernel: [414743.245290] br-outside: dropped over-mtu packet: 1502 > 1500

MTUの値が1500を超えたために破棄されたことが分かります。下記コマンドでMTUの大きなパケットを許容します。

jinglan@host:~$ sudo ovs-vsctl set int br-outside mtu_request=1502

curlで再度テストすると正常に通信が行われ、解決となりました。この追加された2バイトはUSBネットワークアダプタにより追加され、通常にNICよりも大きくなるもののようです。

仮想化技術が普及し当たり前になりましたが、それに伴い低レイヤーの知識が不要になる訳ではないと痛感しました。

夜明け前の最も暗いとき

技術的なやったことをメモするブログ

Open vSwitchでパケットロスのトラブルシューティング