-
Notifications
You must be signed in to change notification settings - Fork 96
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
Makes TimedPhase auto-closeable. (#143)
* Makes TimedPhase auto-closeable. --This would allow us to wrap timed phases in a try-with-resources block: ```java try(TimedPhase phase = RequestLog.startTiming("timerAllTheThings") { doAllTheThings(); } ``` --This has several advantages over the current approach: 1. We always want to wrap the code that stops a timer in a finally block. Otherwise, the timer won't be stopped if we have an exception. try-with-resources makes that clean. 2. It reduces the chances of typos when starting and stopping timers. It also reduces the chances of people staring a timer and then forgetting to stop it. 3. It is more concise. --This has several limitations: 1. The minimum effort code to implement it is awkward. We'll need to do a much more significant (and not yet clear) refactor of RequestLog to handle this cleanly. 2. Timers that cross threads can't be handled this way. Those still need to be stopped and started manually. --Consequences that are more mixed: 1. It exposes a lot more of the inner workings of RequestLog. This could make it easier to customers to perform their own custom timings, but it also exposes code that is very easy to use incorrectly if you don't have a strong understanding of it. * Deprecates `RequestLog::stopMostRecentTimer`. * Timings now use the try-with-resources blocks. --Those timers that are started and stopped in the same context now use try-with-resources blocks that start the timer. * Updates CHANGELOG.
- Loading branch information
Showing
11 changed files
with
192 additions
and
152 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
119 changes: 119 additions & 0 deletions
119
fili-core/src/main/java/com/yahoo/bard/webservice/logging/TimedPhase.java
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,119 @@ | ||
// Copyright 2017 Yahoo Inc. | ||
// Licensed under the terms of the Apache license. Please see LICENSE.md file distributed with this work for terms. | ||
package com.yahoo.bard.webservice.logging; | ||
|
||
import org.slf4j.Logger; | ||
import org.slf4j.LoggerFactory; | ||
|
||
import java.util.concurrent.TimeUnit; | ||
|
||
/** | ||
* Represents a phase that is timed. | ||
* TimedPhase is used to associate a Timer located in the registry with the exact duration of such a phase for a | ||
* specific request. Times are in nanoseconds. | ||
* <p> | ||
* Note: This class is NOT thread-safe. Timers are intended to be started once by one thread, and stopped once by | ||
* one thread (though those threads are not necessarily the same). | ||
*/ | ||
public class TimedPhase implements AutoCloseable { | ||
private static final Logger LOG = LoggerFactory.getLogger(TimedPhase.class); | ||
|
||
private final String name; | ||
private long start; | ||
private long duration; | ||
|
||
/** | ||
* Constructor. | ||
* | ||
* @param name Name of the phase | ||
*/ | ||
public TimedPhase(String name) { | ||
this.name = name; | ||
} | ||
|
||
/** | ||
* Start the phase. | ||
* | ||
* @return This phase after being started | ||
*/ | ||
public TimedPhase start() { | ||
if (isRunning()) { | ||
LOG.warn("Tried to start timer that is already running: {}", name); | ||
} else { | ||
start = System.nanoTime(); | ||
} | ||
return this; | ||
} | ||
|
||
/** | ||
* Stop the phase. | ||
* <p> | ||
* This method just stops the timer. It does not register the time with the {@link RequestLog}. To register | ||
* the timer, invoke {@link TimedPhase#registerTime()}. To do both with a single method call, see | ||
* {@link TimedPhase#close()} | ||
* | ||
* @see TimedPhase#registerTime() | ||
* @see TimedPhase#close() | ||
*/ | ||
public void stop() { | ||
if (!isRunning()) { | ||
LOG.warn("Tried to stop timer that has not been started: {}", name); | ||
return; | ||
} | ||
duration += System.nanoTime() - start; | ||
start = 0; | ||
} | ||
|
||
/** | ||
* Registers the duration of this timer with the RequestLog. | ||
* <p> | ||
* It is highly recommended that you {@link TimedPhase#stop()}} the timer first. Otherwise, the timings may | ||
* be inaccurate. To both stop and register the timer at once see {@link TimedPhase#close}. | ||
* | ||
* @see TimedPhase#stop() | ||
* @see TimedPhase#close() | ||
*/ | ||
public void registerTime() { | ||
RequestLog.registerTime(this); | ||
} | ||
|
||
/** | ||
* Return the duration of the timer in nanoseconds. | ||
* | ||
* @return The duration of the timer in nanoseconds | ||
*/ | ||
public long getDuration() { | ||
if (isRunning()) { | ||
LOG.warn("Timer '{}' is still running. Timings may be incorrect.", getName()); | ||
} | ||
return duration; | ||
} | ||
|
||
public String getName() { | ||
return name; | ||
} | ||
|
||
public TimeUnit getUnit() { | ||
return TimeUnit.NANOSECONDS; | ||
} | ||
|
||
public boolean isRunning() { | ||
return start != 0; | ||
} | ||
|
||
/** | ||
* Stops the timer, and registers the timer with the RequestLog. | ||
* <p> | ||
* This is primarily meant to be used by the try-with-resources block, which both stops the timer and registers it | ||
* with the RequestLog, though it can of course be called manually as well. If you want to stop the timer, but | ||
* don't want to register the timer just yet, then see {@link TimedPhase#stop}. | ||
* | ||
* @see TimedPhase#stop() | ||
* @see TimedPhase#registerTime() | ||
*/ | ||
@Override | ||
public void close() { | ||
stop(); | ||
registerTime(); | ||
} | ||
} |
Oops, something went wrong.