Kafka 消费者测试和报告的指标答案

【问题标题】：Kafka consumer test and reported metricsKafka 消费者测试和报告的指标
【发布时间】：2020-06-26 22:03:22
【问题描述】：

我想了解 kafka 消费者测试的工作原理以及如何解释报告的一些数字，

下面是我运行的测试和我得到的输出。我的问题是

为rebalance.time.ms, fetch.time.ms, fetch.MB.sec, fetch.nMsg.sec 报告的值是1593109326098, -1593108732333, -0.0003, -0.2800；你能解释一下它是如何报告如此高和负数的吗？他们对我没有意义。
从Metric Name Value 行报告的所有内容都是由于--print-metrics 标志而报告的。默认报告的指标和使用此标志的指标有什么区别？它们是如何计算的，我在哪里可以了解它们的含义？
无论我扩展并行运行的总消费者还是扩展代理处的网络和 io 线程，consumer-fetch-manager-metrics:fetch-latency-avg 指标几乎保持不变。你能解释一下吗？随着越来越多的消费者拉取数据，延迟应该会更高；同样对于给定的消耗率，如果我减少代理处的 io 和网络线程参数，延迟不应该更高吗？

这是我运行的命令

[root@oak-clx17 kafka_2.12-2.5.0]# bin/kafka-consumer-perf-test.sh --topic topic_test8_cons_test1 --threads 1  --broker-list clx20:9092 --messages 500000000 --consumer.config config/consumer.properties --print-metrics

