Add method tracing (params, result) to existing application w/o modifying it
Have you ever needed to learn what's going on in a 3rd-party java application and yet didn't want to debug it and step through it? Were you wishing to be able to see what methods get called in what order together with their actual parameters and return values? There is a "simple" solution: AspectWerkz.
Quick start:
- Download AspectWerkz (I had 2.0)
- Create an aop.xml where you define what methods to observe
- (Optional) Modify the tracer class
- Run the target application with the aspect under Java 5 (AspectWerkz supports also older JVM but that's more tricky):
$JRE5_HOME/bin/java
-javaagent:lib/aspectwerkz-jdk5-2.0.jar -Daspectwerkz.definition.file=/path/to/the/aop.xml
-cp <some jars from lib/, see below>:./bin:<your classpath>
yourpackage.YourMainClass
Classpath:
aspectwerkz-core-2.0.jar
aspectwerkz-2.0.jar
commons-collections.jar
commons-beanutils.jar
commons-logging.jar
dom4j-1.4.jar, qdox-1.4.jar, concurrent-1.3.1.jar, trove-1.0.jar (see aspectwerkz-2.0.jar's Manifest)
See: aspectwerkz-2.0\src\samples\examples\logging\* , aspectwerkz-2.0\src\samples\examples\proxy\tracing\*
aop.xml example:
<!-- the aspectwerkz.definition.file -->
<aspectwerkz>
<system id="aopRunttimeLoggerExample">
<package name="net.jakubholy.jeeutils.injectedlogger">
<aspect class="TracingAspect ">
<!-- Expression: any methods in the package including constructors and excluding the aspect class -->
<pointcut name="myPointcut" expression="( execution(* org.hibernate...*(..)) OR execution(org.hibernate.tool.hbm2x...new(..)) ) AND !within(net.jakubholy.jeeutils.injectedlogger.TracingAspect) AND !within(org.hibernate.tool.hbm2x.TemplateHelper) AND !within(org.hibernate.tool.hbm2x.AbstractExporter)"/>
<advice name="beforeMethod" type="before" bind-to="myPointcut"/>
<advice name="afterMethod" type="after" bind-to="myPointcut"/>
</aspect>
</package>
</system>
</aspectwerkz>
And now the tracing class itself:
package net.jakubholy.jeeutils.injectedlogger;
import java.util.Collection;
import java.util.Iterator;
import java.util.Map;
import org.apache.commons.beanutils.BeanUtils;
import org.codehaus.aspectwerkz.joinpoint.*;
/**
* AspectWerkz aspect adding tracing of parameters and return values to methods.
*
* <p>
* See aspectwerkz-2.0\src\samples\examples\proxy\tracing\TracingAspect.java -
* some very good ideas.
* </p>
*
* <p>
* In AspectWerkz definition file you should define this aspect like:
* </p>
* <pre><code>
* <package name="net.jakubholy.jeeutils.injectedlogger">
<aspect class="TracingAspect ">
<pointcut name="myPointcut" expression="execution(* net.jakubholy...*(..)) AND !within(net.jakubholy.jeeutils.injectedlogger.TracingAspect)"/>
<advice name="beforeMethod" type="before" bind-to="myPointcut"/>
<advice name="afterMethod" type="after" bind-to="myPointcut"/>
</aspect>
</package>
* </code></pre>
* <p>
* Replace 'net.jakubholy' in the execution with the package you want to
* enable tracing for. Examples:
* </p>
* <ul>
* <li>All subpackages of mypackage: <code>execution(* com.mycompany.mypackage...*(..)</code>
* <li>All methods in MyClass: <code>execution(* com.mycompany.mypackage.MyClass.*(..)</code>
* <li>All methods in MyClass: <code>execution(* ..MyClass.*(..)</code>
* <li>Only myMethod in MyClass: <code>execution(* com.mycompany.mypackage.MyClass.myMethod(..)</code>
* <li>Only public methods in mypackage: <code>execution(public * com.mycompany.mypackage...*(..)</code>
* <li>Constructors in mypackage and below: execution(com.mycompany.mypackage...new(..)) )
* </ul>
*
* TODO Add support for starting/stopping tracing when a configurable pattern (method+params+retval?) is encountered
*/
public class TracingAspect {
private boolean doTrace = false;
private void log(String logMsg) {
final String threadId = "thread #" +
Thread.currentThread().getId() + "(" + Thread.currentThread().getName() + ")";
// TODO use asynch. loggin e.g. via Log4J's asynch. appender
if (doTrace) System.err.println("[TracingAspect "+threadId+"] " + logMsg);
}
/**
* 'Advice' called before a method or constructor.
*/
public void beforeMethod(JoinPoint joinPoint) {
Rtti rtti = joinPoint.getRtti();
if (rtti instanceof MethodRtti) {
MethodRtti methodRtti = (MethodRtti) rtti;
if (!doTrace) {
doTrace = isStartTracingSignatureMatch(methodRtti);
log("INFO tracing enabled");
}
log("{BEFORE method " + methodRtti.getDeclaringType().getName() + "." + methodRtti.getName());
} else if (rtti instanceof ConstructorRtti) {
ConstructorRtti methodRtti = (ConstructorRtti) rtti;
log("{BEFORE constructor " + methodRtti.getName());
} else {
log("{ERROR: not a method! rtti=" + rtti);
}
}
/**
* 'Advice' called after a method or constructor.
*/
public void afterMethod(JoinPoint joinPoint) {
Rtti rtti = joinPoint.getRtti();
StringBuffer sb = new StringBuffer();
if (rtti instanceof MethodRtti) {
MethodRtti methodRtti = (MethodRtti) rtti;
Object[] params = methodRtti.getParameterValues();
Class[] ptypes = methodRtti.getParameterTypes();
boolean stopTracing = doTrace && isEndTracingSignatureMatch(methodRtti);
if (doTrace) {
sb.append(methodRtti.getDeclaringType().getName() + "." + methodRtti.getName() + "(");
// Describe parameters
for (int i = 0; i < params.length; i++) {
sb.append(ptypes[i].getName() + ": " + describe(params[i]))
.append((i+1 < params.length)? ", " : "");
}
// Describe output
Object output = methodRtti.getReturnValue();
sb.append("): ").append(methodRtti.getReturnType().getName()).append(": ")
.append(describe(output));
// Log
log("AFTER method " + sb + "}");
if (stopTracing) {
log("INFO: tracing disabled; method=" + methodRtti.getName());
doTrace = false;
}
}
} else if (rtti instanceof ConstructorRtti) {
ConstructorRtti methodRtti = (ConstructorRtti) rtti;
Object[] params = methodRtti.getParameterValues();
Class[] ptypes = methodRtti.getParameterTypes();
sb.append("constructor " + methodRtti.getName() + "(");
// Describe parameters
for (int i = 0; i < params.length; i++) {
sb.append(ptypes[i].getName() + ": " + describe(params[i]))
.append((i+1 < params.length)? ", " : "");
}
sb.append(")");
// Log
log("AFTER constructor " + sb + "}");
}
}
/**
* Return a string representation of the <var>target</var>
* containing its properties and their values.
* @param target
* @return
*/
private String describe(Object target) {
String result;
StringBuffer sb = new StringBuffer();
// SPECIAL: Hibernate & hbm2java generation
// When running hbm2java, avoid InvocationTargetException <- MappingException: entity class not found <- ClassNotFoundException
// for a class yet to generate
if (target != null && target.getClass().getName().startsWith("org.hibernate.mapping.")) {
return target.toString();
} // hibernate mapping
if (target == null) {
result = "null";
} else if (target.getClass().isArray()) {
// ARRAY
Object[] targetArray = (Object[]) target;
sb.append("#").append(targetArray.length).append("[");
for (int i = 0; i < targetArray.length; i++) {
sb.append(describe(targetArray[i]));
if (i < targetArray.length - 1) {
sb.append(", ");
}
}
sb.append("]");
result = sb.toString();
} else if (target instanceof Collection) {
Collection targetColl = (Collection) target;
sb.append("#").append(targetColl.size()).append("[");
for (Iterator iter = targetColl.iterator(); iter.hasNext();) {
Object element = (Object) iter.next();
sb.append(describe(element))
.append(iter.hasNext()? ", " : "");
}
sb.append("]");
result = sb.toString();
} else if (target instanceof String) {
result = "'" + target + "'";
} else if (target.getClass().getName().startsWith("java.lang.")) {
result = target.toString();
} else {
sb.append("{");
try {
final String separ = ", ";
Map props = BeanUtils.describe(target);
for (Iterator iter = props.entrySet().iterator(); iter.hasNext();) {
Map.Entry nameValue = (Map.Entry) iter.next();
if (!"class".equals(nameValue.getKey())) {
sb
.append(nameValue.getKey()).append('=')
.append(nameValue.getValue())
.append(separ);
}
} // for props
// remove trailing separator if present
if (separ.equals(sb.substring( Math.max(0, sb.length() - 2 )))) {
sb.delete(sb.length() - 2, sb.length());
}
} catch (Throwable e) {
// e.printStackTrace();
sb.append("Exception examining the object ")
.append(target)
.append(": ")
.append(e);
System.err.println(sb);
}
sb.append("}");
result = sb.toString();
} // switch
return result;
}
/**
* Does the current method being instrumented match the signature
* that should start tracing?
* @param methodRtti
* @return
*/
private boolean isStartTracingSignatureMatch(MethodRtti methodRtti) {
return true;
}
/**
* Does the current method being instrumented match the signature
* indicating we should stop tracing?
* @param methodRtti
* @return
*/
private boolean isEndTracingSignatureMatch(MethodRtti methodRtti) {
return false;// isStartTracingSignatureMatch(methodRtti);
}
}