サーバ間のレイテンシ計測にsockperfを試した

背景
Docker Image作っておきました
使い方
- サーバ側
- クライアント側
サブコマンド
under-loadで計測
wireguardを経由するとどうなるのか？
まとめ

背景

ネットワークのレイテンシとかの計測したいな、と思っていた。iperf3はトラフィックを測れるけど、これはレイテンシ計測はできていない気がしていた。

諸事情でVPSとかクラウドプラットフォームのVMの性能を計測してまとめようとしている。

pingでもいいんだけど、1回リクエストしたらレスポンスが返ってくるまでを計測してもこのような用途はあまりないし、ショートパケット性能（小さいデータをたくさん送る性能）をみたいな、と調べていたらsockperfというものを見つけた。

github.com

MellanoxはNICも作ってるところ。wikiにもちょっと色々書いてある。

Home · Mellanox/sockperf Wiki · GitHub

sockperfはマイナーではなく、AzureでもNvidia（MellanoxはNvidiaに買収されているけど）で紹介されている。

sockperfはパッケージ配布されておらずビルドする必要がある。でも難しくなくて、READMEの内容で簡単にビルドできた。RHEL系もlibtool-binをlibtoolに読み替えれば入れることができた。

オプションが多すぎてよくわからんので、まずは使ってみた。

Docker Image作っておきました

最近はビルド用に色々入れることさえでも環境が汚れるのが嫌な気持ちになるので、Docker imageにしておいた。

https://hub.docker.com/r/ryozitn/sockperf

Linuxでdockerが入っていたら簡単に使えるはずです。使い方は書いてあります。

どこの馬の骨かもわからん人が作った得体のしれないものをpullするのが嫌という人もいると思います（私はそういうタイプなので公式以外は自分で書き直して使う。無駄な苦労してる）

そんな人のためにDockerfileを公開しております。中身はたったの10行程度で変なこともしてないので安心安全です。

https://github.com/ryozi-tn/sockperf-docker/blob/main/Dockerfile

本当はビルドオプションとかで最適化をかけられるっぽいんだけど、よくわかってないのでREADMEの内容でビルドしただけです。

使い方

導入はビルドするだけなのでsockperfのREADMEの内容で。ubuntu 22.04, AlmaLinux 9.3でうまくいくことを確認。面倒ならdocker imageでもご利用ください。

サーバ側

# firewallの穴あけ。ポートはデフォルトで11111なのでとりあえずそれを使う。
firewall-cmd --add-port 11111/tcp --add-port 11111/udp --permanent
firewall-cmd --reload

# 待ち受け。プロトコルはデフォルトでUDP。--tcpでTCPになる。
# IPv6のほうでlistenする場合があるのでIPv4を明示したいときは -i 0.0.0.0 
sockperf server -i 0.0.0.0

クライアント側

sockperf ping-pong -i サーバIP

サブコマンド

server: 接続を待つ

Listenしてクライアントの受付を待つ。

-i IP: 指定したIP（のインタフェース）で待ち受ける
--tcp: UDPではなくTCPで待ち受けるようになる
--daemonize: デーモン化（バックグラウンド実行）

実行するとこんな感じで待ち受け状態になる

# sockperf server -i 0.0.0.0 --tcp
sockperf: == version #3.10-23.gited92afb185e6 ==
sockperf: [SERVER] listen on:
[ 0] IP = 0.0.0.0         PORT = 11111 # TCP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: [tid 1418] using recvfrom() to block on socket(s)

under-load: 負荷をかけながら応答を計測する

多分メイン機能

-i IP: 指定したIPに対して計測する
--mps メッセージ数: 秒間の送信メッセージ数。デフォルトは10000。目標値であるため非常に大きいと全然達しないことがある、パケットの取りこぼしが増える。
-m サイズ: メッセージサイズ(byte)
-t 秒数: 実行時間(秒) デフォルトは1秒
--tcp: UDPではなくTCPで通信する
-- reply-every n: サーバ側が応答を返す頻度。デフォルト100で、これはクライアントからみて100回送ったら1回返答させるようにする、という意味になる。

