001: /*
002: * Copyright 2002-2006 the original author or authors.
003: *
004: * Licensed under the Apache License, Version 2.0 (the "License");
005: * you may not use this file except in compliance with the License.
006: * You may obtain a copy of the License at
007: *
008: * http://www.apache.org/licenses/LICENSE-2.0
009: *
010: * Unless required by applicable law or agreed to in writing, software
011: * distributed under the License is distributed on an "AS IS" BASIS,
012: * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
013: * See the License for the specific language governing permissions and
014: * limitations under the License.
015: */
016:
017: package org.springframework.aop.interceptor;
018:
019: import java.util.Set;
020: import java.util.regex.Matcher;
021: import java.util.regex.Pattern;
022:
023: import org.aopalliance.intercept.MethodInvocation;
024: import org.apache.commons.logging.Log;
025:
026: import org.springframework.core.Constants;
027: import org.springframework.util.Assert;
028: import org.springframework.util.ClassUtils;
029: import org.springframework.util.StopWatch;
030: import org.springframework.util.StringUtils;
031:
032: /**
033: * <code>MethodInterceptor</code> implementation that allows for highly customizable
034: * method-level tracing, using placeholders.
035: *
036: * <p>Trace messages are written on method entry, and if the method invocation succeeds
037: * on method exit. If an invocation results in an exception, then an exception message
038: * is written. The contents of these trace messages is fully customizable and special
039: * placeholders are available to allow you to include runtime information in your log
040: * messages. The placeholders available are:
041: *
042: * <p><ul>
043: * <li><code>$[methodName]</code> - replaced with the name of the method being invoked</li>
044: * <li><code>$[targetClassName]</code> - replaced with the name of the class that is
045: * the target of the invocation</li>
046: * <li><code>$[targetClassShortName]</code> - replaced with the short name of the class
047: * that is the target of the invocation</li>
048: * <li><code>$[returnValue]</code> - replaced with the value returned by the invocation</li>
049: * <li><code>$[argumentTypes]</code> - replaced with a comma-separated list of the
050: * short class names of the method arguments</li>
051: * <li><code>$[arguments]</code> - replaced with a comma-separated list of the
052: * <code>String</code> representation of the method arguments</li>
053: * <li><code>$[exception]</code> - replaced with the <code>String</code> representation
054: * of any <code>Throwable</code> raised during the invocation</li>
055: * <li><code>$[invocationTime]</code> - replaced with the time, in milliseconds,
056: * taken by the method invocation</li>
057: * </ul>
058: *
059: * <p>There are restrictions on which placeholders can be used in which messages:
060: * see the individual message properties for details on the valid placeholders.
061: *
062: * <p><b>NOTE: This class requires JDK 1.4 or later.</b> It uses the
063: * <code>java.util.regex</code> package for regular expression matching,
064: * which is only available on JDK 1.4+.
065: *
066: * @author Rob Harrop
067: * @since 1.2
068: * @see #setEnterMessage
069: * @see #setExitMessage
070: * @see #setExceptionMessage
071: * @see SimpleTraceInterceptor
072: */
073: public class CustomizableTraceInterceptor extends
074: AbstractTraceInterceptor {
075:
076: /**
077: * The <code>$[methodName]</code> placeholder.
078: * Replaced with the name of the method being invoked.
079: */
080: public static final String PLACEHOLDER_METHOD_NAME = "$[methodName]";
081:
082: /**
083: * The <code>$[targetClassName]</code> placeholder.
084: * Replaced with the fully-qualifed name of the <code>Class</code>
085: * of the method invocation target.
086: */
087: public static final String PLACEHOLDER_TARGET_CLASS_NAME = "$[targetClassName]";
088:
089: /**
090: * The <code>$[targetClassShortName]</code> placeholder.
091: * Replaced with the short name of the <code>Class</code> of the
092: * method invocation target.
093: */
094: public static final String PLACEHOLDER_TARGET_CLASS_SHORT_NAME = "$[targetClassShortName]";
095:
096: /**
097: * The <code>$[returnValue]</code> placeholder.
098: * Replaced with the <code>String</code> representation of the value
099: * returned by the method invocation.
100: */
101: public static final String PLACEHOLDER_RETURN_VALUE = "$[returnValue]";
102:
103: /**
104: * The <code>$[argumentTypes]</code> placeholder.
105: * Replaced with a comma-separated list of the argument types for the
106: * method invocation. Argument types are written as short class names.
107: */
108: public static final String PLACEHOLDER_ARGUMENT_TYPES = "$[argumentTypes]";
109:
110: /**
111: * The <code>$[arguments]</code> placeholder.
112: * Replaced with a comma separated list of the argument values for the
113: * method invocation. Relies on the <code>toString()</code> method of
114: * each argument type.
115: */
116: public static final String PLACEHOLDER_ARGUMENTS = "$[arguments]";
117:
118: /**
119: * The <code>$[exception]</code> placeholder.
120: * Replaced with the <code>String</code> representation of any
121: * <code>Throwable</code> raised during method invocation.
122: */
123: public static final String PLACEHOLDER_EXCEPTION = "$[exception]";
124:
125: /**
126: * The <code>$[invocationTime]</code> placeholder.
127: * Replaced with the time taken by the invocation (in milliseconds).
128: */
129: public static final String PLACEHOLDER_INVOCATION_TIME = "$[invocationTime]";
130:
131: /**
132: * The default message used for writing method entry messages.
133: */
134: private static final String DEFAULT_ENTER_MESSAGE = "Entering method '"
135: + PLACEHOLDER_METHOD_NAME
136: + "' of class ["
137: + PLACEHOLDER_TARGET_CLASS_NAME + "]";
138:
139: /**
140: * The default message used for writing method exit messages.
141: */
142: private static final String DEFAULT_EXIT_MESSAGE = "Exiting method '"
143: + PLACEHOLDER_METHOD_NAME
144: + "' of class ["
145: + PLACEHOLDER_TARGET_CLASS_NAME + "]";
146:
147: /**
148: * The default method used for writing exception messages.
149: */
150: private static final String DEFAULT_EXCEPTION_MESSAGE = "Exception thrown in method '"
151: + PLACEHOLDER_METHOD_NAME
152: + "' of class ["
153: + PLACEHOLDER_TARGET_CLASS_NAME + "]";
154:
155: /**
156: * The <code>Pattern</code> used to match placeholders.
157: */
158: private static final Pattern PATTERN = Pattern
159: .compile("\\$\\[\\p{Alpha}+\\]");
160:
161: /**
162: * The <code>Pattern</code> used to escape regex values in class names -
163: * specifically <code>$</code>.
164: */
165: private static final Pattern ESCAPE_PATTERN = Pattern
166: .compile("\\$");
167:
168: /**
169: * The <code>Set</code> of allowed placeholders.
170: */
171: private static final Set ALLOWED_PLACEHOLDERS = new Constants(
172: CustomizableTraceInterceptor.class)
173: .getValues("PLACEHOLDER_");
174:
175: /**
176: * The message for method entry.
177: */
178: private String enterMessage = DEFAULT_ENTER_MESSAGE;
179:
180: /**
181: * The message for method exit.
182: */
183: private String exitMessage = DEFAULT_EXIT_MESSAGE;
184:
185: /**
186: * The message for exceptions during method execution.
187: */
188: private String exceptionMessage = DEFAULT_EXCEPTION_MESSAGE;
189:
190: /**
191: * Ses the template used for method entry log messages.
192: * This template can contain any of the following placeholders:
193: * <ul>
194: * <li><code>$[targetClassName]</code></li>
195: * <li><code>$[targetClassShortName]</code></li>
196: * <li><code>$[argumentTypes]</code></li>
197: * <li><code>$[arguments]</code></li>
198: * </ul>
199: * @throws IllegalArgumentException if the message template is empty
200: * or contains any invalid placeholders
201: */
202: public void setEnterMessage(String enterMessage)
203: throws IllegalArgumentException {
204: Assert
205: .hasText(enterMessage,
206: "'enterMessage' must not be empty");
207: checkForInvalidPlaceholders(enterMessage);
208: Assert.doesNotContain(enterMessage, PLACEHOLDER_RETURN_VALUE,
209: "enterMessage cannot contain placeholder ["
210: + PLACEHOLDER_RETURN_VALUE + "]");
211: Assert.doesNotContain(enterMessage, PLACEHOLDER_EXCEPTION,
212: "enterMessage cannot contain placeholder ["
213: + PLACEHOLDER_EXCEPTION + "]");
214: Assert.doesNotContain(enterMessage,
215: PLACEHOLDER_INVOCATION_TIME,
216: "enterMessage cannot contain placeholder ["
217: + PLACEHOLDER_INVOCATION_TIME + "]");
218: this .enterMessage = enterMessage;
219: }
220:
221: /**
222: * Set the template used for method exit log messages.
223: * This template can contain any of the following placeholders:
224: * <ul>
225: * <li><code>$[targetClassName]</code></li>
226: * <li><code>$[targetClassShortName]</code></li>
227: * <li><code>$[argumentTypes]</code></li>
228: * <li><code>$[arguments]</code></li>
229: * <li><code>$[returnValue]</code></li>
230: * <li><code>$[invocationTime]</code></li>
231: * </ul>
232: * @throws IllegalArgumentException if the message template is empty
233: * or contains any invalid placeholders
234: */
235: public void setExitMessage(String exitMessage) {
236: Assert.hasText(exitMessage, "'exitMessage' must not be empty");
237: checkForInvalidPlaceholders(exitMessage);
238: Assert.doesNotContain(exitMessage, PLACEHOLDER_EXCEPTION,
239: "exitMessage cannot contain placeholder ["
240: + PLACEHOLDER_EXCEPTION + "]");
241: this .exitMessage = exitMessage;
242: }
243:
244: /**
245: * Set the template used for method exception log messages.
246: * This template can contain any of the following placeholders:
247: * <ul>
248: * <li><code>$[targetClassName]</code></li>
249: * <li><code>$[targetClassShortName]</code></li>
250: * <li><code>$[argumentTypes]</code></li>
251: * <li><code>$[arguments]</code></li>
252: * <li><code>$[exception]</code></li>
253: * </ul>
254: * @throws IllegalArgumentException if the message template is empty
255: * or contains any invalid placeholders
256: */
257: public void setExceptionMessage(String exceptionMessage) {
258: Assert.hasText(exceptionMessage,
259: "'exceptionMessage' must not be empty");
260: checkForInvalidPlaceholders(exceptionMessage);
261: Assert.doesNotContain(exceptionMessage,
262: PLACEHOLDER_RETURN_VALUE,
263: "exceptionMessage cannot contain placeholder ["
264: + PLACEHOLDER_RETURN_VALUE + "]");
265: Assert.doesNotContain(exceptionMessage,
266: PLACEHOLDER_INVOCATION_TIME,
267: "exceptionMessage cannot contain placeholder ["
268: + PLACEHOLDER_INVOCATION_TIME + "]");
269: this .exceptionMessage = exceptionMessage;
270: }
271:
272: /**
273: * Writes a log message before the invocation based on the value of <code>enterMessage</code>.
274: * If the invocation succeeds, then a log message is written on exit based on the value
275: * <code>exitMessage</code>. If an exception occurs during invocation, then a message is
276: * written based on the value of <code>exceptionMessage</code>.
277: * @see #setEnterMessage
278: * @see #setExitMessage
279: * @see #setExceptionMessage
280: */
281: protected Object invokeUnderTrace(MethodInvocation invocation,
282: Log logger) throws Throwable {
283: String name = invocation.getMethod().getDeclaringClass()
284: .getName()
285: + "." + invocation.getMethod().getName();
286: StopWatch stopWatch = new StopWatch(name);
287: Object returnValue = null;
288: boolean exitThroughException = false;
289: try {
290: stopWatch.start(name);
291: writeToLog(logger, replacePlaceholders(this .enterMessage,
292: invocation, null, null, -1));
293: returnValue = invocation.proceed();
294: return returnValue;
295: } catch (Throwable ex) {
296: if (stopWatch.isRunning()) {
297: stopWatch.stop();
298: }
299: exitThroughException = true;
300: writeToLog(logger, replacePlaceholders(
301: this .exceptionMessage, invocation, null, ex,
302: stopWatch.getTotalTimeMillis()), ex);
303: throw ex;
304: } finally {
305: if (!exitThroughException) {
306: if (stopWatch.isRunning()) {
307: stopWatch.stop();
308: }
309: writeToLog(logger, replacePlaceholders(
310: this .exitMessage, invocation, returnValue,
311: null, stopWatch.getTotalTimeMillis()));
312: }
313: }
314: }
315:
316: /**
317: * Writes the supplied message to the supplied <code>Log</code> instance.
318: * @see #writeToLog(org.apache.commons.logging.Log, String, Throwable)
319: */
320: protected void writeToLog(Log logger, String message) {
321: writeToLog(logger, message, null);
322: }
323:
324: /**
325: * Writes the supplied message and {@link Throwable} to the
326: * supplied <code>Log</code> instance. By default messages are written
327: * at <code>TRACE</code> level. Sub-classes can override this method
328: * to control which level the message is written at.
329: */
330: protected void writeToLog(Log logger, String message, Throwable ex) {
331: if (ex != null) {
332: logger.trace(message, ex);
333: } else {
334: logger.trace(message);
335: }
336: }
337:
338: /**
339: * Replace the placeholders in the given message with the supplied values,
340: * or values derived from those supplied.
341: * @param message the message template containing the placeholders to be replaced
342: * @param methodInvocation the <code>MethodInvocation</code> being logged.
343: * Used to derive values for all placeholders except <code>$[exception]</code>
344: * and <code>$[returnValue]</code>.
345: * @param returnValue any value returned by the invocation.
346: * Used to replace the <code>$[returnValue]</code> placeholder. May be <code>null</code>.
347: * @param throwable any <code>Throwable</code> raised during the invocation.
348: * The value of <code>Throwable.toString()</code> is replaced for the
349: * <code>$[exception]</code> placeholder. May be <code>null</code>.
350: * @param invocationTime the value to write in place of the
351: * <code>$[invocationTime]</code> placeholder
352: * @return the formatted output to write to the log
353: */
354: protected String replacePlaceholders(String message,
355: MethodInvocation methodInvocation, Object returnValue,
356: Throwable throwable, long invocationTime) {
357:
358: Matcher matcher = PATTERN.matcher(message);
359:
360: StringBuffer output = new StringBuffer();
361: while (matcher.find()) {
362: String match = matcher.group();
363: if (PLACEHOLDER_METHOD_NAME.equals(match)) {
364: matcher.appendReplacement(output, methodInvocation
365: .getMethod().getName());
366: } else if (PLACEHOLDER_TARGET_CLASS_NAME.equals(match)) {
367: String targetClassName = escape(methodInvocation
368: .getThis().getClass().getName());
369: matcher.appendReplacement(output, targetClassName);
370: } else if (PLACEHOLDER_TARGET_CLASS_SHORT_NAME
371: .equals(match)) {
372: matcher.appendReplacement(output, escape(ClassUtils
373: .getShortName(methodInvocation.getThis()
374: .getClass())));
375: } else if (PLACEHOLDER_ARGUMENTS.equals(match)) {
376: matcher.appendReplacement(output, escape(StringUtils
377: .arrayToCommaDelimitedString(methodInvocation
378: .getArguments())));
379: } else if (PLACEHOLDER_ARGUMENT_TYPES.equals(match)) {
380: appendArgumentTypes(methodInvocation, matcher, output);
381: } else if (PLACEHOLDER_RETURN_VALUE.equals(match)) {
382: appendReturnValue(methodInvocation, matcher, output,
383: returnValue);
384: } else if (throwable != null
385: && PLACEHOLDER_EXCEPTION.equals(match)) {
386: matcher.appendReplacement(output, throwable.toString());
387: } else if (PLACEHOLDER_INVOCATION_TIME.equals(match)) {
388: matcher.appendReplacement(output, Long
389: .toString(invocationTime));
390: } else {
391: // Should not happen since placeholders are checked earlier.
392: throw new IllegalArgumentException(
393: "Unknown placeholder [" + match + "]");
394: }
395: }
396: matcher.appendTail(output);
397:
398: return output.toString();
399: }
400:
401: /**
402: * Adds the <code>String</code> representation of the method return value
403: * to the supplied <code>StringBuffer</code>. Correctly handles
404: * <code>null</code> and <code>void</code> results.
405: * @param methodInvocation the <code>MethodInvocation</code> that returned the value
406: * @param matcher the <code>Matcher</code> containing the matched placeholder
407: * @param output the <code>StringBuffer</code> to write output to
408: * @param returnValue the value returned by the method invocatio.
409: */
410: private void appendReturnValue(MethodInvocation methodInvocation,
411: Matcher matcher, StringBuffer output, Object returnValue) {
412:
413: if (methodInvocation.getMethod().getReturnType() == void.class) {
414: matcher.appendReplacement(output, "void");
415: } else if (returnValue == null) {
416: matcher.appendReplacement(output, "null");
417: } else {
418: matcher.appendReplacement(output, escape(returnValue
419: .toString()));
420: }
421: }
422:
423: /**
424: * Adds a comma-separated list of the short <code>Class</code> names of the
425: * method argument types to the output. For example, if a method has signature
426: * <code>put(java.lang.String, java.lang.Object)</code> then the value returned
427: * will be <code>String, Object</code>.
428: * @param methodInvocation the <code>MethodInvocation</code> being logged.
429: * Arguments will be retreived from the corresponding <code>Method</code>.
430: * @param matcher the <code>Matcher</code> containing the state of the output
431: * @param output the <code>StringBuffer</code> containing the output
432: */
433: private void appendArgumentTypes(MethodInvocation methodInvocation,
434: Matcher matcher, StringBuffer output) {
435: Class[] argumentTypes = methodInvocation.getMethod()
436: .getParameterTypes();
437: String[] argumentTypeShortNames = new String[argumentTypes.length];
438: for (int i = 0; i < argumentTypeShortNames.length; i++) {
439: argumentTypeShortNames[i] = ClassUtils
440: .getShortName(argumentTypes[i]);
441: }
442: matcher.appendReplacement(output, escape(StringUtils
443: .arrayToCommaDelimitedString(argumentTypeShortNames)));
444: }
445:
446: /**
447: * Checks to see if the supplied <code>String</code> has any placeholders
448: * that are not specified as constants on this class and throws an
449: * <code>IllegalArgumentException</code> if so.
450: */
451: private void checkForInvalidPlaceholders(String message)
452: throws IllegalArgumentException {
453: Matcher matcher = PATTERN.matcher(message);
454: while (matcher.find()) {
455: String match = matcher.group();
456: if (!ALLOWED_PLACEHOLDERS.contains(match)) {
457: throw new IllegalArgumentException("Placeholder ["
458: + match + "] is not valid");
459: }
460: }
461: }
462:
463: /**
464: * Replaces <code>$</code> in inner class names with <code>\$</code>.
465: */
466: private String escape(String input) {
467: Matcher matcher = ESCAPE_PATTERN.matcher(input);
468: StringBuffer output = new StringBuffer(input.length());
469: while (matcher.find()) {
470: matcher.appendReplacement(output, "");
471: output.append("\\").append(matcher.group());
472: }
473: matcher.appendTail(output);
474: return output.toString();
475: }
476:
477: }
|