Skip to content

Commit 98c35b1

Browse files
ggivoggivo
committed
export "Final test results" per latest spec
1 parent 9badb76 commit 98c35b1

File tree

3 files changed

+192
-14
lines changed

3 files changed

+192
-14
lines changed

‎src/main/java/io/lettuce/test/WorkloadRunnerBase.java‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,7 @@
3838
import java.lang.reflect.InvocationTargetException;
3939
import java.lang.reflect.Method;
4040
import java.time.Duration;
41+
import java.time.Instant;
4142
import java.util.ArrayList;
4243
import java.util.List;
4344
import java.util.concurrent.CompletableFuture;
@@ -87,12 +88,15 @@ public final void run() {
8788
}
8889
}
8990

91+
Instant start = Instant.now();
9092
try {
9193
CompletableFuture<Void> workloadsFuture = executeWorkloads(clients, connections);
9294
workloadsFuture.thenRun(() -> log.info("All tasks completed. Exiting..."));
9395
} catch (Exception e) {
9496
throw new RuntimeException(e);
9597
} finally {
98+
Instant end = Instant.now();
99+
metricsReporter.recordTestDuration(start, end);
96100
executor.shutdown();
97101
}
98102
}

‎src/main/java/io/lettuce/test/metrics/MeterRegistryConfiguration.java‎

Lines changed: 8 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,11 @@
11
package io.lettuce.test.metrics;
22