オプションはいっぱいあるけど、よくわからなかった。

実行後、パーセンタイルが出て悦に浸れる。

`--mps`の補足

--mpsは指定された分を満たすように、メッセージを送信して負荷をかけようとする。これがunder-loadと呼ぶ所以と思われる。

また、通信上問題なければちゃんと相手まで届くので、相手も送り付けられたパケットを捌き切れないと、返すべきパケットで返せなくなり、ドロップが多発することになってしまう。

なので、drop messageが増えてきたら--mpsを下げるか受信側のスペックを上げる必要があるということになる。逆に送信されたメッセージ数が想定よりも少ない場合、--mpsが大きすぎるか送信側のスペックが不足していると考えられる。

`-- reply-every n`についての補足

--reply-every はサーバ側が受け取ったメッセージの内、n回に1回応答する。レイテンシの計測は返ってきたメッセージ(observations)をもって判断している。これは計測界隈でいうところのサンプルに当たる。

簡単な式にすると、 秒間の送信メッセージ数(mps) * 実行時間(t) / replyEvery ≒ サンプル数となる。replyEvery が大きくなるほどサンプル数が減る。

パーセンタイルは 99.999%まで出るので、ここまできっちり出したい場合はサンプル数が10万件をこえるように上の3つのパラメータを調整する。…というのはちょっとやりすぎな感じはする。インターネット自体そこまで安定しているモノじゃないので。

ping-pong: pingっぽい挙動をする

under-loadの時と何が違うんだ？って思って少し調べたが、pingっぽい挙動しようと頑張ろうとしている感じに見受けられた。

ざっくり言えば、以下。

時間指定の実行だけではなく、件数指定の実行ができる（…はずだけど、実際に動かせなかった。）
pingの通り、応答を受け取るようになる（under-loadはひたすら投げっぱなしだった）
--data-integrity により応答の内容が一致することを確認することができる

3.10のコードを読んでた時のメモ。

オプション
- number-of-packets(-n) 追加。これで時間ベースではなく、件数ベースでの計測ができるはず
- reply-everyが削除（1固定になる。ping-pongでは1つの送信で1つの応答を返すようにしたいため）
- mps が UINT32_MAX 固定（これも応答を待つので意味がない？）
- data-integrity追加。受け取ったデータが一致することを確認する（よくわからない。というかヘルプにはunder-loadのほうに出てるのに、オプション自体はping-pongにしかないのはミスでは…）
大きな違いは、b_client_ping_pongが有効になる点
- doSendThenReceiveLoopにより、burst_sizeの数だけ送ったらその数だけ受け取る、を繰り返すようになる
- burst_sizeのデフォルト値は1

違いを探ろうとしたけど、ping-pongの用途はあまり興味なかったのでここまで。

throughput: スループット計測

秒間のスループットを計測できる。iperf3で良くないか？と思うけど、ついでに測るぐらいには使えるかもしれない。

こちらはパーセンタイルといった指標は出てこないので、ちょっと残念な感じ。iperf3でよくないか？ってなる。

playback

よくわからない

under-loadで計測

まず最初に -t 1 等で実行して疎通できることを確認する。UDPは到達保証がないので相手の返答をもって処理しているため、疎通できなくてもそれはUDP的には正常なので待たされた挙句、ちゃんと処理できずに終わるといったことが起きる。