结果

    start.time, end.time, data.consumed.in.MB, MB.sec, data.consumed.in.nMsg, nMsg.sec, rebalance.time.ms,fetch.time.ms, fetch.MB.sec, fetch.nMsg.sec
    WARNING: Exiting before consuming the expected number of messages: timeout (10000 ms) exceeded. You can use the --timeout option to increase the timeout.
    2020-06-25 11:22:05:814, 2020-06-25 11:31:59:579, 435640.7686, 733.6922, 446096147, 751300.8463, 1593109326098, -1593108732333, -0.0003, -0.2800
     
    Metric Name                                                                                                                                    Value
    consumer-coordinator-metrics:assigned-partitions:{client-id=consumer-perf-consumer-25533-1}                                                  : 0.000
    consumer-coordinator-metrics:commit-latency-avg:{client-id=consumer-perf-consumer-25533-1}                                                   : 2.700
    consumer-coordinator-metrics:commit-latency-max:{client-id=consumer-perf-consumer-25533-1}                                                   : 4.000
    consumer-coordinator-metrics:commit-rate:{client-id=consumer-perf-consumer-25533-1}                                                          : 0.230
    consumer-coordinator-metrics:commit-total:{client-id=consumer-perf-consumer-25533-1}                                                         : 119.000
    consumer-coordinator-metrics:failed-rebalance-rate-per-hour:{client-id=consumer-perf-consumer-25533-1}                                       : 0.000
    consumer-coordinator-metrics:failed-rebalance-total:{client-id=consumer-perf-consumer-25533-1}                                               : 1.000
    consumer-coordinator-metrics:heartbeat-rate:{client-id=consumer-perf-consumer-25533-1}                                                       : 0.337
    consumer-coordinator-metrics:heartbeat-response-time-max:{client-id=consumer-perf-consumer-25533-1}                                          : 6.000
    consumer-coordinator-metrics:heartbeat-total:{client-id=consumer-perf-consumer-25533-1}                                                      : 197.000
    consumer-coordinator-metrics:join-rate:{client-id=consumer-perf-consumer-25533-1}                                                            : 0.000
    consumer-coordinator-metrics:join-time-avg:{client-id=consumer-perf-consumer-25533-1}                                                        : NaN
    consumer-coordinator-metrics:join-time-max:{client-id=consumer-perf-consumer-25533-1}                                                        : NaN
    consumer-coordinator-metrics:join-total:{client-id=consumer-perf-consumer-25533-1}                                                           : 1.000
    consumer-coordinator-metrics:last-heartbeat-seconds-ago:{client-id=consumer-perf-consumer-25533-1}                                           : 2.000
    consumer-coordinator-metrics:last-rebalance-seconds-ago:{client-id=consumer-perf-consumer-25533-1}                                           : 593.000
    consumer-coordinator-metrics:partition-assigned-latency-avg:{client-id=consumer-perf-consumer-25533-1}                                       : NaN
    consumer-coordinator-metrics:partition-assigned-latency-max:{client-id=consumer-perf-consumer-25533-1}                                       : NaN
    consumer-coordinator-metrics:partition-lost-latency-avg:{client-id=consumer-perf-consumer-25533-1}                                           : NaN
    consumer-coordinator-metrics:partition-lost-latency-max:{client-id=consumer-perf-consumer-25533-1}                                           : NaN
    consumer-coordinator-metrics:partition-revoked-latency-avg:{client-id=consumer-perf-consumer-25533-1}                                        : 0.000
    consumer-coordinator-metrics:partition-revoked-latency-max:{client-id=consumer-perf-consumer-25533-1}                                        : 0.000
    consumer-coordinator-metrics:rebalance-latency-avg:{client-id=consumer-perf-consumer-25533-1}                                                : NaN
    consumer-coordinator-metrics:rebalance-latency-max:{client-id=consumer-perf-consumer-25533-1}                                                : NaN
    consumer-coordinator-metrics:rebalance-latency-total:{client-id=consumer-perf-consumer-25533-1}                                              : 83.000
    consumer-coordinator-metrics:rebalance-rate-per-hour:{client-id=consumer-perf-consumer-25533-1}                                              : 0.000
    consumer-coordinator-metrics:rebalance-total:{client-id=consumer-perf-consumer-25533-1}                                                      : 1.000
    consumer-coordinator-metrics:sync-rate:{client-id=consumer-perf-consumer-25533-1}                                                            : 0.000
    consumer-coordinator-metrics:sync-time-avg:{client-id=consumer-perf-consumer-25533-1}                                                        : NaN
    consumer-coordinator-metrics:sync-time-max:{client-id=consumer-perf-consumer-25533-1}                                                        : NaN
    consumer-coordinator-metrics:sync-total:{client-id=consumer-perf-consumer-25533-1}                                                           : 1.000
    consumer-fetch-manager-metrics:bytes-consumed-rate:{client-id=consumer-perf-consumer-25533-1, topic=topic_test8_cons_test1}                  : 434828205.989
    consumer-fetch-manager-metrics:bytes-consumed-rate:{client-id=consumer-perf-consumer-25533-1}                                                : 434828205.989
    consumer-fetch-manager-metrics:bytes-consumed-total:{client-id=consumer-perf-consumer-25533-1, topic=topic_test8_cons_test1}                 : 460817319851.000
    consumer-fetch-manager-metrics:bytes-consumed-total:{client-id=consumer-perf-consumer-25533-1}                                               : 460817319851.000
    consumer-fetch-manager-metrics:fetch-latency-avg:{client-id=consumer-perf-consumer-25533-1}                                                  : 58.870
    consumer-fetch-manager-metrics:fetch-latency-max:{client-id=consumer-perf-consumer-25533-1}                                                  : 503.000
    consumer-fetch-manager-metrics:fetch-rate:{client-id=consumer-perf-consumer-25533-1}                                                         : 48.670
    consumer-fetch-manager-metrics:fetch-size-avg:{client-id=consumer-perf-consumer-25533-1, topic=topic_test8_cons_test1}                       : 9543108.526
    consumer-fetch-manager-metrics:fetch-size-avg:{client-id=consumer-perf-consumer-25533-1}                                                     : 9543108.526
    consumer-fetch-manager-metrics:fetch-size-max:{client-id=consumer-perf-consumer-25533-1, topic=topic_test8_cons_test1}                       : 11412584.000
    consumer-fetch-manager-metrics:fetch-size-max:{client-id=consumer-perf-consumer-25533-1}                                                     : 11412584.000
    consumer-fetch-manager-metrics:fetch-throttle-time-avg:{client-id=consumer-perf-consumer-25533-1}                                            : 0.000
    consumer-fetch-manager-metrics:fetch-throttle-time-max:{client-id=consumer-perf-consumer-25533-1}                                            : 0.000
    consumer-fetch-manager-metrics:fetch-total:{client-id=consumer-perf-consumer-25533-1}                                                        : 44889.000
    Exception in thread "main" java.util.IllegalFormatConversionException: f != java.lang.Integer
    at java.base/java.util.Formatter$FormatSpecifier.failConversion(Formatter.java:4426)
            at java.base/java.util.Formatter$FormatSpecifier.printFloat(Formatter.java:2951)
            at java.base/java.util.Formatter$FormatSpecifier.print(Formatter.java:2898)
            at java.base/java.util.Formatter.format(Formatter.java:2673)
            at java.base/java.util.Formatter.format(Formatter.java:2609)
            at java.base/java.lang.String.format(String.java:2897)
            at scala.collection.immutable.StringLike.format(StringLike.scala:354)
            at scala.collection.immutable.StringLike.format$(StringLike.scala:353)
            at scala.collection.immutable.StringOps.format(StringOps.scala:33)
            at kafka.utils.ToolsUtils$.$anonfun$printMetrics$3(ToolsUtils.scala:60)
            at kafka.utils.ToolsUtils$.$anonfun$printMetrics$3$adapted(ToolsUtils.scala:58)
            at scala.collection.mutable.ResizableArray.foreach(ResizableArray.scala:62)
            at scala.collection.mutable.ResizableArray.foreach$(ResizableArray.scala:55)
            at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:49)
            at kafka.utils.ToolsUtils$.printMetrics(ToolsUtils.scala:58)
            at kafka.tools.ConsumerPerformance$.main(ConsumerPerformance.scala:82)
            at kafka.tools.ConsumerPerformance.main(ConsumerPerformance.scala)

【问题讨论】：

标签： apache-kafka consumer

【解决方案1】：

https://medium.com/metrosystemsro/apache-kafka-how-to-test-performance-for-clients-configured-with-ssl-encryption-3356d3a0d52b 这是我写的一篇文章。

根据this KIP 的期望是 rebalance.time.ms 和 fetch.time.ms 显示消费者组的总重新平衡时间和总提取时间不包括重新平衡时间。据我所知，从 Apache Kafka 版本 2.6.0 开始，这仍在进行中，目前的输出是Unix epoch time 中的时间戳。 fetch.MB.sec 和 fetch.nMsg.sec 旨在显示每秒消耗的平均消息数量（以 MB 为单位并作为计数）

请参阅https://kafka.apache.org/documentation/#consumer_group_monitoring 以了解使用 --print-metrics 标志列出的消费者组指标
fetch-latency-avg（获取请求的平均时间）会有所不同，但这在很大程度上取决于测试设置。

【讨论】：