Skip to content

Commit 8586515

Browse files
committed
feat(tools/perf): log the min latency (#2608)
Signed-off-by: Ning Yu <ningyu@automq.com>
1 parent 97ffc3b commit 8586515

File tree

1 file changed

+20
-4
lines changed

1 file changed

+20
-4
lines changed

tools/src/main/java/org/apache/kafka/tools/automq/perf/StatsCollector.java

Lines changed: 20 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -61,13 +61,13 @@ public class StatsCollector {
6161
" | CPU {}% | Mem {} MiB heap / {} MiB direct" +
6262
" | Prod rate {} msg/s / {} MiB/s | Prod err {} err/s" +
6363
" | Cons rate {} msg/s / {} MiB/s | Backlog: {} K msg" +
64-
" | Prod Latency (ms) avg: {} - 50%: {} - 99%: {} - 99.9%: {} - Max: {}" +
65-
" | E2E Latency (ms) avg: {} - 50%: {} - 99%: {} - 99.9%: {} - Max: {}";
64+
" | Prod Latency (ms) avg: {} - min: {} - 50%: {} - 99%: {} - 99.9%: {} - max: {}" +
65+
" | E2E Latency (ms) avg: {} - min: {} - 50%: {} - 99%: {} - 99.9%: {} - max: {}";
6666
private static final String SUMMARY_LOG_FORMAT = "Summary" +
6767
" | Prod rate {} msg/s / {} MiB/s | Prod total {} M msg / {} GiB / {} K err" +
6868
" | Cons rate {} msg/s / {} MiB/s | Cons total {} M msg / {} GiB" +
69-
" | Prod Latency (ms) avg: {} - 50%: {} - 75%: {} - 90%: {} - 95%: {} - 99%: {} - 99.9%: {} - 99.99%: {} - Max: {}" +
70-
" | E2E Latency (ms) avg: {} - 50%: {} - 75%: {} - 90%: {} - 95%: {} - 99%: {} - 99.9%: {} - 99.99%: {} - Max: {}";
69+
" | Prod Latency (ms) avg: {} - min: {} - 50%: {} - 75%: {} - 90%: {} - 95%: {} - 99%: {} - 99.9%: {} - 99.99%: {} - max: {}" +
70+
" | E2E Latency (ms) avg: {} - min: {} - 50%: {} - 75%: {} - 90%: {} - 95%: {} - 99%: {} - 99.9%: {} - 99.99%: {} - max: {}";
7171

7272
private static final Logger LOGGER = LoggerFactory.getLogger(StatsCollector.class);
7373

@@ -159,6 +159,7 @@ public static class Result {
159159
public final List<Double> consumeThroughputBps = new ArrayList<>();
160160
public final List<Long> backlog = new ArrayList<>();
161161
public final List<Double> produceLatencyMeanMicros = new ArrayList<>();
162+
public final List<Double> produceLatencyMinMicros = new ArrayList<>();
162163
public final List<Double> produceLatency50thMicros = new ArrayList<>();
163164
public final List<Double> produceLatency75thMicros = new ArrayList<>();
164165
public final List<Double> produceLatency90thMicros = new ArrayList<>();
@@ -169,6 +170,7 @@ public static class Result {
169170
public final List<Double> produceLatencyMaxMicros = new ArrayList<>();
170171
public Map<Double, Long> produceLatencyQuantilesMicros;
171172
public final List<Double> endToEndLatencyMeanMicros = new ArrayList<>();
173+
public final List<Double> endToEndLatencyMinMicros = new ArrayList<>();
172174
public final List<Double> endToEndLatency50thMicros = new ArrayList<>();
173175
public final List<Double> endToEndLatency75thMicros = new ArrayList<>();
174176
public final List<Double> endToEndLatency90thMicros = new ArrayList<>();
@@ -193,6 +195,7 @@ private void update(PeriodResult periodResult, double elapsedTotal) {
193195
this.consumeThroughputBps.add(periodResult.consumeThroughputBps);
194196
this.backlog.add(periodResult.backlog);
195197
this.produceLatencyMeanMicros.add(periodResult.produceLatencyMeanMicros);
198+
this.produceLatencyMinMicros.add(periodResult.produceLatencyMinMicros);
196199
this.produceLatency50thMicros.add(periodResult.produceLatency50thMicros);
197200
this.produceLatency75thMicros.add(periodResult.produceLatency75thMicros);
198201
this.produceLatency90thMicros.add(periodResult.produceLatency90thMicros);
@@ -202,6 +205,7 @@ private void update(PeriodResult periodResult, double elapsedTotal) {
202205
this.produceLatency9999thMicros.add(periodResult.produceLatency9999thMicros);
203206
this.produceLatencyMaxMicros.add(periodResult.produceLatencyMaxMicros);
204207
this.endToEndLatencyMeanMicros.add(periodResult.endToEndLatencyMeanMicros);
208+
this.endToEndLatencyMinMicros.add(periodResult.endToEndLatencyMinMicros);
205209
this.endToEndLatency50thMicros.add(periodResult.endToEndLatency50thMicros);
206210
this.endToEndLatency75thMicros.add(periodResult.endToEndLatency75thMicros);
207211
this.endToEndLatency90thMicros.add(periodResult.endToEndLatency90thMicros);
@@ -256,6 +260,7 @@ private static class PeriodResult {
256260
private final double consumeThroughputBps;
257261
private final long backlog;
258262
private final double produceLatencyMeanMicros;
263+
private final double produceLatencyMinMicros;
259264
private final double produceLatency50thMicros;
260265
private final double produceLatency75thMicros;
261266
private final double produceLatency90thMicros;
@@ -265,6 +270,7 @@ private static class PeriodResult {
265270
private final double produceLatency9999thMicros;
266271
private final double produceLatencyMaxMicros;
267272
private final double endToEndLatencyMeanMicros;
273+
private final double endToEndLatencyMinMicros;
268274
private final double endToEndLatency50thMicros;
269275
private final double endToEndLatency75thMicros;
270276
private final double endToEndLatency90thMicros;
@@ -285,6 +291,7 @@ private PeriodResult(CpuMonitor cpu, PeriodStats stats, double elapsed, int read
285291
this.consumeThroughputBps = stats.bytesReceived / elapsed;
286292
this.backlog = Math.max(0, readWriteRatio * stats.totalMessagesSent - stats.totalMessagesReceived);
287293
this.produceLatencyMeanMicros = stats.sendLatencyMicros.getMean();
294+
this.produceLatencyMinMicros = stats.sendLatencyMicros.getMinValue();
288295
this.produceLatency50thMicros = stats.sendLatencyMicros.getValueAtPercentile(50);
289296
this.produceLatency75thMicros = stats.sendLatencyMicros.getValueAtPercentile(75);
290297
this.produceLatency90thMicros = stats.sendLatencyMicros.getValueAtPercentile(90);
@@ -294,6 +301,7 @@ private PeriodResult(CpuMonitor cpu, PeriodStats stats, double elapsed, int read
294301
this.produceLatency9999thMicros = stats.sendLatencyMicros.getValueAtPercentile(99.99);
295302
this.produceLatencyMaxMicros = stats.sendLatencyMicros.getMaxValue();
296303
this.endToEndLatencyMeanMicros = stats.endToEndLatencyMicros.getMean();
304+
this.endToEndLatencyMinMicros = stats.endToEndLatencyMicros.getMinValue();
297305
this.endToEndLatency50thMicros = stats.endToEndLatencyMicros.getValueAtPercentile(50);
298306
this.endToEndLatency75thMicros = stats.endToEndLatencyMicros.getValueAtPercentile(75);
299307
this.endToEndLatency90thMicros = stats.endToEndLatencyMicros.getValueAtPercentile(90);
@@ -317,11 +325,13 @@ private void logIt(double elapsedTotal) {
317325
THROUGHPUT_FORMAT.format(consumeThroughputBps / BYTES_PER_MB),
318326
COUNT_FORMAT.format(backlog / 1_000.0),
319327
LATENCY_FORMAT.format(produceLatencyMeanMicros / MICROS_PER_MILLI),
328+
LATENCY_FORMAT.format(produceLatencyMinMicros / MICROS_PER_MILLI),
320329
LATENCY_FORMAT.format(produceLatency50thMicros / MICROS_PER_MILLI),
321330
LATENCY_FORMAT.format(produceLatency99thMicros / MICROS_PER_MILLI),
322331
LATENCY_FORMAT.format(produceLatency999thMicros / MICROS_PER_MILLI),
323332
LATENCY_FORMAT.format(produceLatencyMaxMicros / MICROS_PER_MILLI),
324333
LATENCY_FORMAT.format(endToEndLatencyMeanMicros / MICROS_PER_MILLI),
334+
LATENCY_FORMAT.format(endToEndLatencyMinMicros / MICROS_PER_MILLI),
325335
LATENCY_FORMAT.format(endToEndLatency50thMicros / MICROS_PER_MILLI),
326336
LATENCY_FORMAT.format(endToEndLatency99thMicros / MICROS_PER_MILLI),
327337
LATENCY_FORMAT.format(endToEndLatency999thMicros / MICROS_PER_MILLI),
@@ -341,6 +351,7 @@ private static class CumulativeResult {
341351
private final double consumeCountTotal;
342352
private final double consumeSizeTotalBytes;
343353
private final double produceLatencyMeanTotalMicros;
354+
private final double produceLatencyMinTotalMicros;
344355
private final double produceLatency50thTotalMicros;
345356
private final double produceLatency75thTotalMicros;
346357
private final double produceLatency90thTotalMicros;
@@ -351,6 +362,7 @@ private static class CumulativeResult {
351362
private final double produceLatencyMaxTotalMicros;
352363
public final Map<Double, Long> produceLatencyQuantilesMicros = new TreeMap<>();
353364
private final double endToEndLatencyMeanTotalMicros;
365+
private final double endToEndLatencyMinTotalMicros;
354366
private final double endToEndLatency50thTotalMicros;
355367
private final double endToEndLatency75thTotalMicros;
356368
private final double endToEndLatency90thTotalMicros;
@@ -372,6 +384,7 @@ private CumulativeResult(CumulativeStats stats, double elapsedTotal) {
372384
consumeCountTotal = stats.totalMessagesReceived;
373385
consumeSizeTotalBytes = stats.totalBytesReceived;
374386
produceLatencyMeanTotalMicros = stats.totalSendLatencyMicros.getMean();
387+
produceLatencyMinTotalMicros = stats.totalSendLatencyMicros.getMinValue();
375388
produceLatency50thTotalMicros = stats.totalSendLatencyMicros.getValueAtPercentile(50);
376389
produceLatency75thTotalMicros = stats.totalSendLatencyMicros.getValueAtPercentile(75);
377390
produceLatency90thTotalMicros = stats.totalSendLatencyMicros.getValueAtPercentile(90);
@@ -384,6 +397,7 @@ private CumulativeResult(CumulativeStats stats, double elapsedTotal) {
384397
value -> produceLatencyQuantilesMicros.put(value.getPercentile(), value.getValueIteratedTo())
385398
);
386399
endToEndLatencyMeanTotalMicros = stats.totalEndToEndLatencyMicros.getMean();
400+
endToEndLatencyMinTotalMicros = stats.totalEndToEndLatencyMicros.getMinValue();
387401
endToEndLatency50thTotalMicros = stats.totalEndToEndLatencyMicros.getValueAtPercentile(50);
388402
endToEndLatency75thTotalMicros = stats.totalEndToEndLatencyMicros.getValueAtPercentile(75);
389403
endToEndLatency90thTotalMicros = stats.totalEndToEndLatencyMicros.getValueAtPercentile(90);
@@ -409,6 +423,7 @@ private void logIt() {
409423
COUNT_FORMAT.format(consumeCountTotal / 1_000_000.0),
410424
COUNT_FORMAT.format(consumeSizeTotalBytes / BYTES_PER_GB),
411425
LATENCY_FORMAT.format(produceLatencyMeanTotalMicros / MICROS_PER_MILLI),
426+
LATENCY_FORMAT.format(produceLatencyMinTotalMicros / MICROS_PER_MILLI),
412427
LATENCY_FORMAT.format(produceLatency50thTotalMicros / MICROS_PER_MILLI),
413428
LATENCY_FORMAT.format(produceLatency75thTotalMicros / MICROS_PER_MILLI),
414429
LATENCY_FORMAT.format(produceLatency90thTotalMicros / MICROS_PER_MILLI),
@@ -418,6 +433,7 @@ private void logIt() {
418433
LATENCY_FORMAT.format(produceLatency9999thTotalMicros / MICROS_PER_MILLI),
419434
LATENCY_FORMAT.format(produceLatencyMaxTotalMicros / MICROS_PER_MILLI),
420435
LATENCY_FORMAT.format(endToEndLatencyMeanTotalMicros / MICROS_PER_MILLI),
436+
LATENCY_FORMAT.format(endToEndLatencyMinTotalMicros / MICROS_PER_MILLI),
421437
LATENCY_FORMAT.format(endToEndLatency50thTotalMicros / MICROS_PER_MILLI),
422438
LATENCY_FORMAT.format(endToEndLatency75thTotalMicros / MICROS_PER_MILLI),
423439
LATENCY_FORMAT.format(endToEndLatency90thTotalMicros / MICROS_PER_MILLI),

0 commit comments

Comments
 (0)