From cd0f4740d42601ea3e19bec160a052021df68e99 Mon Sep 17 00:00:00 2001 From: Morten Date: Mon, 9 Jan 2023 15:16:36 +0100 Subject: [PATCH] Use scheduled sample-rater for better sample precision --- src/main/java/com/ethlo/time/Chronograph.java | 32 +++++++++---------- .../com/ethlo/time/RateLimitedTaskInfo.java | 27 +++++++++------- src/main/java/com/ethlo/time/TaskInfo.java | 6 ++-- .../com/ethlo/util/ListPerformanceTest.java | 20 ++++++------ 4 files changed, 45 insertions(+), 40 deletions(-) diff --git a/src/main/java/com/ethlo/time/Chronograph.java b/src/main/java/com/ethlo/time/Chronograph.java index 4fbf33c..ae2f6e5 100644 --- a/src/main/java/com/ethlo/time/Chronograph.java +++ b/src/main/java/com/ethlo/time/Chronograph.java @@ -21,15 +21,14 @@ */ import java.time.Duration; -import java.util.ArrayList; -import java.util.Collections; import java.util.LinkedHashMap; import java.util.List; import java.util.Map; import java.util.Optional; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.ScheduledThreadPoolExecutor; import java.util.function.Function; import java.util.function.Supplier; -import java.util.stream.Collectors; import com.ethlo.ascii.TableTheme; @@ -38,6 +37,8 @@ public class Chronograph private static TableTheme theme = TableTheme.DEFAULT; private static OutputConfig outputConfig = OutputConfig.DEFAULT; + private final ScheduledExecutorService scheduledExecutorService = new ScheduledThreadPoolExecutor(1); + private final Map taskInfos; private final CaptureConfig captureConfig; private final String name; @@ -103,7 +104,7 @@ public R timedFunction(final String taskName, final Function task, } } - public R timedSupplier(final String taskName, final Supplier task) + public R timedSupplier(final String taskName, final Supplier task) { try { @@ -132,7 +133,13 @@ public void start(String task) throw new IllegalArgumentException("task cannot be null"); } - final TaskInfo taskInfo = taskInfos.computeIfAbsent(task, t -> captureConfig.getMinInterval().equals(Duration.ZERO) ? new TaskInfo(task) : new RateLimitedTaskInfo(task, captureConfig.getMinInterval())); + final TaskInfo taskInfo = taskInfos.computeIfAbsent(task, t -> { + if (captureConfig.getMinInterval().equals(Duration.ZERO)) + { + return new TaskInfo(task); + } + return new RateLimitedTaskInfo(task, captureConfig.getMinInterval(), scheduledExecutorService); + }); taskInfo.start(); } @@ -141,11 +148,7 @@ public void stop() final long ts = System.nanoTime(); for (TaskInfo taskInfo : taskInfos.values()) { - final boolean shouldLog = taskInfo.stopped(ts, true); - if (shouldLog) - { - taskInfo.logTiming(ts); - } + taskInfo.stopped(ts, true); } } @@ -163,10 +166,7 @@ public void stop(String task) throw new IllegalStateException("No started task with name " + task); } - if (taskInfo.stopped(ts, false)) - { - taskInfo.logTiming(ts); - } + taskInfo.stopped(ts, false); } public void resetAll() @@ -181,7 +181,7 @@ public TaskInfo getTasks(final String task) public List getTasks() { - return Collections.unmodifiableList(new ArrayList<>(taskInfos.values())); + return List.copyOf(taskInfos.values()); } public boolean isRunning(String task) @@ -200,7 +200,7 @@ public ChronographData getTaskData() final List stats = getTasks() .stream() .map(task -> new TaskPerformanceStatistics(task.getName(), task.getSampleSize(), task.getDurationStatistics(), task.getThroughputStatistics())) - .collect(Collectors.toList()); + .toList(); return new ChronographData(name, stats, getTotalTime()); } } diff --git a/src/main/java/com/ethlo/time/RateLimitedTaskInfo.java b/src/main/java/com/ethlo/time/RateLimitedTaskInfo.java index baab37c..48efdd5 100644 --- a/src/main/java/com/ethlo/time/RateLimitedTaskInfo.java +++ b/src/main/java/com/ethlo/time/RateLimitedTaskInfo.java @@ -21,38 +21,43 @@ */ import java.time.Duration; +import java.util.concurrent.ScheduledExecutorService; +import com.ethlo.sampler.SampleRater; +import com.ethlo.sampler.ScheduledSampleRater; import com.ethlo.time.statistics.DurationPerformanceStatistics; import com.ethlo.time.statistics.PerformanceStatistics; import com.ethlo.util.IndexedCollectionStatistics; public class RateLimitedTaskInfo extends TaskInfo { - private final long nanosInterval; - private long lastStopped; + private final SampleRater sampleRater; private int totalInvocations; private long totalElapsed; - RateLimitedTaskInfo(final String name, Duration minInterval) + RateLimitedTaskInfo(final String name, Duration minInterval, final ScheduledExecutorService scheduledExecutorService) { super(name); - this.nanosInterval = minInterval.toNanos(); + this.sampleRater = new ScheduledSampleRater<>(scheduledExecutorService, minInterval, prg -> logElapsedDuration(prg.progress())); } @Override boolean stopped(final long ts, final boolean ignoreState) { - super.stopped(ts, ignoreState); - final long elapsed = ts - lastStopped; - if (lastStopped == 0 || elapsed > nanosInterval) + if (!isRunning() && !ignoreState) { - lastStopped = ts; + throw new IllegalStateException("Task " + getName() + " is not started"); + } + + if (isRunning()) + { + final long elapsed = ts - super.getTaskStartTimestamp(); totalInvocations++; - totalElapsed += ts - super.getTaskStartTimestamp(); + totalElapsed += elapsed; + sampleRater.update(elapsed); + running = false; return true; } - totalInvocations++; - totalElapsed += ts - super.getTaskStartTimestamp(); return false; } diff --git a/src/main/java/com/ethlo/time/TaskInfo.java b/src/main/java/com/ethlo/time/TaskInfo.java index 6baf02a..08b2ca9 100644 --- a/src/main/java/com/ethlo/time/TaskInfo.java +++ b/src/main/java/com/ethlo/time/TaskInfo.java @@ -34,7 +34,7 @@ public class TaskInfo private final String name; private final IndexedCollection data; private long taskStartTimestamp; - private boolean running = false; + protected boolean running = false; TaskInfo(final String name) { @@ -84,15 +84,15 @@ boolean stopped(final long ts, boolean ignoreState) if (running) { + logElapsedDuration(ts - getTaskStartTimestamp()); running = false; return true; } return false; } - void logTiming(final long ts) + void logElapsedDuration(final long duration) { - final long duration = ts - taskStartTimestamp; data.add(duration); } diff --git a/src/test/java/com/ethlo/util/ListPerformanceTest.java b/src/test/java/com/ethlo/util/ListPerformanceTest.java index 8c8ba44..6a4a334 100644 --- a/src/test/java/com/ethlo/util/ListPerformanceTest.java +++ b/src/test/java/com/ethlo/util/ListPerformanceTest.java @@ -41,7 +41,7 @@ import com.ethlo.time.PresentationMode; import com.ethlo.time.Report; -public class ListPerformanceTest +class ListPerformanceTest { private static final Logger logger = LoggerFactory.getLogger(ListPerformanceTest.class); @@ -49,7 +49,7 @@ public class ListPerformanceTest private final int count = 4; @Test - public void performanceTestLargeLinkedList() + void performanceTestLargeLinkedList() { final Chronograph c = Chronograph.create(); for (int i = 0; i < count; i++) @@ -63,7 +63,7 @@ public void performanceTestLargeLinkedList() } @Test - public void performanceTestLargeArrayList() + void performanceTestLargeArrayList() { final Chronograph c = Chronograph.create(); for (int i = 0; i < count; i++) @@ -77,7 +77,7 @@ public void performanceTestLargeArrayList() } @Test - public void performanceTestLargeLongList() + void performanceTestLargeLongList() { final Chronograph c = Chronograph.create(); for (int i = 0; i < count; i++) @@ -91,9 +91,9 @@ public void performanceTestLargeLongList() } @Test - public void rateLimitingTest() + void rateLimitingTest() { - final Chronograph c = Chronograph.create(CaptureConfig.minInterval(Duration.ofNanos(1000))); + final Chronograph c = Chronograph.create(CaptureConfig.minInterval(Duration.ofNanos(10_000))); final IndexedCollection list = new LongList(100_000); for (int i = 0; i < 2_000_000; i++) @@ -105,13 +105,13 @@ public void rateLimitingTest() c.timed("Adding", () -> list.add(randomNano())); } - System.out.println(Report.prettyPrint(c.getTaskData(), OutputConfig.DEFAULT.mode(PresentationMode.THROUGHPUT).formatting(false).percentiles(90, 95, 99, 99.9), TableTheme.TSV)); + System.out.println(c.prettyPrint()); assertThat(true).isTrue(); } @Test - public void performanceTestMediumAdd() + void performanceTestMediumAdd() { final Chronograph c = performAddBenchmark(10, 500_000); output(c, TableTheme.RED_HERRING); @@ -132,7 +132,7 @@ private Chronograph performAddBenchmark(final int runs, final int size) } @Test - public void performanceTestMediumSort() + void performanceTestMediumSort() { final Chronograph c = performSortBenchmark(10, 500_000); output(c, TableTheme.RED_HERRING); @@ -162,7 +162,7 @@ private Chronograph performSortBenchmark(final int runs, final int size) } @Test - public void testCombinedPerformanceTable() + void testCombinedPerformanceTable() { final Chronograph a = performAddBenchmark(20, 10_000); final Chronograph b = performSortBenchmark(10, 10_000);