Recording API Invocations for Debugging

Today I encountered a problem when using the Oracle JDBC API that only manifested itself in a certain complicated sequence of API invocations. I wanted to understand exactly what the sequence of API invocations was and also be able to extract them, so I could spit them out into a standalone test-case that I could use to debug the problem. Below is a class I whipped up to help automate most of this task.

So now I can do something like:

Invocations t = new Invocations();
PoolDataSource ods= t.trace(PoolDataSourceFactory.getPoolDataSource(),PoolDataSource.class);

ods.setConnectionFactoryClassName("oracle.jdbc.pool.OracleDataSource");
ods.setURL("jdbc:oracle:thin://localhost:1521/orcl");
ods.setUser("scott");
ods.setPassword("tiger");
Connection conn = ods.getConnection();
CallableStatement stmt = conn.prepareCall("begin dbms_output.put_line('Hello'); end;");
stmt.execute();
stmt.close();
conn.close();
System.out.print(t);

Which produces the following output:

oracle.ucp.jdbc.PoolDataSource v1;
v1.setConnectionFactoryClassName("oracle.jdbc.pool.OracleDataSource");
v1.setURL("jdbc:oracle:thin://localhost:1521/orcl");
v1.setUser("scott");
v1.setPassword("tiger");
java.sql.Connection v2;
v2 = v1.getConnection();
java.sql.CallableStatement v3;
v3 = v2.prepareCall("begin dbms_output.put_line('Hello'); end;");
boolean v4;
v4 = v3.execute();
v3.close();
v2.close();

Which is a pretty good facsimile of the original code. Note there are obviously limitations to what this kind of approach can achieve:

  • Invocations can only handle primitive values and values created within the API itself
  • Any non primitive values (including arrays) created outside of the API can only be declared, code to initialize these values will need to be added manually.

The major benefit of the generated code is that it does not have any dependencies other than the API being traced, thus making it easier to extract a stand-alone test case that exhibits the problem. This makes it easier to focus on the problem by eradicating superfluous code. It also very useful when you need a stand-alone test-case for a bug report for a third party API.

The Source Code

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;
import java.util.IdentityHashMap;

public class Invocations {

	@Override
	public String toString() {
		return b.toString();
	}
	public <T> T trace(final Object target, final Class<T> type) {
		return trace(target, type, false);
	}

	private void declare(final Object object, final Class<?> type,
			final boolean force) {
		if (!void.class.equals(type)) {
			if (force
					|| (object != null && !variables.containsKey(object) && !isPrimitive(type))) {
				b.append(typeName(type));
				b.append(" ");
				b.append(register(object));
				b.append(";\n");
			}
		}
	}
	private boolean isPrimitive(final Class<?> type) {
		boolean isPrimitive = type.isPrimitive();
		if (!isPrimitive) {
			for (final Class<?> c : PRIMITIVES) {
				if (c.equals(type)) {
					isPrimitive = true;
					break;
				}
			}
		}
		return isPrimitive;
	}
	private String name(final Object object) {
		String name = "null";
		if (object != null) {
			name = variables.get(object);
			if (name == null) {
				if (isPrimitive(object.getClass())) {
					return render(object);
				} else {
					throw new RuntimeException("Could not find name for: "
							+ object);
				}
			}
		}
		return name;
	}
	private String register(final Object object) {
		String name;
		name = variables.get(object);
		if (name == null) {
			name = "v" + (++var);
			variables.put(object, name);
		}
		return name;
	}
	private String render(final Object object) {
		final Class<?> type = object.getClass();
		if (String.class.equals(type)) {
			return "\"" + object.toString() + "\"";
		} else if (short.class.equals(type) || Short.class.equals(type)) {
			return "(short)" + object.toString();
		} else if (long.class.equals(type) || Long.class.equals(type)) {
			return object.toString() + "L";
		} else if (char.class.equals(type) || Character.class.equals(type)) {
			return "'" + object.toString() + "'";
		} else {
			return object.toString();
		}
	}
	@SuppressWarnings("unchecked")
	private <T> T trace(final Object target, final Class<T> type,
			final boolean force) {
		T result = null;
		if (target != null) {
			if (target.getClass().getInterfaces().length > 0
					&& !isPrimitive(target.getClass())) {
				result = type.cast(Proxy.newProxyInstance(Thread
						.currentThread().getContextClassLoader(), target
						.getClass().getInterfaces(), new Recorder(target)));
			} else {
				result = (T) target;
			}
		}
		declare(result, type, force);
		return result;
	}
	private String typeName(final Class<?> type) {
		if (type.isArray()) {
			return typeName(type.getComponentType()) + "[]";
		} else {
			return type.getName();
		}
	}

