Spring Boot + Spring Integration でいろいろ試してみる ( その44 )( Docker Compose でサーバを構築する、Kafka 編11 - kafka-producer-perf-test、kafka-consumer-perf-test コマンドでパフォーマンスを確認する )
概要
記事一覧はこちらです。
パフォーマンスのテストをするために kafka-producer-perf-test、kafka-consumer-perf-test というコマンドが用意されていましたので、それらを利用して今の環境でどれくらいのパフォーマンスを出せるのか確認してみます。
参照したサイト・書籍
ably77/DCOS-Kafka-Performance
https://github.com/ably77/DCOS-Kafka-Performanceueokande/benchmark-commands.md
https://gist.github.com/ueokande/b96eadd798fff852551b80962862bfb3Benchmarking Kafka!
https://blog.clairvoyantsoft.com/benchmarking-kafka-e7b7c289257dPerformance testing in Kafka
https://stackoverflow.com/questions/50753980/performance-testing-in-kafkaKafka to the Maxka - (Kafka Performance Tuning)
https://www.slideshare.net/Hadoop_Summit/kafka-to-the-maxka-kafka-performance-tuningめざせ!Kafkaマスター ~Apache Kafkaで最高の性能を出すには~
https://www.ospn.jp/osc2017.enterprise/pdf/OSC2017.enterprise_Hitachi_Kafka.pdfConfluent Platform CLI Tools
https://docs.confluent.io/current/installation/cli-reference.html- 今回の調査中にコマンド一覧を見つけたのでメモしておきます。
目次
- パフォーマンスを確認する方針を決める
- kafka-producer-perf-test、kafka-consumer-perf-test 実行用のコンテナを起動するための docker-compose.perftest.yml を作成する
- 確認手順
- partition x 3 の場合 throughput はどこまで指定可能か?
- partition x 9 の場合 throughput はどこまで指定可能か?
- kafka-consumer-groups コマンドで登録されている offset を削除する
- 最後に
手順
パフォーマンスを確認する方針を決める
- kafka-producer-perf-test でメッセージを送信し、kafka-consumer-perf-test コマンドでメッセージを受信することでパフォーマンスを確認します。
- kafka-producer-perf-test、kafka-consumer-perf-test コマンドを実行するコンテナはそれぞれ専用のものを Docker Compose で構築します。コンテナのイメージには confluentinc/cp-kafka:5.3.0 を使用します。また zookeeper も cp-zookeeper1~3 とは別に kafka-producer-perf-test、kafka-consumer-perf-test コマンド実行用コンテナ専用のものを構築します。
- topic は
Topic1
という名前のものを作成します。partition 数は確認時の条件に合わせて変更しますが、replication-factor は 3 固定です。 - kafka-producer-perf-test コマンドのオプションの内、以下のものは固定の値を指定します。
--topic Topic1
--record-size 250
--producer-props acks=1 buffer.memory=67108864 compression.type=none batch.size=8196 bootstrap.servers=cp-kafka1:19092,cp-kafka2:29092,cp-kafka3:39092
(buffer.memory、compression.type、batch.size はデフォルト値ですが明示的に指定しています)
- kafka-consumer-perf-test コマンドのオプションの内、以下のものは固定の値を指定します。
--broker-list cp-kafka1:19092,cp-kafka2:29092,cp-kafka3:39092
--topic Topic1
--group topic1-perftest-group
--timeout 300000
- 可変にするのは以下の値です。
- topic の partition 数
- kafka-producer-perf-test コマンドの
--throughput
オプションの値(秒あたりの送信メッセージ件数がこの値に近くなるよう自動調整されます)--num-records
オプションの値は--throughput
オプションに指定する値が 1000未満の場合には 100000(10万)、5000未満の場合には 1000000(100万)、それ以上の場合には 5000000(500万)にします。
- kafka-consumer-perf-test コマンドの
--threads
オプション(topic の partition 数に合わせます)--messages
オプションの値は kafka-producer-perf-test コマンドの--num-records
オプションの値に合わせます。
kafka-producer-perf-test、kafka-consumer-perf-test 実行用のコンテナを起動するための docker-compose.perftest.yml を作成する
プロジェクトのルートディレクトリ直下に docker-compose.perftest.yml というファイルを新規作成し、以下の内容を記述します。
# docker-compose -f docker-compose.perftest.yml up -d # docker-compose -f docker-compose.perftest.yml down version: '3' services: cp-zookeeper-perf-test: image: confluentinc/cp-zookeeper:5.3.0 container_name: cp-zookeeper-perf-test environment: ZOOKEEPER_CLIENT_PORT: 2181 ZOOKEEPER_TICK_TIME: 2000 ZOOKEEPER_INIT_LIMIT: 5 ZOOKEEPER_SYNC_LIMIT: 2 # kafka-producer-perf-test コマンド実行用 # docker exec -it cp-kafka-producer-perf-test /bin/bash cp-kafka-producer-perf-test: image: confluentinc/cp-kafka:5.3.0 container_name: cp-kafka-producer-perf-test environment: KAFKA_ZOOKEEPER_CONNECT: cp-zookeeper-perf-test:2181 KAFKA_ADVERTISED_LISTENERS: PLAINTEXT://cp-kafka-producer-perf-test:9092 depends_on: - cp-zookeeper-perf-test # kafka-consumer-perf-test コマンド実行用 # docker exec -it cp-kafka-consumer-perf-test /bin/bash cp-kafka-consumer-perf-test: image: confluentinc/cp-kafka:5.3.0 container_name: cp-kafka-consumer-perf-test environment: KAFKA_ZOOKEEPER_CONNECT: cp-zookeeper-perf-test:2181 KAFKA_ADVERTISED_LISTENERS: PLAINTEXT://cp-kafka-consumer-perf-test:9092 depends_on: - cp-zookeeper-perf-test networks: default: external: name: ksbysample-eipapp-kafka_default
確認手順
パフォーマンスは以下の手順で確認します(1度書いた後に手順追加しているため画像に一貫性はありません)。
docekr-compose up -d
コマンドでコンテナを起動します。docker-compose -f docker-compose.perftest.yml up -d
コマンドで perf-test コマンド実行用のコンテナを起動します。http://localhost:1936/haproxy-cp-schema-registry?stats にアクセスして cp-schema-registry のステータスが全て緑になるまで待機します。
cp-kafka1 コンテナに接続し、topic を作成します。この時 partition 数を指定します。
kafka-topics --zookeeper cp-zookeeper1:12181 --create --topic Topic1 --partitions <パーティション数> --replication-factor 3 --if-not-exists
以下のコマンドを実行して cp-kafka-producer-perf-test、cp-kafka-consumer-perf-test コンテナに接続した後、実行用のコマンドを入力します(ただしまだ実行はしません)。
- kafka-producer-perf-test コマンド用
docker exec -it cp-kafka-producer-perf-test /bin/bash
kafka-producer-perf-test --topic Topic1 --num-records <送受信するレコード数(例:1000000)> --record-size 250 --throughput <ここに秒あたりの送信レコード数を指定する(例:100)> --producer-props acks=1 buffer.memory=67108864 compression.type=none batch.size=8196 bootstrap.servers=cp-kafka1:19092,cp-kafka2:29092,cp-kafka3:39092
- kafka-consumer-perf-test コマンド用
docker exec -it cp-kafka-consumer-perf-test /bin/bash
kafka-consumer-perf-test --threads <スレッド数、topic の partition 数と同じ値を指定する> --broker-list cp-kafka1:19092,cp-kafka2:29092,cp-kafka3:39092 --messages <送受信するレコード数(例:1000000)> --topic Topic1 --group topic1-perftest-group --timeout 300000
- kafka-producer-perf-test コマンド用
まず kafka-consumer-perf-test コマンドを実行します。topic の partition に対する group の offset を登録します。
kafka-consumer-perf-test コマンド実行前は topic の partition に対する group の offset は登録されていませんが、
kafka-consumer-perf-test コマンドを実行すると、
topic の partition に対する group の offset が登録されます。この時点ではメッセージの送受信が行われていないので CURRENT-OFFSET、LOG-END-OFFSET、LAG は全て 0 です。
kafka-producer-perf-test コマンドを実行します。
メッセージ送受信中の lag の確認は kafka-consumer-groups コマンドか Grafana の Kafka Lag Exporter で確認します。
kafka-consumer-groups --bootstrap-server cp-kafka1:19092,cp-kafka2:29092,cp-kafka3:39092 --describe --group topic1-perftest-group --timeout 300000
コマンドを実行するとその時の lag が表示されます。ただしこのコマンドは応答が返ってくるまで少し時間がかかります。Grafana の Kafka Lag Exporter では「Consumer Group Max Lag Offsets」「Consumer Group Lag Partition Offsets」と「Consumer Group Lag In Time Per Group Over Offset Lag」の上のグラフの黄色の線の方を見ます。
10万レコードを送信し終わると kafka-producer-perf-test、kafka-consumer-perf-test コマンドがほぼ同時に終わります。
kafka-producer-perf-test コマンドからは以下の情報が出力されます(最後の4つが何かよく分かりませんでした)。
--print-metrics
オプションを指定すればより詳細な metrics が出力されます。100000 records sent 999.440313 records/sec (0.24 MB/sec) 88.55 ms avg latency 653.00 ms max latency 68 ms 50th 235 ms 95th 367 ms 99th 536 ms 99.9th kafka-consumer-perf-test コマンドからは以下の情報が出力されます。
start.time 2019-09-22 03:11:23:490 end.time 2019-09-22 03:13:06:721 data.consumed.in.MB 23.8419 MB.sec 0.2310 data.consumed.in.nMsg 100000 nMsg.sec 968.7013 rebalance.time.ms 3159 fetch.time.ms 100072 fetch.MB.sec 0.2382 fetch.nMsg.sec 999.2805 コマンド終了後の offset を確認すると CURRENT-OFFSET と LOG-END-OFFSET が同じ値になっており、LAG も 0 になっています。
docker-compose -f docker-compose.perftest.yml down
、docekr-compose down
コマンドでコンテナを停止します。メッセージを大量に送受信した結果ディスクを消費していますので
docker volume prune
コマンドで削除します。この作業は毎回ではなくしばらくやった後でも構いません。大量にメッセージを送受信すると Docker 自体が不安定になるかもしれません。不安定になっていると感じたら Docker 本体を再起動してください。
partition x 3 の場合 throughput はどこまで指定可能か?
kafka-producer-perf-test コマンドの出力結果は以下の通りでした。
--throughput 50 |
--throughput 100 |
--throughput 150 |
---|---|---|
100000 records sent | 100000 records sent | 100000 records sent |
49.998700 records/sec (0.01 MB/sec) | 99.999200 records/sec (0.02 MB/sec) | 149.985751 records/sec (0.04 MB/sec) |
3.39 ms avg latency | 7.73 ms avg latency | 18.07 ms avg latency |
592.00 ms max latency | 887.00 ms max latency | 1096.00 ms max latency |
2 ms 50th | 2 ms 50th | 2 ms 50th |
8 ms 95th | 30 ms 95th | 106 ms 95th |
27 ms 99th | 94 ms 99th | 245 ms 99th |
115 ms 99.9th | 393 ms 99.9th | 500 ms 99.9th |
--throughput 200 |
--throughput 500 |
--throughput 1000 |
---|---|---|
100000 records sent | 100000 records sent | 1000000 records sent |
199.990800 records/sec (0.05 MB/sec) | 499.640259 records/sec (0.12 MB/sec) | 999.835027 records/sec (0.24 MB/sec) |
24.33 ms avg latency | 70.29 ms avg latency | 64.27 ms avg latency |
607.00 ms max latency | 1068.00 ms max latency | 967.00 ms max latency |
4 ms 50th | 54 ms 50th | 44 ms 50th |
124 ms 95th | 199 ms 95th | 200 ms 95th |
242 ms 99th | 333 ms 99th | 357 ms 99th |
420 ms 99.9th | 522 ms 99.9th | 595 ms 99.9th |
--throughput 5000 |
--throughput 10000 |
--throughput 20000 |
---|---|---|
5000000 records sent | 5000000 records sent | 5000000 records sent |
4998.520438 records/sec (1.19 MB/sec) | 8417.465905 records/sec (2.01 MB/sec) | 7975.550153 records/sec (1.90 MB/sec) |
80.29 ms avg latency | 28588.07 ms avg latency | 30396.65 ms avg latency |
3520.00 ms max latency | 68596.00 ms max latency | 104988.00 ms max latency |
31 ms 50th | 29904 ms 50th | 15809 ms 50th |
200 ms 95th | 52302 ms 95th | 95187 ms 95th |
1809 ms 99th | 61605 ms 99th | 102926 ms 99th |
3103 ms 99.9th | 67960 ms 99.9th | 104409 ms 99.9th |
kafka-consumer-perf-test コマンドの出力結果は以下の通りでした。
--throughput 50 |
--throughput 100 |
--throughput 150 |
|
---|---|---|---|
start.time | 2019-09-22 10:03:49:071 | 2019-09-22 12:46:33:432 | 2019-09-23 00:08:07:191 |
end.time | 2019-09-22 10:37:10:303 | 2019-09-22 13:03:14:996 | 2019-09-23 00:19:15:541 |
data.consumed.in.MB | 23.8419 | 23.8419 | 23.8419 |
MB.sec | 0.0119 | 0.0238 | 0.0357 |
data.consumed.in.nMsg | 100000 | 100000 | 100000 |
nMsg.sec | 49.9692 | 99.8438 | 149.6222 |
rebalance.time.ms | 3309 | 3416 | 3871 |
fetch.time.ms | 1997923 | 998148 | 664479 |
fetch.MB.sec | 0.0119 | 0.0239 | 0.0359 |
fetch.nMsg.sec | 50.0520 | 100.1855 | 150.4938 |
--throughput 200 |
--throughput 500 |
--throughput 1000 |
|
---|---|---|---|
start.time | 2019-09-23 02:39:14:142 | 2019-09-23 03:03:18:495 | 2019-09-23 03:19:35:384 |
end.time | 2019-09-23 02:47:35:920 | 2019-09-23 03:06:43:725 | 2019-09-23 03:36:18:194 |
data.consumed.in.MB | 23.8419 | 23.8419 | 238.4186 |
MB.sec | 0.0475 | 0.1162 | 0.2378 |
data.consumed.in.nMsg | 100000 | 100000 | 1000000 |
nMsg.sec | 199.2913 | 487.2582 | 997.1979 |
rebalance.time.ms | 4296 | 4172 | 9785 |
fetch.time.ms | 497482 | 201058 | 993025 |
fetch.MB.sec | 0.0479 | 0.1186 | 0.2401 |
fetch.nMsg.sec | 201.0123 | 497.3689 | 1007.0240 |
--throughput 5000 |
--throughput 10000 |
--throughput 20000 |
|
---|---|---|---|
start.time | 2019-09-23 04:03:53:545 | 2019-09-23 04:31:34:424 | 2019-09-23 04:51:40:650 |
end.time | 2019-09-23 04:20:35:428 | 2019-09-23 04:41:31:001 | 2019-09-23 05:02:09:149 |
data.consumed.in.MB | 1192.0929 | 1192.0929 | 1192.0929 |
MB.sec | 1.1899 | 1.9982 | 1.8967 |
data.consumed.in.nMsg | 5000000 | 5000000 | 5000000 |
nMsg.sec | 4990.6027 | 8381.1478 | 7955.4621 |
rebalance.time.ms | 3930 | 5931 | 3694 |
fetch.time.ms | 997953 | 590646 | 624805 |
fetch.MB.sec | 1.1945 | 2.0183 | 1.9079 |
fetch.nMsg.sec | 5010.2560 | 8465.3075 | 8002.4968 |
--throughput 50
の時の Grafana の Kafka Lag Exporter のグラグです(時間がかかったのでこれだけ Last 1 hour に変更しています)。
--throughput 100
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 150
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 200
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 500
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 1000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 5000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 10000
の時の Grafana の Kafka Lag Exporter のグラグです。今回 --throughput
オプションで指定した値のスループットが出たのは下のグラフの黄色の線が急に落ちたところからでした(それまでは 6,000~9,000 records/sec 程度)。
--throughput 20000
の時の Grafana の Kafka Lag Exporter のグラグです。
ここまでやってみて思ったことを以下に記載します。
--throughput 5000
までは指定したスループットが出ているが、--throughput 10000
以上だと出ていない。kafka-producer-perf-test コマンドが 5秒おきに出力する records/sec を見ていると 6,000~7,000程度が限界のような気がする。--throughput 10000
以上は kafka-producer-perf-test コマンドが出力する avg latency の値も 30秒以上と急に悪化していた。- kafka-producer-perf-test コマンドで指定した
--throughput
オプションの値と kafka-consumer-perf-test コマンドが終了時に出力する nMsg.sec、fetch.nMsg.sec の件数が同じならば指定したスループットは出ていると思われる。 - 例えば
--throughput 5000
を指定して実際に 5,000 records/sec のメッセージを送信していて、Grafana の Kafka Lag Exporter に lag が 5,000 程度表示されるのは当然なのかもしれない(心配することではないのかもしれない)。最初は lag は 0 に近い方がよいと思っていたが、何度もやっているうちにそんな感じがした。 - Grafana の Kafka Lag Exporter を見ていると突然 lag in offsets の値が落ちる時があるが、なぜこうなるのか不明。
- partition 数 = 3 だと、kafka-consumer-perf-test コマンドの方で
[2019-09-23 04:14:48,147] WARN [Consumer clientId=consumer-1, groupId=topic1-perftest-group] Offset commit failed on partition Topic1-0 at offset 1079272: The request timed out. (org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
というログが 1~2件程度出力されることがあった。 - kafka-consumer-groups コマンドが出力する lag の数も確認したいと思い途中で何度か実行してみたが kafka-producer-perf-test コマンドの
--throughput
オプションの値が大きくなる程応答が遅くなった(正直かなり遅い)。また Grafana の Kafka Lag Exporter のグラフに表示されている lag 数と一致しない(kafka-consumer-groups コマンドが出力する値の方が大きい)。応答が遅い影響だろうか?
partition x 9 の場合 throughput はどこまで指定可能か?
kafka-producer-perf-test コマンドの出力結果は以下の通りでした。
--throughput 10000 |
--throughput 12000 |
--throughput 14000 |
---|---|---|
5000000 records sent | 5000000 records sent | 5000000 records sent |
9987.575456 records/sec (2.38 MB/sec) | 11993.571446 records/sec (2.86 MB/sec) | 13965.193153 records/sec (3.33 MB/sec) |
99.84 ms avg latency | 188.95 ms avg latency | 8180.31 ms avg latency |
1451.00 ms max latency | 4328.00 ms max latency | 30732.00 ms max latency |
57 ms 50th | 57 ms 50th | 3453 ms 50th |
325 ms 95th | 852 ms 95th | 26020 ms 95th |
770 ms 99th | 3241 ms 99th | 29981 ms 99th |
1291 ms 99.9th | 4164 ms 99.9th | 30537 ms 99.9th |
--throughput 16000 |
--throughput 18000 |
--throughput 20000 |
---|---|---|
5000000 records sent | 5000000 records sent | 5000000 records sent |
15766.454660 records/sec (3.76 MB/sec) | 16550.646634 records/sec (3.95 MB/sec) | 15266.056839 records/sec (3.64 MB/sec) |
12374.64 ms avg latency | 13948.77 ms avg latency | 15236.51 ms avg latency |
33281.00 ms max latency | 29037.00 ms max latency | 38270.00 ms max latency |
12813 ms 50th | 13504 ms 50th | 11244 ms 50th |
27468 ms 95th | 27285 ms 95th | 35753 ms 95th |
32314 ms 99th | 28354 ms 99th | 37608 ms 99th |
32968 ms 99.9th | 28914 ms 99.9th | 38143 ms 99.9th |
kafka-consumer-perf-test コマンドの出力結果は以下の通りでした。
--throughput 10000 |
--throughput 12000 |
--throughput 14000 |
|
---|---|---|---|
start.time | 2019-09-23 13:12:22:034 | 2019-09-23 14:27:28:905 | 2019-09-23 14:44:20:245 |
end.time | 2019-09-23 13:20:43:969 | 2019-09-23 14:34:28:852 | 2019-09-23 14:50:19:972 |
data.consumed.in.MB | 1192.0929 | 1192.0929 | 1192.0929 |
MB.sec | 2.3750 | 2.8387 | 3.3139 |
data.consumed.in.nMsg | 5000000 | 5000000 | 5000000 |
nMsg.sec | 9961.4492 | 11906.2644 | 13899.4293 |
rebalance.time.ms | 4203 | 3526 | 4455 |
fetch.time.ms | 497732 | 416421 | 355272 |
fetch.MB.sec | 2.3950 | 2.8627 | 3.3554 |
fetch.nMsg.sec | 10045.5667 | 12007.0794 | 14073.7238 |
--throughput 16000 |
--throughput 18000 |
--throughput 20000 |
|
---|---|---|---|
start.time | 2019-09-23 15:15:57:943 | 2019-09-23 15:31:05:693 | 2019-09-23 15:45:44:630 |
end.time | 2019-09-23 15:21:16:930 | 2019-09-23 15:36:09:433 | 2019-09-23 15:51:16:616 |
data.consumed.in.MB | 1192.0929 | 1192.0929 | 1192.0929 |
MB.sec | 3.7371 | 3.9247 | 3.5908 |
data.consumed.in.nMsg | 5000000 | 5000000 | 5000000 |
nMsg.sec | 15674.6200 | 16461.4473 | 15060.8761 |
rebalance.time.ms | 4074 | 4020 | 4339 |
fetch.time.ms | 314913 | 299720 | 327647 |
fetch.MB.sec | 3.7855 | 3.9774 | 3.6383 |
fetch.nMsg.sec | 15877.4011 | 16682.2368 | 15260.3259 |
--throughput 10000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 12000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 14000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 16000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 18000
の時の Grafana の Kafka Lag Exporter のグラグです。
--throughput 20000
の時の Grafana の Kafka Lag Exporter のグラグです。
ここまでやってみて思ったことを以下に記載します。
--throughput 16000
までオプションに指定した値と実際に送受信される records/sec のメッセージ件数はほぼ一致しているが、avg latency がまともなのは--throughput 12000
まで。kafka-consumer-perf-test コマンドの方も nMsg.sec が--throughput
オプションと同じなのは--throughput 16000
までだった。- kafka-producer-perf-test、kafka-consumer-perf-test コマンドでパフォーマンスを見る場合には throughput(records/sec あるいは nMsg.sec)や avg latency、max latency のような気がする。lag を見る必要は感じなかったかな。。。
kafka-consumer-groups コマンドで登録されている offset を削除する
メッセージを送受信すると offset が登録されますが、
kafka-consumer-groups --bootstrap-server cp-kafka1:19092,cp-kafka2:29092,cp-kafka3:39092 --delete --group topic1-perftest-group --timeout 300000
コマンドを実行すれば削除できます。
最後に
kafka-producer-perf-test、kafka-consumer-perf-test コマンドは、構築した kafka の環境で求める throughput と latency が出るのかを確認するには便利なコマンドだと思いました。
次は Kafka Streams、KSQL あたりをやってみるつもりです。
履歴
2019/09/29
初版発行。