1 package org.perf4j.aop;
2
3 import org.apache.commons.jexl.Expression;
4 import org.apache.commons.jexl.ExpressionFactory;
5 import org.apache.commons.jexl.JexlContext;
6 import org.apache.commons.jexl.context.HashMapContext;
7 import org.perf4j.LoggingStopWatch;
8
9 import java.util.Map;
10 import java.util.concurrent.ConcurrentHashMap;
11
12 /**
13 * This AgnosticTimingAspect class contains all the logic for executing a profiled method with appropriate timing calls,
14 * but in an AOP-framework-agnostic way. You may choose to either extend or wrap this class to create an aspect in
15 * your desired framework. For example, if you look at the {@link org.perf4j.aop.AbstractTimingAspect}, you can see
16 * that it delegates all functionality to this class - it just includes the necessary AspectJ annotations and wraps
17 * the AspectJ-specific ProceedingJoinPoint as an {@link org.perf4j.aop.AbstractJoinPoint}.
18 *
19 * @author Marcin ZajƒÖczkowski, Alex Devine
20 */
21 public class AgnosticTimingAspect {
22 /**
23 * This Map is used to cache compiled JEXL expressions. While theoretically unbounded, in reality the number of
24 * possible keys is equivalent to the number of unique JEXL expressions created in @Profiled annotations, which
25 * will have to be loaded in memory anyway when the class is loaded.
26 */
27 private Map<String, Expression> jexlExpressionCache = new ConcurrentHashMap<String, Expression>(64, .75F, 16);
28
29 /**
30 * This method actually executes the profiled method. Your AOP-framework-specific class should delegate to this
31 * method to proceed with execution.
32 *
33 * @param joinPoint The AOP join point - usually this will just be a simple wrapper around the
34 * AOP-framework-specific join point.
35 * @param profiled The Profiled annotation that was set on the method being profiled.
36 * @param stopWatch This LogginStopWatch should be started JUST before this method is called.
37 * @return The return value from the profiled method.
38 * @throws Throwable Exception thrown by the profiled method will bubble up.
39 */
40 public Object runProfiledMethod(AbstractJoinPoint joinPoint, Profiled profiled, LoggingStopWatch stopWatch)
41 throws Throwable {
42 //if we're not going to end up logging the stopwatch, just run the wrapped method
43 if (!stopWatch.isLogging()) {
44 return joinPoint.proceed();
45 }
46
47 stopWatch.setTimeThreshold(profiled.timeThreshold());
48 stopWatch.setNormalAndSlowSuffixesEnabled(profiled.normalAndSlowSuffixesEnabled());
49
50 Object retVal = null;
51 Throwable exceptionThrown = null;
52 try {
53 return retVal = joinPoint.proceed();
54 } catch (Throwable t) {
55 throw exceptionThrown = t;
56 } finally {
57 String tag = getStopWatchTag(profiled, joinPoint, retVal, exceptionThrown);
58 String message = getStopWatchMessage(profiled, joinPoint, retVal, exceptionThrown);
59
60 if (profiled.logFailuresSeparately()) {
61 tag = (exceptionThrown == null) ? tag + ".success" : tag + ".failure";
62 }
63
64 stopWatch.stop(tag, message);
65 }
66 }
67
68 /**
69 * Helper method gets the tag to use for StopWatch logging. Performs JEXL evaluation if necessary.
70 *
71 * @param profiled The profiled annotation that was attached to the method.
72 * @param joinPoint The AbstractJoinPoint encapulates the method around which this aspect advice runs.
73 * @param returnValue The value returned from the execution of the profiled method, or null if the method
74 * returned void or an exception was thrown.
75 * @param exceptionThrown The exception thrown, if any, by the profiled method. Will be null if the method
76 * completed normally.
77 * @return The value to use as the StopWatch tag.
78 */
79 protected String getStopWatchTag(Profiled profiled,
80 AbstractJoinPoint joinPoint,
81 Object returnValue,
82 Throwable exceptionThrown) {
83 String tag;
84 if (Profiled.DEFAULT_TAG_NAME.equals(profiled.tag())) {
85 // if the tag name is not explicitly set on the Profiled annotation,
86 // use the name of the method being annotated.
87 tag = joinPoint.getMethodName();
88 } else if (profiled.el() && profiled.tag().indexOf("{") >= 0) {
89 tag = evaluateJexl(profiled.tag(),
90 joinPoint.getParameters(),
91 joinPoint.getExecutingObject(),
92 returnValue,
93 exceptionThrown);
94 } else {
95 tag = profiled.tag();
96 }
97 return tag;
98 }
99
100
101 /**
102 * Helper method get the message to use for StopWatch logging. Performs JEXL evaluation if necessary.
103 *
104 * @param profiled The profiled annotation that was attached to the method.
105 * @param joinPoint The AbstractJoinPoint encapulates the method around which this aspect advice runs.
106 * @param returnValue The value returned from the execution of the profiled method, or null if the method
107 * returned void or an exception was thrown.
108 * @param exceptionThrown The exception thrown, if any, by the profiled method. Will be null if the method
109 * completed normally.
110 * @return The value to use as the StopWatch message.
111 */
112 protected String getStopWatchMessage(Profiled profiled,
113 AbstractJoinPoint joinPoint,
114 Object returnValue,
115 Throwable exceptionThrown) {
116 String message;
117 if (profiled.el() && profiled.message().indexOf("{") >= 0) {
118 message = evaluateJexl(profiled.message(),
119 joinPoint.getParameters(),
120 joinPoint.getExecutingObject(),
121 returnValue,
122 exceptionThrown);
123 if ("".equals(message)) {
124 message = null;
125 }
126 } else {
127 message = "".equals(profiled.message()) ? null : profiled.message();
128 }
129 return message;
130 }
131
132 /**
133 * Helper method is used to parse out {expressionLanguage} elements from the text and evaluate the strings using
134 * JEXL.
135 *
136 * @param text The text to be parsed.
137 * @param args The args that were passed to the method to be profiled.
138 * @param annotatedObject The value of the object whose method was profiled. Will be null if a class method was
139 * profiled.
140 * @param returnValue The value returned from the execution of the profiled method, or null if the method
141 * returned void or an exception was thrown.
142 * @param exceptionThrown The exception thrown, if any, by the profiled method. Will be null if the method
143 * completed normally.
144 * @return The evaluated string.
145 * @see Profiled#el()
146 */
147 @SuppressWarnings("unchecked")
148 protected String evaluateJexl(String text,
149 Object[] args,
150 Object annotatedObject,
151 Object returnValue,
152 Throwable exceptionThrown) {
153 StringBuilder retVal = new StringBuilder(text.length());
154
155 //create a JexlContext to be used in all evaluations
156 JexlContext jexlContext = new HashMapContext();
157 for (int i = 0; i < args.length; i++) {
158 jexlContext.getVars().put("$" + i, args[i]);
159 }
160 jexlContext.getVars().put("$this", annotatedObject);
161 jexlContext.getVars().put("$return", returnValue);
162 jexlContext.getVars().put("$exception", exceptionThrown);
163
164 // look for {expression} in the passed in text
165 int bracketIndex;
166 int lastCloseBracketIndex = -1;
167 while ((bracketIndex = text.indexOf('{', lastCloseBracketIndex + 1)) >= 0) {
168 retVal.append(text.substring(lastCloseBracketIndex + 1, bracketIndex));
169
170 lastCloseBracketIndex = text.indexOf('}', bracketIndex + 1);
171 if (lastCloseBracketIndex == -1) {
172 //if there wasn't a closing bracket index just go to the end of the string
173 lastCloseBracketIndex = text.length();
174 }
175
176 String expressionText = text.substring(bracketIndex + 1, lastCloseBracketIndex);
177 if (expressionText.length() > 0) {
178 try {
179 Object result = getJexlExpression(expressionText).evaluate(jexlContext);
180 retVal.append(result);
181 } catch (Exception e) {
182 //we don't want to propagate exceptions up
183 retVal.append("_EL_ERROR_");
184 }
185 }
186 }
187
188 //append the final part
189 if (lastCloseBracketIndex < text.length()) {
190 retVal.append(text.substring(lastCloseBracketIndex + 1, text.length()));
191 }
192
193 return retVal.toString();
194 }
195
196 /**
197 * Helper method gets a compiled JEXL expression for the specified expression text, either from the cache or by
198 * creating a new compiled expression.
199 *
200 * @param expressionText The JEXL expression text
201 * @return A compiled JEXL expression representing the expression text
202 * @throws Exception Thrown if there was an error compiling the expression text
203 */
204 protected Expression getJexlExpression(String expressionText) throws Exception {
205 Expression retVal = jexlExpressionCache.get(expressionText);
206 if (retVal == null) {
207 //Don't need synchronization here - if we end up calling createExpression in 2 separate threads, that's fine
208 jexlExpressionCache.put(expressionText, retVal = ExpressionFactory.createExpression(expressionText));
209 }
210 return retVal;
211 }
212 }