Using Javassist to log method calls and argument v

Question

The tool (in this repo) comprises 3 classes (given below). The problem is how to make my ParaTracer.Logger class visible in every class I instrument (such as java.util.Random shown below). The statement cp.importPackage( "ParaTracer.Logger"); doesn't seem to work and I am getting this error:

java.lang.NoClassDefFoundError: ParaTracer/Logger at java.util.Random.nextLong(Random.java)

I tried dynamically loading the Logger class inside every instrumented class. But it seems I was using Class.getMethod() incorrectly, or the Javassist compiler is too primitive to compile dynamic class-loading code. I get this error:

javassist.CannotCompileException: [source error] getMethod(java.lang.String,java.lang.Class,java.lang.Class) not found in java.lang.Class

The following 3 classes are exported into a JAR file with MANIFEST.MF file defining the Premain-Class and is passed to the JVM when running any instrumented program using the switch:

-javaagent:/Path/To/ParaTracerAgent.jar

Here are the 3 classes.

package ParaTracer;

import java.lang.instrument.Instrumentation;

import javassist.CannotCompileException;
import javassist.ClassPool;
import javassist.CtClass;
import javassist.CtField;
import javassist.CtNewConstructor;
import javassist.CtNewMethod;

public class ParaTracer {

    private static volatile Instrumentation instr;

    public static void premain(String agentArgs, Instrumentation inst) {
        instr = inst;
        SimpleClassTransformer transformer = new SimpleClassTransformer();
        inst.addTransformer( transformer, false );
    }
}

The transformer class:

package ParaTracer;

import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.security.ProtectionDomain;
import java.util.HashMap;
import java.util.HashSet;

import javassist.ClassPool;
import javassist.CtClass;
import javassist.CtMethod;


public class SimpleClassTransformer implements ClassFileTransformer {

    public HashMap< String, HashSet< String > > mInstrumentedMethods;

    public SimpleClassTransformer() {
        mInstrumentedMethods = new HashMap< String, HashSet< String > >();

        mInstrumentedMethods.put( "java.util.Random", new HashSet< String >() );
        mInstrumentedMethods.get( "java.util.Random").add( "nextLong" );
    }

    @Override
    public byte[] transform(
        ClassLoader       loader,
        String            className,
        Class<?>          classBeingRedefined,
        ProtectionDomain  protectionDomain,
        byte[]            classfileBuffer) throws IllegalClassFormatException {

        System.err.println( "---- Instrumenting: " + className );

        byte[] byteCode = classfileBuffer;

        String normalizedClassName = className.replaceAll("/", ".");

        if ( mInstrumentedMethods.containsKey( normalizedClassName ) ) {
            try {
                ClassPool cp = ClassPool.getDefault();

                cp.importPackage( "ParaTracer.Logger");

                CtClass cc = cp.get( normalizedClassName );

                for( String method : mInstrumentedMethods.get( normalizedClassName ) ) {
                    CtMethod  m  = cc.getDeclaredMethod( method );

                    StringBuilder sbs = new StringBuilder();
                    sbs.append( "long tid = Thread.currentThread().getId();" );
                    sbs.append( "StringBuilder sbArgs = new StringBuilder();" );
                    sbs.append( "sbArgs.append( System.identityHashCode( $0 ) );" );
                    CtClass[] pTypes = m.getParameterTypes();
                    for( int i=0; i < pTypes.length; ++i ) {
                        CtClass pType = pTypes[i];
                        if ( pType.isPrimitive() ) {
                            sbs.append( "sbArgs.append( \", \" + $args[" + i + "] );" );
                        } else {
                            sbs.append( "sbArgs.append( \", \" + System.identityHashCode( $args[" + i + "] ) );" );
                        }
                    }
                    sbs.append( "ParaTracer.Logger.pushArgs( tid, sbArgs.toString() );" );
                    sbs.append( "StringBuilder sb = new StringBuilder();" );
                    sbs.append( "sb.append( tid + \" : " + m.getLongName() + ".<START>(\" );" );
                    sbs.append( "sb.append( sbArgs.toString() );" );
                    sbs.append( "sb.append( \")\" );" );
                    sbs.append( "ParaTracer.Logger.print( sb.toString() );" );

                    m.insertBefore("{" + sbs.toString() + "}");

                    StringBuilder sbe = new StringBuilder();
                    sbe.append( "long tid = Thread.currentThread().getId();" );
                    sbe.append( "String args = ParaTracer.Logger.popArgs( tid );" );
                    sbe.append( "StringBuilder sb = new StringBuilder();" );
                    sbe.append( "sb.append( tid + \" : " + m.getLongName() + ".<END>(\" );" );
                    sbe.append( "sb.append( args );" );
                    sbe.append( "sb.append( \")\" );" );
                    sbe.append( "ParaTracer.Logger.print( sb.toString() );" );

                    m.insertAfter("{" + sbe.toString() + "}");
                }
                byteCode = cc.toBytecode();
                cc.detach();
            } catch (Exception ex) {
                ex.printStackTrace();
            }
        }
        return byteCode;
    }
}

The thread-safe logger class is given by:

package ParaTracer;

import java.io.FileWriter;
import java.io.IOException;
import java.io.PrintWriter;
import java.util.HashMap;
import java.util.Stack;

public class Logger {

    private static String loggerFilePath = "\"/some/fixed/path\"";
    private static FileWriter   fw;
    private static PrintWriter  out;
    private static HashMap< Long, Stack<String> > callStacks;