計測時間が10秒と狭すぎて、サンプル数が少ないときの例。

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 10 --mps 10000 --reply-every 10 -i 160.XXX.XXX.XXX
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 160.XXX.XXX.XXX PORT = 11111 # UDP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=10.000 sec; Warm up time=400 msec; SentMessages=100005; ReceivedMessages=9980
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=9.569 sec; SentMessages=95491; ReceivedMessages=9550
sockperf: ====> avg-latency=10414.973 (std-dev=292.475, mean-ad=220.454, median-ad=258.087, siqr=183.170, cv=0.028, std-error=2.993, 99.0% ci=[10407.264, 10422.682])
sockperf: # dropped messages = 0; # duplicated messages = 0; # out-of-order messages = 0
sockperf: Summary: Latency is 10414.973 usec
sockperf: Total 9550 observations; each percentile contains 95.50 observations
sockperf: ---> <MAX> observation = 13090.065
sockperf: ---> percentile 99.999 = 13090.065
sockperf: ---> percentile 99.990 = 13025.994
sockperf: ---> percentile 99.900 = 12305.607
sockperf: ---> percentile 99.000 = 11380.875
sockperf: ---> percentile 90.000 = 10773.490
sockperf: ---> percentile 75.000 = 10569.703
sockperf: ---> percentile 50.000 = 10357.035
sockperf: ---> percentile 25.000 = 10203.362
sockperf: ---> <MIN> observation = 9885.433

real    0m13.058s
user    0m0.009s
sys     0m0.023s

計測時間を60秒に伸ばした。99.99%タイルにはだいぶブレが出てきている。

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 10000 --reply-every 10 -i 160.XXX.XXX.XXX
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 160.XXX.XXX.XXX PORT = 11111 # UDP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=600005; ReceivedMessages=59915
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.569 sec; SentMessages=595471; ReceivedMessages=59481
sockperf: ====> avg-latency=10917.384 (std-dev=732.756, mean-ad=216.424, median-ad=228.385, siqr=159.503, cv=0.067, std-error=3.004, 99.0% ci=[10909.645, 10925.123])
sockperf: # dropped messages = 64; # duplicated messages = 0; # out-of-order messages = 3
sockperf: Summary: Latency is 10917.384 usec
sockperf: Total 59481 observations; each percentile contains 594.81 observations
sockperf: ---> <MAX> observation = 51134.455
sockperf: ---> percentile 99.999 = 50702.441
sockperf: ---> percentile 99.990 = 48740.305
sockperf: ---> percentile 99.900 = 18242.131
sockperf: ---> percentile 99.000 = 11674.610
sockperf: ---> percentile 90.000 = 11217.223
sockperf: ---> percentile 75.000 = 11032.988
sockperf: ---> percentile 50.000 = 10853.167
sockperf: ---> percentile 25.000 = 10713.981
sockperf: ---> <MIN> observation = 10383.069

real    1m2.968s
user    0m0.008s
sys     0m0.022s

次はそのままmpsを10万にしたところ、メッセージのドロップが多発している状態。

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 100000 --reply-every 10 -i 160.XXX.XXX.XXX
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 160.XXX.XXX.XXX PORT = 11111 # UDP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=6000016; ReceivedMessages=123254
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.600 sec; SentMessages=5947191; ReceivedMessages=122258
sockperf: ====> avg-latency=58840.769 (std-dev=3298.576, mean-ad=2464.401, median-ad=2862.134, siqr=1971.034, cv=0.056, std-error=9.434, 99.0% ci=[58816.469, 58865.069])
sockperf: # dropped messages = 473240; # duplicated messages = 0; # out-of-order messages = 1
sockperf: Summary: Latency is 58840.769 usec
sockperf: Total 122258 observations; each percentile contains 1222.58 observations
sockperf: ---> <MAX> observation = 84434.286
sockperf: ---> percentile 99.999 = 84350.111
sockperf: ---> percentile 99.990 = 83975.272
sockperf: ---> percentile 99.900 = 80795.003
sockperf: ---> percentile 99.000 = 69371.001
sockperf: ---> percentile 90.000 = 62876.051
sockperf: ---> percentile 75.000 = 60541.705
sockperf: ---> percentile 50.000 = 58380.472
sockperf: ---> percentile 25.000 = 56599.635
sockperf: ---> <MIN> observation = 51220.518

real    1m3.065s
user    0m0.000s
sys     0m0.029s

