alma.acs.util

Class StopWatch

java.lang.Object

alma.acs.util.StopWatch

Direct Known Subclasses:

Profiler

public class StopWatch
extends java.lang.Object

Class that facilitates elapsed-time runtime profiling. For per-thread time profiling better use an external profiler.

This class requires external synchronization if used from different threads.

About system clock issues and the JVM, see https://blogs.oracle.com/dholmes/entry/inside_the_hotspot_vm_clocks

Over the years also other open source libs have developed similar classes, but as of ACS 12.2 we do not see a need to replace our StopWatch or change its API. See http://docs.guava-libraries.googlecode.com/git/javadoc/com/google/common/base/Stopwatch.html, http://jamonapi.sourceforge.net/, http://commons.apache.org/proper/commons-lang/javadocs/api-release/index.html?org/apache/commons/lang3/time/StopWatch.html

Author:

hsommer May 7, 2003 2:18:39 PM

Constructor Summary

Constructors

Constructor and Description
StopWatch() Ctor without logger provided.
StopWatch(java.util.logging.Logger logger) Constructor that resets the time count.

Method Summary

Modifier and Type	Method and Description
StopWatch	createStopWatchForSubtask(java.lang.String newSubtaskName) Creates a StopWatch for a subtask.
java.lang.String	formattedMillis() Converts getLapTimeNanos() to fractional milliseconds, using the format from millisecFormatter.
long	getLapTimeMillis() Gets the time in milliseconds that has elapsed since this object was created or reset() was called.
long	getLapTimeNanos() Gets the time in nanoseconds that has elapsed since this object was created or reset() was called.
java.util.Date	getStartTime() Returns the time when this StopWatch was created / started.
java.lang.String	getSubtaskDetails() Gets the subtask timing data as a string.
void	logLapTime(java.lang.String taskDesc) Logs a message about the elapsed time for a certain task.
void	logLapTime(java.lang.String taskDesc, java.util.logging.Level logLevel) Variant of logLapTime(String) that allows the user to specify the log level.
void	logLapTimeWithSubtaskDetails(java.lang.String taskDesc, java.util.logging.Level logLevel)
void	reset()
void	setLogger(java.util.logging.Logger logger)
void	stop() Stops the StopWatch.

Methods inherited from class java.lang.Object

clone, equals, finalize, getClass, hashCode, notify, notifyAll, toString, wait, wait, wait

Constructor Detail

StopWatch

public StopWatch()

Ctor without logger provided. Either call setLogger later, or logs will be printed to stdout.

StopWatch

public StopWatch(java.util.logging.Logger logger)

Constructor that resets the time count.

Parameters:

logger - the logger to be used in logLapTime(String). If null, logs will be printed to stdout.

Method Detail

setLogger

public void setLogger(java.util.logging.Logger logger)

reset

public void reset()

createStopWatchForSubtask

public StopWatch createStopWatchForSubtask(java.lang.String newSubtaskName)

Creates a StopWatch for a subtask. The returned StopWatch can be used to profile blocks of code to get a single log in the end that contains details about how the total time was spent. The returned StopWatch can be used to create more sub-StopWatches, which is convenient if you pass it to a called method which itself uses subtask timing.
When a subtask is done, you must call stop() on the subtask's StopWatch.

Do not expect that subtask elapsed times add up exactly to the total elapsed time. The system-dependent timing granularity does not allow this.

getStartTime

public java.util.Date getStartTime()

Returns the time when this StopWatch was created / started. This method can be useful for log output, to later correlate the profiled elapsed time with other occurrences in the system.

stop

public void stop()

Stops the StopWatch. This method must be called for subtask StopWatches (see createStopWatchForSubtask(String)). It is optional in case of top-level StopWatches where it makes little difference whether or not we first stop the watch right before retrieving or logging the lap time.

This method can be called more than once without (side) effects.

getLapTimeMillis

public long getLapTimeMillis()

Gets the time in milliseconds that has elapsed since this object was created or reset() was called.

The implementation relies on System.nanoTime(), so that the granularity of measurements is OS dependent and can be more than one ms. Also, note that the time spent on all threads together is returned, which might be a poor measure for runtime profiling of a particular method.

Returns:

elapsed time in milliseconds

formattedMillis

public java.lang.String formattedMillis()

Converts getLapTimeNanos() to fractional milliseconds, using the format from millisecFormatter.

getLapTimeNanos

public long getLapTimeNanos()

Gets the time in nanoseconds that has elapsed since this object was created or reset() was called.

The implementation simply relies on System.nanoTime(), so that the granularity of measurements is OS dependent. Also, note that the time spent on all threads together is returned, which might be a poor measure for runtime profiling a particular method.

Returns:

elapsed time in nanoseconds

logLapTime

public void logLapTime(java.lang.String taskDesc)

Logs a message about the elapsed time for a certain task. It uses log level Level.FINE and inserts the supplied description: "elapsed time in ms to taskDescription: elapsed-time".

If no logger has been supplied, it will get one using Logger.getLogger(java.lang.String). This ad-hoc logger will likely not work in an ACS environment where log handlers are configured for the needs of containers and remote logging.

todo: provide nicer text mask for message

Parameters:

taskDesc - the message to be include in the standard message which should describe the task for which the lap time is taken.

See Also:

getLapTimeMillis()

logLapTime

public void logLapTime(java.lang.String taskDesc,
                       java.util.logging.Level logLevel)

Variant of logLapTime(String) that allows the user to specify the log level. Generally the FINE (=DEBUG) level is appropriate for performance logs, but in special cases such as unit tests it can be necessary to log at INFO or other levels.

logLapTimeWithSubtaskDetails

public void logLapTimeWithSubtaskDetails(java.lang.String taskDesc,
                                         java.util.logging.Level logLevel)

Since:

ACS 12.3

getSubtaskDetails

public java.lang.String getSubtaskDetails()

Gets the subtask timing data as a string. The returned String has the same format that is also used in logLapTimeWithSubtaskDetails(String, Level).