    public static synchronized void pushArgs( long tid, String args ) {
        try {
            init();
        } catch (IOException e) {
            e.printStackTrace();
        }
        if ( ! callStacks.containsKey( tid ) ) {
            callStacks.put( tid, new Stack<String>() );
        }
        callStacks.get( tid ).push( args );
    }

    public static synchronized String popArgs( long tid ) {
        assert( callStacks.containsKey( tid ) );
        assert( ! callStacks.get( tid ).empty() );
        return callStacks.get( tid ).pop();
    }

    public static synchronized void shutdown() {
        if ( fw == null ) return;
        try {
            fw.close();
        } catch (IOException e) {
            e.printStackTrace();
        }
    }

    public static synchronized void print( String str ) {
        try {
            init();
        } catch (IOException e) {
            e.printStackTrace();
        }
        out.print( str );
    }

    private static void init() throws IOException {
        if ( fw != null ) return;
        fw  = new FileWriter( loggerFilePath );
        out = new PrintWriter( fw );
        callStacks = new HashMap< Long, Stack<String> >();
    }
}

Answer 1

According to the documentation for Java agents the agent class is loaded by the system classloader. But if you want to instrument core Java classes and refer from those to a custom class of your own then that class would need to be available to the bootstrap classloader rather than the system one.

Move your Logger class into a separate JAR file, and list that file in the Boot-Class-Path attribute of the agent JAR's manifest:

Boot-Class-Path: ParaTracerLogger.jar

Now the logger class is visible on the bootstrap loader and can be seen by the instrumented java.lang classes.

Answer 2

I ended up having the ClassFileTransformer.tranform method as follows:

Basically, the code inserted by Javassist reopens the same log file every time there is a message to be written out and appends that message to the output file. Having a separate log file was important because redirecting standard output/error will result in contaminated log files if those streams are already used by the instrumented application (as is usually the case).

@Override
public byte[] transform(
        ClassLoader       loader,
        String            className,
        Class<?>          classBeingRedefined,
        ProtectionDomain  protectionDomain,
        byte[]            classfileBuffer)
                throws IllegalClassFormatException {

    byte[] byteCode = classfileBuffer;

    String normalizedClassName = className.replaceAll("/", ".");
    System.out.println( "\tNormalized: " + normalizedClassName );

    ClassMonitorSet classMonitorSet = monitorClass( normalizedClassName );
    if ( classMonitorSet != null ) {
        System.out.println( "\tMonitoring: " + normalizedClassName );
        try {
            ClassPool cp = ClassPool.getDefault();
            CtClass cc = cp.get( normalizedClassName );

            for( String methodName : classMonitorSet.monitorSet ) {
                CtMethod[]  methods  = cc.getDeclaredMethods( methodName );
                for( CtMethod method : methods ) {

                    StringBuilder sbs = new StringBuilder();
                    sbs.append( "long tid = Thread.currentThread().getId();" );
                    sbs.append( "StringBuilder sbArgs = new StringBuilder();" );
                    sbs.append( "sbArgs.append( System.identityHashCode( $0 ) );" );
                    CtClass[] pTypes = method.getParameterTypes();
                    for( int i=0; i < pTypes.length; ++i ) {
                        CtClass pType = pTypes[i];
                        if ( pType.isPrimitive() ) {
                            sbs.append( "sbArgs.append( \", \" + $args[" + i + "] );" );
                        } else {
                            sbs.append( "sbArgs.append( \", \" + System.identityHashCode( $args[" + i + "] ) );" );
                        }
                    }
                    sbs.append( "StringBuilder sb = new StringBuilder();" );
                    sbs.append( "sb.append( tid + \" : " + method.getLongName() + ".<START>(\" );" );
                    sbs.append( "sb.append( sbArgs.toString() );" );
                    sbs.append( "sb.append( \")\" );" );
                    sbs.append( "String fPath = \"/path/to/log.out\";" );
                    sbs.append( "try {" );
                    sbs.append( "   java.io.FileWriter  fw  = new java.io.FileWriter( fPath, true );" );
                    sbs.append( "   java.io.PrintWriter out = new java.io.PrintWriter( fw, true );" );
                    sbs.append( "   out.println( sb.toString() );" );
                    sbs.append( "   fw.close();" );
                    sbs.append( "} catch (java.io.IOException e) {" );
                    sbs.append( "   e.printStackTrace();" );
                    sbs.append( "}" );

                    method.insertBefore("{" + sbs.toString() + "}");

                    StringBuilder sbe = new StringBuilder();
                    sbe.append( "long tid = Thread.currentThread().getId();" );
                    sbe.append( "StringBuilder sb = new StringBuilder();" );
                    sbe.append( "sb.append( tid + \" : " + method.getLongName() + ".<END>(*)\" );" );
                    sbe.append( "String fPath = \"/path/to/log.out\";" );
                    sbe.append( "try {" );
                    sbe.append( "   java.io.FileWriter  fw  = new java.io.FileWriter( fPath, true );" );
                    sbe.append( "   java.io.PrintWriter out = new java.io.PrintWriter( fw, true );" );
                    sbe.append( "   out.println( sb.toString() );" );
                    sbe.append( "   fw.close();" );
                    sbe.append( "} catch (java.io.IOException e) {" );
                    sbe.append( "   e.printStackTrace();" );
                    sbe.append( "}" );

                    method.insertAfter("{" + sbe.toString() + "}");
                }
            }
            byteCode = cc.toBytecode();
            cc.detach();
        } catch (Exception ex) {
            ex.printStackTrace();
        }
    }
    return byteCode;
}