ちなみに同じ条件でLANのマシンに対して行うと安定している。なので、サーバ側で処理できていないと思われる。

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 100000 --reply-every 10 -i 192.168.XXX.XXX
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 192.168.XXX.XXX   PORT = 11111 # UDP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=6000170; ReceivedMessages=600014
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.551 sec; SentMessages=5955151; ReceivedMessages=595510
sockperf: ====> avg-latency=304.798 (std-dev=144.524, mean-ad=113.105, median-ad=156.292, siqr=105.897, cv=0.474, std-error=0.187, 99.0% ci=[304.316, 305.280])
sockperf: # dropped messages = 0; # duplicated messages = 0; # out-of-order messages = 6
sockperf: Summary: Latency is 304.798 usec
sockperf: Total 595510 observations; each percentile contains 5955.10 observations
sockperf: ---> <MAX> observation = 2867.470
sockperf: ---> percentile 99.999 = 2720.729
sockperf: ---> percentile 99.990 = 2331.875
sockperf: ---> percentile 99.900 = 1503.292
sockperf: ---> percentile 99.000 =  590.463
sockperf: ---> percentile 90.000 =  491.041
sockperf: ---> percentile 75.000 =  399.590
sockperf: ---> percentile 50.000 =  291.793
sockperf: ---> percentile 25.000 =  187.796
sockperf: ---> <MIN> observation =   43.368

ちなみにout-of-order messages は送ったメッセージ順とは異なる順で届いた数っぽい？。

TCPも可能。その際、サーバ側も--tcpオプションを付けてTCPで待ち受ける状態にすること。

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 10000 --reply-every 10 -i 160.XXX.XXX.XXX --tcp
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 160.XXX.XXX.XXX PORT = 11111 # TCP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=600000; ReceivedMessages=59980
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.567 sec; SentMessages=595471; ReceivedMessages=59548
sockperf: ====> avg-latency=10227.860 (std-dev=1153.357, mean-ad=328.798, median-ad=229.416, siqr=183.344, cv=0.113, std-error=4.726, 99.0% ci=[10215.686, 10240.034])
sockperf: # dropped messages = 0; # duplicated messages = 0; # out-of-order messages = 0
sockperf: Summary: Latency is 10227.860 usec
sockperf: Total 59548 observations; each percentile contains 595.48 observations
sockperf: ---> <MAX> observation = 41310.827
sockperf: ---> percentile 99.999 = 40892.454
sockperf: ---> percentile 99.990 = 39891.092
sockperf: ---> percentile 99.900 = 31694.354
sockperf: ---> percentile 99.000 = 11573.122
sockperf: ---> percentile 90.000 = 10599.184
sockperf: ---> percentile 75.000 = 10306.398
sockperf: ---> percentile 50.000 = 10064.742
sockperf: ---> percentile 25.000 = 9939.709
sockperf: ---> <MIN> observation = 9630.072

real    1m3.070s
user    0m0.033s
sys     0m0.007s

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 100000 --reply-every 10 -i 160.XXX.XXX.XXX --tcp
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 160.XXX.XXX.XXX PORT = 11111 # TCP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=5999989; ReceivedMessages=599021
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.600 sec; SentMessages=5950271; ReceivedMessages=595028
sockperf: ====> avg-latency=50095.818 (std-dev=8661.781, mean-ad=5597.583, median-ad=5548.840, siqr=3726.770, cv=0.173, std-error=11.229, 99.0% ci=[50066.894, 50124.742])
sockperf: # dropped messages = 476; # duplicated messages = 0; # out-of-order messages = 0
sockperf: Summary: Latency is 50095.818 usec
sockperf: Total 595028 observations; each percentile contains 5950.28 observations
sockperf: ---> <MAX> observation = 121045.617
sockperf: ---> percentile 99.999 = 120753.656
sockperf: ---> percentile 99.990 = 119770.317
sockperf: ---> percentile 99.900 = 113603.389
sockperf: ---> percentile 99.000 = 83211.026
sockperf: ---> percentile 90.000 = 57785.554
sockperf: ---> percentile 75.000 = 53038.611
sockperf: ---> percentile 50.000 = 48963.068
sockperf: ---> percentile 25.000 = 45585.070
sockperf: ---> <MIN> observation = 16341.555

real    1m3.095s
user    0m0.030s
sys     0m0.000s

