java.lang.NoSuchMethodError when using the agent for method instrumentation

[kavehshahedi]

Hello,

As shown in the following code, I have created an agent in order to instrument the methods of a project with a specific class name and capture their execution times:

import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.implementation.MethodDelegation;
import net.bytebuddy.implementation.bind.annotation.Origin;
import net.bytebuddy.implementation.bind.annotation.RuntimeType;
import net.bytebuddy.implementation.bind.annotation.SuperCall;
import net.bytebuddy.matcher.ElementMatchers;

import java.io.BufferedWriter;
import java.io.FileWriter;
import java.io.IOException;
import java.io.Writer;
import java.lang.instrument.Instrumentation;
import java.lang.reflect.Method;
import java.util.Arrays;
import java.util.concurrent.Callable;
import java.util.concurrent.CompletableFuture;

public class FunctionEntryAgent {

    public static void premain(String args, Instrumentation inst) {
        new AgentBuilder.Default()
                .type(ElementMatchers.nameContains("org.HdrHistogram"))
                .transform(
                        (builder, type, classLoader, module, protectionDomain) -> 
                        builder.method(ElementMatchers.any())
                                .intercept(MethodDelegation.to(MethodExecutionTime.class)))
                .installOn(inst);
    }

    public static class MethodExecutionTime {
        private static final String LOG_FILE = "method_logs.log";

        @RuntimeType
        public static Object intercept(@Origin Method method, @SuperCall Callable<?> callable) throws Exception{
            long start = System.nanoTime();
            try {
                return callable.call();
            } finally {
                String message = "[" + (System.nanoTime() - start) + "] "
                        + method.getDeclaringClass().getName() + "." + method.getName() + " "
                        + "(" + Arrays.toString(method.getParameterTypes()) + ") "
                        + method.getReturnType().getName();

                CompletableFuture.runAsync(() -> logMethodExecutionTime(message));
            }
        }

        private static void logMethodExecutionTime(String message) {
            try (Writer writer = new BufferedWriter(new FileWriter(LOG_FILE, true))) {
                writer.write(message + "\n");
            } catch (IOException e) {
                e.printStackTrace();
            }
        }
    }
}

The agent works in most cases, but in some projects, it throws java.lang.NoSuchMethodError error during the execution. For instance, the following error comes from this line of the code return callable.call();:

java.lang.NoSuchMethodError: 'boolean org.HdrHistogram.RecordedValuesIterator.hasNext$original$NZclujSK()'

Based on one of the suggestions in this this issue, I formatted the code in way that it uses Advice instead of MethodDelegation, as follows:

import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.matcher.ElementMatchers;

import java.io.BufferedWriter;
import java.io.FileWriter;
import java.io.IOException;
import java.io.Writer;
import java.lang.instrument.Instrumentation;
import java.lang.reflect.Method;
import java.util.Arrays;
import java.util.concurrent.CompletableFuture;
import java.util.function.Supplier;

public class FunctionEntryAgent {

    public static void premain(String args, Instrumentation inst) {
        new AgentBuilder.Default()
                .type(ElementMatchers.nameStartsWith("org.HdrHistogram"))
                .transform(new AgentBuilder.Transformer.ForAdvice()
                        .advice(ElementMatchers.isMethod(),
                                MethodExecutionTime.class.getName()))
                .installOn(inst);
    }

    public static class MethodExecutionTime {
        private static final String LOG_FILE = "method_logs.log";

        @Advice.OnMethodEnter
        static long enter(@Advice.Origin Method method) {
            return System.nanoTime();
        }

        @Advice.OnMethodExit
        static void exit(@Advice.Origin Method method, @Advice.Enter long start) {
            long duration = System.nanoTime() - start;
            String message = "[" + duration + "] "
                    + method.getDeclaringClass().getName() + "." + method.getName() + " "
                    + "(" + Arrays.toString(method.getParameterTypes()) + ") "
                    + method.getReturnType().getName();

            CompletableFuture.supplyAsync(new LoggerSupplier(message));
        }

        public static class LoggerSupplier implements Supplier<Void> {
            private final String message;

            public LoggerSupplier(String message) {
                this.message = message;
            }

            @Override
            public Void get() {
                try (Writer writer = new BufferedWriter(new FileWriter(LOG_FILE, true))) {
                    writer.write(message + "\n");
                } catch (IOException e) {
                    e.printStackTrace();
                }

                return null;
            }
        }
    }
}

These modifications fix the error, but the other problem is that the agent is not able to instrument all the classes and subclasses under the target package name. For instance, the agent attaches to a jar, which is a JMH benchmark that is benchmarking a baseline project (both of them have the same package names). The agent instruments the methods within the jmh project correctly (i.e., methods that are targeting the baseline project), but it can't capture the methods from the baseline project. However, when using MethodDelegation instead of Advice, the agent instruments all the methods (but as said, it throws the mentioned error).

I would be glad if you could inform me how to overcome this issue. Thanks!

[raphw]

This does not quite make sense to me. Could you investigate how the methods get instrumented? Register an AgentBuilder.Listener, possibly some of the instrumentations are failing

[kavehshahedi]

Thanks for the suggestion. After attaching a listener to the agent, this error popped up: Cannot write invoke dynamic instruction for class file version Java 6 (50)

As I investigated the previous issues, it turned out that the lambda dynamic invocation was causing the problem. I re-compiled the agent with Java 7, and the problem seems to be fixed.

Thanks again!