patterntesting.runtime.log.PerfLogger Maven / Gradle / Ivy
Go to download
Show more of this group Show more artifacts with this name
Show all versions of patterntesting-rt Show documentation
Show all versions of patterntesting-rt Show documentation
PatternTesting Runtime (patterntesting-rt) is the runtime component for
the PatternTesting framework. It provides the annotations and base classes
for the PatternTesting testing framework (e.g. patterntesting-check,
patterntesting-concurrent or patterntesting-exception) but can be also
used standalone for classpath monitoring or profiling.
It uses AOP and AspectJ to perform this feat.
/*
* $Id: PerfLogger.java,v 1.7 2014/04/19 19:14:29 oboehm Exp $
*
* Copyright (c) 2014 by Oliver Boehm
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express orimplied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
* (c)reated 17.03.2014 by oliver ([email protected])
*/
package patterntesting.runtime.log;
import org.slf4j.*;
import patterntesting.runtime.monitor.ProfileMonitor;
import patterntesting.runtime.util.Converter;
/**
* This class is a kind of performance logger to be able to log the execution
* times of methods or code segments which may need a little bit longer. It can
* be used as a replacement of a normal logger.
*
* We use a {@link LogWatch} to measure the times between a
* {@link #start(String, Object...)} and {@link #end(String, Object...)} call.
* We store this {@link LogWatch} as {@link ThreadLocal} because loggers are
* normally used as static variables. So we can be sure that each thread has
* its own {@link LogWatch}.
*
*
* @author oliver
* @since 1.4.1 (17.03.2014)
* @version $Revision: 1.7 $
*/
public final class PerfLogger {
private final Logger logger;
/** The local stopwatch. */
private final ThreadLocal timer = new ThreadLocal() {
@Override
protected LogWatch initialValue() {
LogWatch watch = new LogWatch();
return watch;
}
};
/**
* Instantiates a new perf logger.
*/
public PerfLogger() {
this(PerfLogger.class);
}
/**
* Instantiates a new perf logger.
*
* @param clazz the clazz
*/
public PerfLogger(final Class clazz) {
this(LoggerFactory.getLogger(clazz));
}
/**
* Instantiates a new perf logger.
*
* @param logger the logger
*/
public PerfLogger(final Logger logger) {
this.logger = logger;
}
/**
* Start the log for the given message. The default level for the logged
* message is "INFO".
*
* @param format the format
* @param args the args
*/
public void start(final String format, final Object... args) {
this.start(SimpleLog.LOG_LEVEL_INFO, format, args);
}
/**
* Start the log for the given message. For the valid log levels see
*
* @param level the level
* @param format the format
* @param args the args
* {@link SimpleLog}.
* @see SimpleLog
*/
public void start(final int level, final String format, final Object... args) {
this.log(level, format, args);
timer.get().start();
}
/**
* End the log with the given message. The output will contain the measure
* time from the last {@link #start(String, Object...)} log. So be sure to
* call one of the start methods before.
*
* The default level for the logged message is "INFO".
*
*
* @param format the format
* @param args the args
*/
public void end(final String format, final Object... args) {
this.end(SimpleLog.LOG_LEVEL_INFO, format, args);
}
/**
* End the log with the given message. The output will contain the measure
* time from the last {@link #start(String, Object...)} log. So be sure to
* call one of the start methods before.
*
* It is recommended to use the same as in
*
* @param level the level
* @param format the format
* @param args the args
* {@link #start(int, String, Object...)}. If the reported times is greater
* than 1 minute the log level will be increased at least to "INFO".
*
*/
public void end(int level, final String format, final Object... args) {
LogWatch watch = timer.get();
watch.stop();
long millis = watch.getElapsedTime();
if ((millis > 60000L) && (level < SimpleLog.LOG_LEVEL_INFO)) {
this.logger.trace("Log level will be increased from {} to 'INFO'", level);
level = SimpleLog.LOG_LEVEL_INFO;
}
this.log(level, format + " finished after " + watch + ".", args);
}
/**
* Log.
*
* @param level the level
* @param format the format
* @param args the args
*/
public void log(final int level, final String format, final Object... args) {
switch (level) {
case SimpleLog.LOG_LEVEL_TRACE:
this.logger.trace(format, args);
break;
case SimpleLog.LOG_LEVEL_DEBUG:
this.logger.debug(format, args);
break;
case SimpleLog.LOG_LEVEL_INFO:
this.logger.info(format, args);
break;
case SimpleLog.LOG_LEVEL_WARN:
this.logger.warn(format, args);
break;
case SimpleLog.LOG_LEVEL_ERROR:
case SimpleLog.LOG_LEVEL_FATAL:
this.logger.trace(format, args);
break;
default:
this.logger.info("Level " + level + ": " + format, args);
break;
}
}
/**
* Error.
*
* @param format the format
* @param args the args
*/
public void error(final String format, final Object... args) {
logger.error(format, args);
}
/**
* Warn.
*
* @param format the format
* @param args the args
*/
public void warn(final String format, final Object... args) {
logger.warn(format, args);
}
/**
* Info.
*
* @param format the format
* @param args the args
*/
public void info(final String format, final Object... args) {
logger.info(format, args);
}
/**
* Debug.
*
* @param format the format
* @param args the args
*/
public void debug(final String format, final Object... args) {
logger.debug(format, args);
}
/**
* Stops the given 'mon' and logs the given command with the needed time if
* debug is enabled.
*
* @param mon the mon
* @param command the command
*/
public void stop(final ProfileMonitor mon, final String command) {
stop(mon, command, Void.TYPE);
}
/**
* Stops the given 'mon' and logs the given command with the needed time if
* debug is enabled.
*
* @param mon the mon
* @param command the command
* @param returnValue the return value
*/
public void stop(final ProfileMonitor mon, final String command, final Object returnValue) {
mon.stop();
if (logger.isDebugEnabled()) {
logger.debug("\"{}\" returned with {} after {}.", command,
Converter.toShortString(returnValue), mon.getLastTime());
}
}
/**
* Trace.
*
* @param format the format
* @param args the args
*/
public void trace(final String format, final Object... args) {
logger.trace(format, args);
}
/**
* Checks if is debug enabled.
*
* @return true, if is debug enabled
*/
public boolean isDebugEnabled() {
return logger.isDebugEnabled();
}
}