	private class Recorder implements InvocationHandler {

		Recorder(final Object target) {
			this.target = target;
		}

		public Object invoke(final Object proxy, final Method method,
				final Object[] args) throws Throwable {
			Object result = null;
			final Class<?> type = method.getReturnType();
			try {
				result = method.invoke(target, args);
			} catch (final InvocationTargetException e) {
				final Throwable t = e.getCause();
				for (final Class<?> ex : method.getExceptionTypes()) {
					if (ex.isAssignableFrom(t.getClass())) {
						throw t;
					}
				}
				throw e;
			}
			result = trace(result, type, true);
			record(result, proxy, method, args);
			return result;
		}

		private void record(final Object result, final Object proxy,
				final Method method, final Object[] args) {
			if (args != null) {
				final Class<?>[] types = method.getParameterTypes();
				for (int i = 0; i < args.length; ++i) {
					declare(args[i], types[i], false);
				}
			}
			if (result != null) {
				b.append(name(result));
				b.append(" = ");
			}
			b.append(name(proxy));
			b.append('.');
			b.append(method.getName());
			b.append('(');
			if (args != null) {
				for (int i = 0; i < args.length; ++i) {
					b.append(name(args[i]));
					if (i < args.length - 1) {
						b.append(',');
					}
				}
			}
			b.append(");\n");
		}

		private final Object target;

	};

	private final StringBuilder b = new StringBuilder();

	private int var = 0;

	private final IdentityHashMap<Object, String> variables = new IdentityHashMap<Object, String>();
	private static final Class<?>[] PRIMITIVES = { String.class, Integer.class,
			Boolean.class, Double.class, Long.class, Short.class, Byte.class,
			Character.class, Float.class };
}

I’ve only used this code with the specific problem I was facing, I’m sure there are issues with it, I haven’t tested it comprehensively, YMMV. For example I know it doesn’t handle arrays very well, particularly those with multiple dimensions.

Advertisements

2 thoughts on “Recording API Invocations for Debugging

  1. There are some problems with this code. To begin with it will not compile.

    1. The Invocations class seems to be parametrized but the T parameter is not defined at class or method level.

    2. The line result = type.cast(Proxy.newProxyInstance(Thread… does not seem to compile in JDK 6.

    3. The variables IdentityHashMap should be parametrized in order to have lines like variables.get(object) to compile. Unparametrized collections will return objects by default, not Strings.

    4. Objects as keys for HashMaps are not a good idea. Sure the hash code generated is going to be random enough but it is possible for them to collide and cause some havoc.

    5. I tried to set all the compile problems right and invoked the Invocations class with a Map to trace its calls and it failed with a class cast exception.

    Never the less your example shows that something like this is possible, since it worked for you. Please update the post if your code was misplaced.

    Have you tried a profiler like JProbe. If I am not mistaken this functionality would come out of the box with a product like that.

    Thanks for sharing.

    • @CertPal: Thanks for taking the time to take a look at the code, as you noticed, I managed to mangle the code somewhere along the way and the angle brackets got chewed. I’ve fixed the code now, and verified it compiles.

      Objects as keys for HashMaps are not a good idea. Sure the hash code generated is going to be random enough but it is possible for them to collide and cause some havoc.

      In this case I’m using an IdentityHashMap so the use of an Object as key is correct. IdentityHashMap compares object instances instead of object values (it uses ‘==’ instead of .equals()).

      Regards

Comments are closed.