- Notifications
You must be signed in to change notification settings - Fork0
Highly configurable, easy to use stopwatch allowing measurement of accumulated run-time, with support for numerous statistics.
License
ethlo/chronograph
Folders and files
| Name | Name | Last commit message | Last commit date | |
|---|---|---|---|---|
Repository files navigation
Easy to use Java stopwatch allowing measurement of elapsed time.
- New in 4.0: Hierarchical task tracking - Start several nested tasks.
- The same task can be timed multiple times for aggregated/cumulative data.
- Supports numerous metrics:
- average
- median
- min/max
- standard deviation
- percentiles
- percentage
- count
- total time
- Human-readable durations
- Well documented
- Highly tweaked code for minimal overhead.
- Dynamic ASCII/Unicode table support for detailed result output on the console or in logs with support for colored output (ANSI console)
- Easy to fetch the underlying data for when you need your own output format, like JSON
- Configurable sample interval for very short running tasks
- No dependencies
finalChronographc =Chronograph.create();c.time("Request", () ->{for (inti =0;i <13;i++) {c.time("Fetch", () ->busy(12)); }// Overheadbusy(300);c.time("De-serialize", () -> {// Overheadbusy(14);c.time("JSON de-serialize", () ->busy(44)); });});
Sample output in tables:
Or in JSON format if you need it for later analysis:
{"tasks" : [ {"name" :"Request","subtasks" : [ {"name" :"Fetch","total_time" :"0.15757311","subtasks_time" :"0","self_time" :"0.15757311","invocation_count" :13,"statistics" : {"average" :"0.012121008","median" :"0.012110195","min" :"0.01208667","max" :"0.012215087","standard_deviation" :"0.000038184","percentiles" : {"75.0" :"0.012130908","90.0" :"0.012183143","95.0" :"0.012215087","99.0" :"0.012215087","99.9" :"0.012215087" } } }, {"name" :"De-serialize","subtasks" : [ {"name" :"JSON de-serialize","total_time" :"0.044214251","subtasks_time" :"0","self_time" :"0.044214251","invocation_count" :1 }, {"name" :"<overhead>","total_time" :"0.015809396","subtasks_time" :"0","self_time" :"0.015809396","invocation_count" :1 } ],"total_time" :"0.060023647","subtasks_time" :"0.060023647","self_time" :"0","invocation_count" :1 }, {"name" :"<overhead>","total_time" :"0.301883674","subtasks_time" :"0","self_time" :"0.301883674","invocation_count" :1 } ],"total_time" :"0.519480431","subtasks_time" :"0.519480431","self_time" :"0","invocation_count" :1 }, {"name" :"Response","subtasks" : [ {"name" :"Logging","total_time" :"0.011222603","subtasks_time" :"0","self_time" :"0.011222603","invocation_count" :1 }, {"name" :"Serialize","subtasks" : [ {"name" :"JSON serialize","total_time" :"0.027233243","subtasks_time" :"0","self_time" :"0.027233243","invocation_count" :1 }, {"name" :"<overhead>","total_time" :"0.014704076","subtasks_time" :"0","self_time" :"0.014704076","invocation_count" :1 } ],"total_time" :"0.041937319","subtasks_time" :"0.041937319","self_time" :"0","invocation_count" :1 } ],"total_time" :"0.053987607","subtasks_time" :"0.053159922","self_time" :"0.000827685","invocation_count" :1 } ]}<dependency> <groupId>com.ethlo.time</groupId> <artifactId>chronograph</artifactId> <version>4.0.0</version></dependency>
finalChronographchronograph =Chronograph.create();chronograph.start("my-task");// perform a taskchronograph.stop();System.out.printn(chronograph.prettyPrint());
finalList<Long>myList = ...;finalChronographchronograph =Chronograph.create();chronograph.time("List sort", () ->linkedList.sort(Comparator.naturalOrder()));System.out.println(chronograph);
Empty columns will be dropped automatically. Included columns can be configured.
Begin from scratch:
finalOutputConfigoutputConfig =newOutputConfig() .median(true) .standardDeviation(true);
Begin from DEFAULT configuration:
finalOutputConfigoutputConfig =Chronograph.configure(OutputConfig.DEFAULT .percentiles(75,90,99,99.9,99.99));
// Then use it like thisSystem.out.println(newTableOutputFormatter(outputConfig,TableTheme.RED_HERRING).format(chronograph.getData()));
If you run very quick tasks (typically less than milliseconds) in a loop, it may be beneficial to not capture every iteration, but instead sample some of them. This can be achieved by
finalChronographchronograph =Chronograph .create(CaptureConfig .minInterval(Duration.ofNanos(10_000)));// 10 microseconds
You can choose to output the results using different styles and colors. Below are a few examples.
finalTableThememyTheme =TableTheme.builder() .stringColor(AnsiColor.BLUE) .numericColor(AnsiColor.GREEN) .horizontalSeparator(" ") .verticalSpacerColor(AnsiColor.GRAY) .horizontalSpacerColor(AnsiColor.GRAY) .build();
This project is utilizingSystem.nanoTime() which has some inherent issues with very quick task times. It does have a nanosecond resolution, but not a nanosecond precision. These are still usually orders of magnitude away from what you are trying to measure, so it is not a problem. If you are micro-benchmarking, consider using a framework likeJMH.
If you would like to know more:
- https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/System.html#nanoTime()
- https://shipilev.net/blog/2014/nanotrusting-nanotime/#_timers
The Chronograph is NOT thread safe.
About
Highly configurable, easy to use stopwatch allowing measurement of accumulated run-time, with support for numerous statistics.