001: /*
002: * Copyright (c) 2002-2006 by OpenSymphony
003: * All rights reserved.
004: */
005: package com.opensymphony.xwork.interceptor;
006:
007: import com.opensymphony.xwork.ActionInvocation;
008: import org.apache.commons.logging.Log;
009: import org.apache.commons.logging.LogFactory;
010:
011: /**
012: * <!-- START SNIPPET: description -->
013: * This interceptor logs the amount of time in milliseconds. In order for this interceptor to work properly, the
014: * logging framework must be set to at least the
015: * <a href="http://jakarta.apache.org/commons/logging/api/org/apache/commons/logging/Log.html">INFO</a> level.
016: * This interceptor relies on the
017: * <a href="http://jakarta.apache.org/commons/logging/">Commons Logging API</a> to report its execution-time value.
018: * <!-- END SNIPPET: description -->
019: *
020: * <!-- START SNIPPET: parameters -->
021: *
022: * <ul>
023: *
024: * <li>logLevel (optional) - what log level should we use (<code>trace, debug, info, warn, error, fatal</code>)? - defaut is <code>info</code></li>
025: *
026: * <li>logCategory (optional) - If provided we would use this category (eg. <code>com.mycompany.app</code>).
027: * Default is to use <code>com.opensymphony.xwork.interceptor.TimerInterceptor</code>.</li>
028: *
029: * </ul>
030: *
031: * The parameters above enables us to log all action execution times in our own logfile.
032: *
033: * <!-- END SNIPPET: parameters -->
034: *
035: * <!-- START SNIPPET: extending -->
036: * This interceptor can be extended to provide custom message format. Users should override the
037: * <code>invokeUnderTiming</code> method.
038: * <!-- END SNIPPET: extending -->
039: *
040: * <pre>
041: * <!-- START SNIPPET: example -->
042: * <!-- records only the action's execution time -->
043: * <action name="someAction" class="com.examples.SomeAction">
044: * <interceptor-ref name="completeStack"/>
045: * <interceptor-ref name="timer"/>
046: * <result name="success">good_result.ftl</result>
047: * </action>
048: *
049: * <!-- records action's execution time as well as other interceptors-->
050: * <action name="someAction" class="com.examples.SomeAction">
051: * <interceptor-ref name="timer"/>
052: * <interceptor-ref name="completeStack"/>
053: * <result name="success">good_result.ftl</result>
054: * </action>
055: * <!-- END SNIPPET: example -->
056: * </pre>
057: *
058: * This second example uses our own log category at debug level.
059: *
060: * <pre>
061: * <!-- START SNIPPET: example2 -->
062: * <!-- records only the action's execution time -->
063: * <action name="someAction" class="com.examples.SomeAction">
064: * <interceptor-ref name="completeStack"/>
065: * <interceptor-ref name="timer">
066: * <param name="logLevel">debug</param>
067: * <param name="logCategory">com.mycompany.myapp.actiontime</param>
068: * <interceptor-ref/>
069: * <result name="success">good_result.ftl</result>
070: * </action>
071: *
072: * <!-- records action's execution time as well as other interceptors-->
073: * <action name="someAction" class="com.examples.SomeAction">
074: * <interceptor-ref name="timer"/>
075: * <interceptor-ref name="completeStack"/>
076: * <result name="success">good_result.ftl</result>
077: * </action>
078: * <!-- END SNIPPET: example2 -->
079: * </pre>
080: *
081: * @author Jason Carreira
082: * @author Claus Ibsen
083: */
084: public class TimerInterceptor implements Interceptor {
085: protected static final Log log = LogFactory
086: .getLog(TimerInterceptor.class);
087:
088: protected Log categoryLogger;
089: protected String logCategory;
090: protected String logLevel;
091:
092: public String getLogCategory() {
093: return logCategory;
094: }
095:
096: public void setLogCategory(String logCatgory) {
097: this .logCategory = logCatgory;
098: }
099:
100: public String getLogLevel() {
101: return logLevel;
102: }
103:
104: public void setLogLevel(String logLevel) {
105: this .logLevel = logLevel;
106: }
107:
108: public void destroy() {
109: }
110:
111: public void init() {
112: }
113:
114: public String intercept(ActionInvocation invocation)
115: throws Exception {
116: if (!shouldLog()) {
117: return invocation.invoke();
118: } else {
119: return invokeUnderTiming(invocation);
120: }
121: }
122:
123: /**
124: * Is called to invoke the action invocation and time the execution time.
125: *
126: * @param invocation the action invocation.
127: * @return the result of the action execution.
128: * @throws Exception can be thrown from the action.
129: */
130: protected String invokeUnderTiming(ActionInvocation invocation)
131: throws Exception {
132: long startTime = System.currentTimeMillis();
133: String result = invocation.invoke();
134: long executionTime = System.currentTimeMillis() - startTime;
135:
136: StringBuffer message = new StringBuffer(100);
137: message.append("Executed action [");
138: String namespace = invocation.getProxy().getNamespace();
139: if ((namespace != null) && (namespace.trim().length() > 0)) {
140: message.append(namespace).append("/");
141: }
142: message.append(invocation.getProxy().getActionName());
143: message.append("!");
144: message.append(invocation.getProxy().getMethod());
145: message.append("] took ").append(executionTime).append(" ms.");
146:
147: doLog(getLoggerToUse(), message.toString());
148:
149: return result;
150: }
151:
152: /**
153: * Determines if we should log the time.
154: *
155: * @return true to log, false to not log.
156: */
157: protected boolean shouldLog() {
158: // default check first
159: if (logLevel == null && logCategory == null) {
160: return log.isInfoEnabled();
161: }
162:
163: // okay user have set some parameters
164: return isLoggerEnabled(getLoggerToUse(), logLevel);
165: }
166:
167: /**
168: * Get's the logger to use.
169: *
170: * @return the logger to use.
171: */
172: protected Log getLoggerToUse() {
173: if (logCategory != null) {
174: if (categoryLogger == null) {
175: // init category logger
176: categoryLogger = LogFactory.getLog(logCategory);
177: if (logLevel == null) {
178: logLevel = "info"; // use info as default if not provided
179: }
180: }
181: return categoryLogger;
182: }
183:
184: return log;
185: }
186:
187: /**
188: * Performs the actual logging.
189: *
190: * @param logger the provided logger to use.
191: * @param message the message to log.
192: */
193: protected void doLog(Log logger, String message) {
194: if (logLevel == null) {
195: logger.info(message);
196: return;
197: }
198:
199: if ("debug".equalsIgnoreCase(logLevel)) {
200: logger.debug(message);
201: } else if ("info".equalsIgnoreCase(logLevel)) {
202: logger.info(message);
203: } else if ("warn".equalsIgnoreCase(logLevel)) {
204: logger.warn(message);
205: } else if ("error".equalsIgnoreCase(logLevel)) {
206: logger.error(message);
207: } else if ("fatal".equalsIgnoreCase(logLevel)) {
208: logger.fatal(message);
209: } else if ("trace".equalsIgnoreCase(logLevel)) {
210: logger.trace(message);
211: } else {
212: throw new IllegalArgumentException("LogLevel [" + logLevel
213: + "] is not supported");
214: }
215: }
216:
217: /**
218: * Is the given logger enalbed at the given level?
219: *
220: * @param logger the logger.
221: * @param level the level to check if <code>isXXXEnabled</code>.
222: * @return <tt>true</tt> if enabled, <tt>false</tt> if not.
223: */
224: private static boolean isLoggerEnabled(Log logger, String level) {
225: if ("debug".equalsIgnoreCase(level)) {
226: return logger.isDebugEnabled();
227: } else if ("info".equalsIgnoreCase(level)) {
228: return logger.isInfoEnabled();
229: } else if ("warn".equalsIgnoreCase(level)) {
230: return logger.isWarnEnabled();
231: } else if ("error".equalsIgnoreCase(level)) {
232: return logger.isErrorEnabled();
233: } else if ("fatal".equalsIgnoreCase(level)) {
234: return logger.isFatalEnabled();
235: } else if ("trace".equalsIgnoreCase(level)) {
236: return logger.isTraceEnabled();
237: } else {
238: throw new IllegalArgumentException("LogLevel [" + level
239: + "] is not supported");
240: }
241: }
242:
243: }
|