UDPとくらべメッセージのドロップは減るがレイテンシが大幅に増えてしまっている。

wireguardを経由するとどうなるのか？

VPNトンネルでオーバーヘッドがーって言う話があるが、実際どんなものか見てみる。

wireguardは普通に入れて特にチューニングもしていない。サーバ側は非常に貧弱で1vCore,512MBのVPS上で動作している。計測期間や計測タイミングの影響もありそうだけど一旦気にしない。

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 10000 --reply-every 10 -i 172.30.XXX.XXX
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 172.30.XXX.XXX    PORT = 11111 # UDP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=600005; ReceivedMessages=59978
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.568 sec; SentMessages=595471; ReceivedMessages=59548
sockperf: ====> avg-latency=10529.421 (std-dev=805.115, mean-ad=250.045, median-ad=233.983, siqr=163.474, cv=0.076, std-error=3.299, 99.0% ci=[10520.923, 10537.919])
sockperf: # dropped messages = 0; # duplicated messages = 0; # out-of-order messages = 0
sockperf: Summary: Latency is 10529.421 usec
sockperf: Total 59548 observations; each percentile contains 595.48 observations
sockperf: ---> <MAX> observation = 32738.336
sockperf: ---> percentile 99.999 = 32428.636
sockperf: ---> percentile 99.990 = 31357.646
sockperf: ---> percentile 99.900 = 25564.202
sockperf: ---> percentile 99.000 = 11535.529
sockperf: ---> percentile 90.000 = 10815.435
sockperf: ---> percentile 75.000 = 10625.324
sockperf: ---> percentile 50.000 = 10440.591
sockperf: ---> percentile 25.000 = 10298.374
sockperf: ---> <MIN> observation = 9984.818

real    1m2.974s
user    0m0.001s
sys     0m0.029s

平均0.38msのレイテンシ増加。

mps=10万

$ time docker run --rm -it ryozitn/sockperf under-load -m 64 -t 60 --mps 100000 --reply-every 10 -i 172.30.XXX.XXX
sockperf: == version #3.10-23.gited92afb185e6 == 
sockperf[CLIENT] send on:sockperf: using recvfrom() to block on socket(s)

[ 0] IP = 172.30.XXX.XXX    PORT = 11111 # UDP
sockperf: Warmup stage (sending a few dummy messages)...
sockperf: Starting test...
sockperf: Test end (interrupted by timer)
sockperf: Test ended
sockperf: [Total Run] RunTime=60.000 sec; Warm up time=400 msec; SentMessages=6000012; ReceivedMessages=127174
sockperf: ========= Printing statistics for Server No: 0
sockperf: [Valid Duration] RunTime=59.598 sec; SentMessages=5948271; ReceivedMessages=126097
sockperf: ====> avg-latency=60572.512 (std-dev=4968.047, mean-ad=3916.500, median-ad=4461.047, siqr=3365.390, cv=0.082, std-error=13.991, 99.0% ci=[60536.475, 60608.549])
sockperf: # dropped messages = 469401; # duplicated messages = 0; # out-of-order messages = 1
sockperf: Summary: Latency is 60572.512 usec
sockperf: Total 126097 observations; each percentile contains 1260.97 observations
sockperf: ---> <MAX> observation = 114536.386
sockperf: ---> percentile 99.999 = 114345.399
sockperf: ---> percentile 99.990 = 113892.937
sockperf: ---> percentile 99.900 = 97946.817
sockperf: ---> percentile 99.000 = 72480.961
sockperf: ---> percentile 90.000 = 67725.835
sockperf: ---> percentile 75.000 = 63626.256
sockperf: ---> percentile 50.000 = 59378.713
sockperf: ---> percentile 25.000 = 56895.475
sockperf: ---> <MIN> observation = 50969.324

real    1m3.003s
user    0m0.000s
sys     0m0.031s

mps=10万のときは平均1.73msの減少。だけど、元々dropが多発していて不安定なので参考にもならないですが。

まとめ

pingでもいいと思います

背景