33
import io.lettuce.core.LettuceVersion;
4+
import io.lettuce.test.config.TestRunProperties;
45
import io.micrometer.core.instrument.MeterRegistry;
56
import io.micrometer.core.instrument.config.MeterFilter;
67
import io.micrometer.core.instrument.logging.LoggingRegistryConfig;
78
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
8-
import org.springframework.beans.factory.annotation.Value;
99
import org.springframework.boot.actuate.autoconfigure.metrics.MeterRegistryCustomizer;
1010
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
1111
import org.springframework.context.annotation.Bean;
@@ -15,19 +15,18 @@
1515
@Configuration(proxyBeanMethods = false)
1616
public class MeterRegistryConfiguration {
1717

18-
@Value("${runId:${runner.test.workload.type}-#{T(org.apache.commons.lang3.RandomStringUtils).randomAlphanumeric(8)}}")
19-
private String runId;
18+
private final TestRunProperties testRunProperties;
2019

21-
@Value("${instanceId:${spring.application.name}-#{T(org.apache.commons.lang3.RandomStringUtils).randomAlphanumeric(8)}}")
22-
private String instanceId;
23-
24-
@Value("${appName:lettuce-test-app}")
25-
private String appName;
20+
public MeterRegistryConfiguration(TestRunProperties testRunProperties) {
21+
this.testRunProperties = testRunProperties;
22+
}
2623

2724
@Bean
2825
public MeterRegistryCustomizer<MeterRegistry> metricsCommonTags() {
2926
return (registry) -> {
30-
registry.config().commonTags("app_name", appName).commonTags("run_id", runId).commonTags("instance_id", instanceId)
27+
registry.config().commonTags("app_name", testRunProperties.getAppName())
28+
.commonTags("run_id", testRunProperties.getRunId())
29+
.commonTags("instance_id", testRunProperties.getInstanceId())
3130
.commonTags("version", LettuceVersion.getVersion());
3231

3332
// Ensure OTLP registry accepts all redis metrics

‎src/main/java/io/lettuce/test/metrics/MetricsReporter.java‎

Lines changed: 180 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,7 @@
11
package io.lettuce.test.metrics;
22

3+
import io.lettuce.core.LettuceVersion;
4+
import io.lettuce.test.config.TestRunProperties;
35
import io.lettuce.test.workloads.BaseWorkload;
46
import io.micrometer.core.instrument.Counter;
57
import io.micrometer.core.instrument.Gauge;
@@ -14,11 +16,19 @@
1416
import org.springframework.beans.factory.annotation.Value;
1517
import org.springframework.scheduling.TaskScheduler;
1618
import org.springframework.stereotype.Component;
19+
import com.fasterxml.jackson.databind.ObjectMapper;
20+
import com.fasterxml.jackson.databind.node.ObjectNode;
1721

22+
import java.io.IOException;
1823
import java.lang.reflect.Proxy;
24+
import java.nio.file.Files;
25+
import java.nio.file.Path;
26+
import java.nio.file.Paths;
1927
import java.time.Duration;
28+
import java.time.Instant;
2029
import java.util.Comparator;
2130
import java.util.Map;
31+
import java.util.OptionalDouble;
2232
import java.util.concurrent.ConcurrentHashMap;
2333
import java.util.concurrent.ScheduledFuture;
2434
import java.util.concurrent.TimeUnit;
@@ -28,15 +38,31 @@ public class MetricsReporter {
2838

2939
private static final Logger log = LoggerFactory.getLogger("simple-metrics-reporter");
3040

41+
public static final String REDIS_OPERATION_DURATION_TOTAL = "redis.operation.duration.total";
42+
43+
public static final String REDIS_OPERATION_DURATION = "redis.operation.duration";
44+
45+
public static final String REDIS_RECONNECTION_DURATION = "redis.reconnection.duration";
46+
47+
public static final String REDIS_TEST_DURATION = "redis.test.duration";
48+
3149
private final MeterRegistry meterRegistry;
3250

3351
private final SimpleMeterRegistry simpleMeterRegistry;
3452

3553
private final TaskScheduler taskScheduler;
3654

55+
private final TestRunProperties testRunProperties;
56+
3757
@Value("${simple.metrics.dumpRate:PT5S}")
3858
private Duration dumpRate;
3959

60+
@Value("${logging.file.path:logs}")
61+
private String logPath;
62+
63+
@Value("${runner.test.workload.type}")
64+
private String workloadType;
65+
4066
private final Map<CommandKey, Timer> commandLatencyTimers = new ConcurrentHashMap<>();
4167

4268
private final Timer commandLatencyTotalTimer;
@@ -67,10 +93,17 @@ public class MetricsReporter {
6793

6894
private ScheduledFuture<?> scheduledFuture;
6995

96+
private final ObjectMapper objectMapper = new ObjectMapper();
97+
98+
private volatile Instant testRunStart;
99+
100+
private volatile Instant testRunEnd;
101+
70102
public MetricsReporter(MeterRegistry meterRegistry, SimpleMeterRegistry simpleMeterRegistry,
71-
@Qualifier("metricReporterScheduler") TaskScheduler taskScheduler) {
103+
@Qualifier("metricReporterScheduler") TaskScheduler taskScheduler, TestRunProperties testRunProperties) {
72104
this.meterRegistry = meterRegistry;
73105
this.simpleMeterRegistry = simpleMeterRegistry;
106+
this.testRunProperties = testRunProperties;
74107
this.connectionSuccessTimer = Timer.builder("lettuce.connect.success")
75108
.description("Measures the duration and count of successful Redis connections").register(meterRegistry);
76109
this.connectionFailureTimer = Timer.builder("lettuce.connect.failure")
@@ -95,6 +128,15 @@ Timer.Sample startCommandTimer() {
95128
return Timer.start(meterRegistry);
96129
}
97130

131+
public void recordTestDuration(Instant start, Instant end) {
132+
this.testRunStart = start;
133+
this.testRunEnd = end;
134+
Timer.builder(REDIS_TEST_DURATION)
135+
.description("Measures the duration of the test run")
136+
.register(meterRegistry)
137+
.record(Duration.between(start, end));
138+
}
139+
98140
public record CommandKey(String commandName, OperationStatus status) {
99141

100142
}
@@ -167,17 +209,19 @@ private Counter createPubSubOperationCounter(PubSubOpKey pubSubOpKey) {
167209
.register(meterRegistry);
168210
}
169211

170-
private Timer createCommandLatencyTimer(CommandKey commandKey) {
171-
return Timer.builder("redis.operation.duration").description(
212+
private Timer createCommandLatencyTimer(CommandKey commandKey) {
213+
return Timer.builder(REDIS_OPERATION_DURATION).description(
172214
"Measures the execution time of Redis commands from API invocation until command completion per command")
173215
.tag("command", commandKey.commandName).tag("status", commandKey.status.name().toLowerCase())
174216
.publishPercentileHistogram(true).publishPercentiles(0.5, 0.95, 0.99).register(meterRegistry);
175217
}
176218

177219
private Timer createCommandLatencyTotalTimer() {
178-
return Timer.builder("redis.operation.total.duration")
220+
return Timer.builder(REDIS_OPERATION_DURATION_TOTAL)
179221
.description("Measures the execution time of Redis commands from API invocation until command completion")
180-
.publishPercentileHistogram(true).publishPercentiles(0.5, 0.95, 0.99).register(meterRegistry);
222+
.publishPercentileHistogram(true)
223+
.publishPercentiles(0.5, 0.95, 0.99)
224+
.register(meterRegistry);
181225
}
182226

183227
private Counter createCommandErrorCounter(String commandName) {
@@ -273,18 +317,149 @@ public void dumpMetrics() {
273317
@PostConstruct
274318
public void startScheduledTask() {
275319
scheduledFuture = taskScheduler.scheduleAtFixedRate(this::dumpMetrics, dumpRate);
320+
taskScheduler.scheduleAtFixedRate(this::dumpFinalResult, dumpRate);
276321
}
277322

278323
@PreDestroy
279324
public void shutdown() {
280325
log.info("MetricsReporter is shutting down.");
326+
dumpFinalResult();
281327
if (scheduledFuture != null) {
282328
scheduledFuture.cancel(true);
283329
dumpMetrics();
284330
log.info("MetricsReporter is stopped.");
285331
}
286332
}
287333

334+
public void dumpFinalResult() {
335+
336+
try {
337+
ObjectNode result = buildFinalResultJson();
338+
String jsonResult = objectMapper.writerWithDefaultPrettyPrinter().writeValueAsString(result);
339+
340+
// Log to console
341+
log.info("=== FINAL TEST RESULTS ===");
342+
log.info(jsonResult);
343+
log.info("=== END FINAL TEST RESULTS ===");
344+
345+
// Write to file
346+
writeResultsToFile(jsonResult);
347+
348+
} catch (Exception e) {
349+
log.error("Error generating final result", e);
350+
}
351+
}
352+
353+
private void writeResultsToFile(String jsonResult) {
354+
try {
355+
// Create logs directory if it doesn't exist
356+
Path logDir = Paths.get(logPath);
357+
if (!Files.exists(logDir)) {
358+
Files.createDirectories(logDir);
359+
log.info("Created log directory: {}", logDir.toAbsolutePath());
360+
}
361+
362+
// Write to test-run-summary.json
363+
Path summaryFile = logDir.resolve("test-run-summary.json");
364+
Files.write(summaryFile, jsonResult.getBytes());
365+
log.info("Final test results written to: {}", summaryFile.toAbsolutePath());
366+
367+
} catch (IOException e) {
368+
log.error("Failed to write final results to file", e);
369+
}
370+
}
371+
372+
public String getFinalResultAsJson() {
373+
try {
374+
ObjectNode result = buildFinalResultJson();
375+
return objectMapper.writerWithDefaultPrettyPrinter().writeValueAsString(result);
376+
} catch (Exception e) {
377+
log.error("Error generating final result JSON", e);
378+
return "{}";
379+
}
380+
}
381+
382+
private ObjectNode buildFinalResultJson() {
383+
ObjectNode result = objectMapper.createObjectNode();
384+
385+
// Basic run information
386+
result.put("app_name", testRunProperties.getAppName());
387+
result.put("instance_id", testRunProperties.getInstanceId());
388+
result.put("run_id", testRunProperties.getRunId());
389+
result.put("version", LettuceVersion.getVersion());
390+
391+
// Test duration
392+
result.put("workload_name", workloadType != null ? workloadType : "unknown");
393+
394+
// Command counts and success rate
395+
long totalCommands = getTotalCmdCount();
396+
long successfulCommands = getSuccessfulCommandCount();
397+
long failedCommands = getFailedCommandCount();
398+
399+
result.put("total_commands_count", totalCommands);
400+
result.put("successful_commands_count", successfulCommands);
401+
result.put("failed_commands_count", failedCommands);
402+
result.put("success_rate",
403+
String.format("%.2f%%", totalCommands > 0 ? (successfulCommands * 100.0 / totalCommands) : 0.0));
404+
405+
// Reconnection metrics
406+
result.put("avg_reconnection_duration_ms", getAverageReconnectionDuration().orElseGet(() -> 0.0));
407+
408+
// Run timestamps (as epoch seconds with decimals)
409+
result.put("run_start", testRunStart.getEpochSecond());
410+
result.put("run_end", testRunEnd.getEpochSecond());
411+
412+
// Latency statistics
413+
result.put("min_latency_ms", 0);
414+
result.put("max_latency_ms", getMaxLatency().orElse(0.0));
415+
result.put("median_latency_ms", getMedianLatency().orElse(0.0));
416+
result.put("p95_latency_ms", getP95Latency().orElse(0.0));
417+
result.put("p99_latency_ms", getP99().orElse(0.0));
418+
419+
return result;
420+
}
421+
422+
private OptionalDouble getMedianLatency() {
423+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION_TOTAL).timers().stream().mapToDouble( m-> m.percentile(0.5, TimeUnit.MILLISECONDS)).average();
424+
}
425+
426+
private OptionalDouble getP95Latency() {
427+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION_TOTAL).timers().stream().mapToDouble( m-> m.percentile(0.95, TimeUnit.MILLISECONDS)).average();
428+
}
429+
430+
private OptionalDouble getP99() {
431+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION_TOTAL).timers().stream().mapToDouble( m-> m.percentile(0.99, TimeUnit.MILLISECONDS)).average();
432+
}
433+
434+
private OptionalDouble getAverageReconnectionDuration() {
435+
return simpleMeterRegistry.find(REDIS_RECONNECTION_DURATION).timers().stream().mapToDouble( m-> m.mean(TimeUnit.MILLISECONDS)).average();
436+
437+
}
438+
439+
private OptionalDouble getMaxLatency() {
440+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION).timers().stream().mapToDouble( m-> m.max(TimeUnit.MILLISECONDS)).max();
441+
}
442+
443+
private long getTotalCmdCount() {
444+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION).timers().stream().mapToLong(Timer::count).sum();
445+
}
446+
447+
private long getSuccessfulCommandCount() {
448+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION)
449+
.tag("status", "success")
450+
.timers()
451+
.stream()
452+
.mapToLong(Timer::count).sum();
453+
}
454+
455+
private long getFailedCommandCount() {
456+
return simpleMeterRegistry.find(REDIS_OPERATION_DURATION)
457+
.tag("status", "error")
458+
.timers()
459+
.stream()
460+
.mapToLong(Timer::count).sum();
461+
}
462+
288463
public static CommandKey cmdKeyOk(String commandName) {
289464
return new CommandKey(commandName, OperationStatus.SUCCESS);
290465
}

0 commit comments

Comments
 (0)