com.opensymphony.xwork2.interceptor.TimerInterceptor Maven / Gradle / Ivy

Go to download
Show more of this group Show more artifacts with this name
Show all versions of xwork Show documentation
XWork is an command-pattern framework that is used to power WebWork as well as other applications. XWork provides an Inversion of Control container, a powerful expression language, data type conversion, validation, and pluggable configuration.
The newest version!
/*
 * Copyright (c) 2002-2006 by OpenSymphony
 * All rights reserved.
 */
package com.opensymphony.xwork2.interceptor;

import com.opensymphony.xwork2.ActionInvocation;
import com.opensymphony.xwork2.util.logging.Logger;
import com.opensymphony.xwork2.util.logging.LoggerFactory;

/**
 * 
 * This interceptor logs the amount of time in milliseconds. In order for this interceptor to work properly, the
 * logging framework must be set to at least the INFO level.
 * This interceptor relies on the Commons Logging API to
 * report its execution-time value.
 * 
 *
 * 
 *
 * 
 *
 * logLevel (optional) - what log level should we use (trace, debug, info, warn, error, fatal)? - defaut is info
 *
 * logCategory (optional) - If provided we would use this category (eg. com.mycompany.app).
 * Default is to use com.opensymphony.xwork2.interceptor.TimerInterceptor.
 *
 * 
 *
 * The parameters above enables us to log all action execution times in our own logfile.
 *
 * 
 *
 * 
 * This interceptor can be extended to provide custom message format. Users should override the
 * invokeUnderTiming method.
 * 
 *
 *  * 
 * <!-- records only the action's execution time -->
 * <action name="someAction" class="com.examples.SomeAction">
 *     <interceptor-ref name="completeStack"/>
 *     <interceptor-ref name="timer"/>
 *     <result name="success">good_result.ftl</result>
 * </action>
 *
 * <!-- records action's execution time as well as other interceptors-->
 * <action name="someAction" class="com.examples.SomeAction">
 *     <interceptor-ref name="timer"/>
 *     <interceptor-ref name="completeStack"/>
 *     <result name="success">good_result.ftl</result>
 * </action>
 * 
 * 
 *
 * This second example uses our own log category at debug level.
 *
 *  * 
 * <!-- records only the action's execution time -->
 * <action name="someAction" class="com.examples.SomeAction">
 *     <interceptor-ref name="completeStack"/>
 *     <interceptor-ref name="timer">
 *         <param name="logLevel">debug</param>
 *         <param name="logCategory">com.mycompany.myapp.actiontime</param>
 *     <interceptor-ref/>
 *     <result name="success">good_result.ftl</result>
 * </action>
 *
 * <!-- records action's execution time as well as other interceptors-->
 * <action name="someAction" class="com.examples.SomeAction">
 *     <interceptor-ref name="timer"/>
 *     <interceptor-ref name="completeStack"/>
 *     <result name="success">good_result.ftl</result>
 * </action>
 * 
 * 
 *
 * @author Jason Carreira
 * @author Claus Ibsen
 */
public class TimerInterceptor extends AbstractInterceptor {
    protected static final Logger LOG = LoggerFactory.getLogger(TimerInterceptor.class);

    protected Logger categoryLogger;
    protected String logCategory;
    protected String logLevel;

    public String getLogCategory() {
        return logCategory;
    }

    public void setLogCategory(String logCatgory) {
        this.logCategory = logCatgory;
    }

    public String getLogLevel() {
        return logLevel;
    }

    public void setLogLevel(String logLevel) {
        this.logLevel = logLevel;
    }

    @Override
    public String intercept(ActionInvocation invocation) throws Exception {
        if (! shouldLog()) {
            return invocation.invoke();
        } else {
            return invokeUnderTiming(invocation);
        }
    }

    /**
     * Is called to invoke the action invocation and time the execution time.
     *
     * @param invocation  the action invocation.
     * @return the result of the action execution.
     * @throws Exception  can be thrown from the action.
     */
    protected String invokeUnderTiming(ActionInvocation invocation) throws Exception {
        long startTime = System.currentTimeMillis();
        String result = invocation.invoke();
        long executionTime = System.currentTimeMillis() - startTime;

        StringBuilder message = new StringBuilder(100);
        message.append("Executed action [");
        String namespace = invocation.getProxy().getNamespace();
        if ((namespace != null) && (namespace.trim().length() > 0)) {
            message.append(namespace).append("/");
        }
        message.append(invocation.getProxy().getActionName());
        message.append("!");
        message.append(invocation.getProxy().getMethod());
        message.append("] took ").append(executionTime).append(" ms.");

        doLog(getLoggerToUse(), message.toString());

        return result;
    }

    /**
     * Determines if we should log the time.
     *
     * @return  true to log, false to not log.
     */
    protected boolean shouldLog() {
        // default check first
        if (logLevel == null && logCategory == null) {
            return LOG.isInfoEnabled();
        }

        // okay user have set some parameters
        return isLoggerEnabled(getLoggerToUse(), logLevel);
    }

    /**
     * Get's the logger to use.
     *
     * @return the logger to use.
     */
    protected Logger getLoggerToUse() {
        if (logCategory != null) {
            if (categoryLogger == null) {
                // init category logger
                categoryLogger = LoggerFactory.getLogger(logCategory);
                if (logLevel == null) {
                    logLevel = "info"; // use info as default if not provided
                }
            }
            return categoryLogger;
        }

        return LOG;
    }

    /**
     * Performs the actual logging.
     *
     * @param logger  the provided logger to use.
     * @param message  the message to log.
     */
    protected void doLog(Logger logger, String message) {
        if (logLevel == null) {
            logger.info(message);
            return;
        }

        if ("debug".equalsIgnoreCase(logLevel)) {
            logger.debug(message);
        } else if ("info".equalsIgnoreCase(logLevel)) {
            logger.info(message);
        } else if ("warn".equalsIgnoreCase(logLevel)) {
            logger.warn(message);
        } else if ("error".equalsIgnoreCase(logLevel)) {
            logger.error(message);
        } else if ("fatal".equalsIgnoreCase(logLevel)) {
            logger.fatal(message);
        } else if ("trace".equalsIgnoreCase(logLevel)) {
            logger.trace(message);
        } else {
            throw new IllegalArgumentException("LogLevel [" + logLevel + "] is not supported");
        }
    }

    /**
     * Is the given logger enalbed at the given level?
     *
     * @param logger  the logger.
     * @param level   the level to check if isXXXEnabled.
     * @return true if enabled, false if not.
     */
    private static boolean isLoggerEnabled(Logger logger, String level) {
        if ("debug".equalsIgnoreCase(level)) {
            return logger.isDebugEnabled();
        } else if ("info".equalsIgnoreCase(level)) {
            return logger.isInfoEnabled();
        } else if ("warn".equalsIgnoreCase(level)) {
            return logger.isWarnEnabled();
        } else if ("error".equalsIgnoreCase(level)) {
            return logger.isErrorEnabled();
        } else if ("fatal".equalsIgnoreCase(level)) {
            return logger.isFatalEnabled();
        } else if ("trace".equalsIgnoreCase(level)) {
            return logger.isTraceEnabled();
        } else {
            throw new IllegalArgumentException("LogLevel [" + level + "] is not supported");
        }
    }

}