byte-buddy icon indicating copy to clipboard operation
byte-buddy copied to clipboard

Published 20 hours ago • verified publisher icon raphw

Cannot write invoke dynamic instruction for class file version Java 6 (50)

Open KLYMPTZIC opened this issue 2 years ago • 7 comments

My Java agent is compiled using JDK 11.0.6. During instrumentation, observed the error below from the component where the agent is attached.

Components Java version is java-17-openjdk-17.0.1.0.12-2.portable.jdk.el.x86_64

Cannot write invoke dynamic instruction for class file version Java 6 (50)

java.lang.IllegalStateException: Cannot write invoke dynamic instruction for class file version Java 6 (50) at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ValidatingClassVisitor$Constraint$ForClassFileVersion.assertInvokeDynamic(TypeWriter.java:3532) at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ValidatingClassVisitor$Constraint$Compound.assertInvokeDynamic(TypeWriter.java:3720) at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ValidatingClassVisitor$ValidatingMethodVisitor.visitInvokeDynamicInsn(TypeWriter.java:3859) at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474) at net.bytebuddy.utility.visitor.StackAwareMethodVisitor.visitInvokeDynamicInsn(StackAwareMethodVisitor.java:378) at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474) at net.bytebuddy.utility.visitor.StackAwareMethodVisitor.visitInvokeDynamicInsn(StackAwareMethodVisitor.java:378) at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474) at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474) at net.bytebuddy.jar.asm.ClassReader.readCode(ClassReader.java:2474) at net.bytebuddy.jar.asm.ClassReader.readMethod(ClassReader.java:1514) at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:744) at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:424) at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$AdviceMethodInliner.apply(Advice.java:8457) at net.bytebuddy.asm.Advice$AdviceVisitor$WithExitAdvice.onUserEnd(Advice.java:10967) at net.bytebuddy.asm.Advice$AdviceVisitor.visitMaxs(Advice.java:10746) at net.bytebuddy.jar.asm.ClassReader.readCode(ClassReader.java:2665) at net.bytebuddy.jar.asm.ClassReader.readMethod(ClassReader.java:1514) at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:744) at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:424) at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ForInlining.create(TypeWriter.java:4014) at net.bytebuddy.dynamic.scaffold.TypeWriter$Default.make(TypeWriter.java:2224) at net.bytebuddy.dynamic.DynamicType$Builder$AbstractBase$UsingTypeWriter.make(DynamicType.java:4057) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:12201) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:12136) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1800(AgentBuilder.java:11845) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12623) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12555) at java.base/java.security.AccessController.doPrivileged(AccessController.java:399) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doPrivileged(AgentBuilder.java) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:12079) at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$ByteBuddy$ModuleSupport.transform(Unknown Source)

KLYMPTZIC avatar Aug 16 '23 05:08 KLYMPTZIC

It seems like you are creating a lambda expression which is added to a class file of version 6. invokedynamic instructions can only be added starting from class file version 7 and later.

raphw avatar Aug 16 '23 11:08 raphw

Verified the .java & .class files of the agent jar file and there is no usage of lambda expression. In Manifest file, I see that the build JDK is 11.0.6

KLYMPTZIC avatar Aug 17 '23 02:08 KLYMPTZIC

refer to this: PatchBytecodeVersionTo51Transformer

dogourd avatar Aug 17 '23 12:08 dogourd

It's about the class file version of the class, not the executing VM. The error comes from a mismatch.

raphw avatar Aug 30 '23 10:08 raphw

For reference, also started seeing a similar issue today:

[Byte Buddy] ERROR ch.qos.logback.classic.Logger [jdk.internal.loader.ClassLoaders$AppClassLoader@251a69d7, unnamed module @7eecb5b8, Thread[Test worker,5,main], loaded=true]
java.lang.IllegalStateException: Cannot write invoke dynamic instruction for class file version Java 6 (50)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ValidatingClassVisitor$Constraint$ForClassFileVersion.assertInvokeDynamic(TypeWriter.java:3532)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ValidatingClassVisitor$Constraint$Compound.assertInvokeDynamic(TypeWriter.java:3720)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ValidatingClassVisitor$ValidatingMethodVisitor.visitInvokeDynamicInsn(TypeWriter.java:3859)
	at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474)
	at net.bytebuddy.utility.visitor.StackAwareMethodVisitor.visitInvokeDynamicInsn(StackAwareMethodVisitor.java:378)
	at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474)
	at net.bytebuddy.utility.visitor.StackAwareMethodVisitor.visitInvokeDynamicInsn(StackAwareMethodVisitor.java:378)
	at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474)
	at net.bytebuddy.jar.asm.MethodVisitor.visitInvokeDynamicInsn(MethodVisitor.java:474)
	at net.bytebuddy.jar.asm.ClassReader.readCode(ClassReader.java:2475)
	at net.bytebuddy.jar.asm.ClassReader.readMethod(ClassReader.java:1514)
	at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:744)
	at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$AdviceMethodInliner.apply(Advice.java:9230)
	at net.bytebuddy.asm.Advice$AdviceVisitor$WithExitAdvice.onUserEnd(Advice.java:11780)
	at net.bytebuddy.asm.Advice$AdviceVisitor.visitMaxs(Advice.java:11559)
	at net.bytebuddy.jar.asm.ClassReader.readCode(ClassReader.java:2666)
	at net.bytebuddy.jar.asm.ClassReader.readMethod(ClassReader.java:1514)
	at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:744)
	at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ForInlining.create(TypeWriter.java:4014)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default.make(TypeWriter.java:2224)
	at net.bytebuddy.dynamic.DynamicType$Builder$AbstractBase$UsingTypeWriter.make(DynamicType.java:4062)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:12450)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:12385)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1800(AgentBuilder.java:12094)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12872)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12804)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:399)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doPrivileged(AgentBuilder.java)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:12328)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$ByteBuddy$ModuleSupport.transform(Unknown Source)
	at java.instrument/sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at java.instrument/sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:541)
	at java.instrument/sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at java.instrument/sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:169)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at net.bytebuddy.utility.Invoker$Dispatcher.invoke(Unknown Source)
	at net.bytebuddy.utility.dispatcher.JavaDispatcher$Dispatcher$ForNonStaticMethod.invoke(JavaDispatcher.java:1032)
	at net.bytebuddy.utility.dispatcher.JavaDispatcher$ProxiedInvocationHandler.invoke(JavaDispatcher.java:1162)
	at net.bytebuddy.agent.builder.$Proxy52.retransformClasses(Unknown Source)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Collector$ForRetransformation.doApply(AgentBuilder.java:8336)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Collector.apply(AgentBuilder.java:8151)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy.apply(AgentBuilder.java:5848)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.doInstall(AgentBuilder.java:11462)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.installOn(AgentBuilder.java:11362)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.installOnByteBuddyAgent(AgentBuilder.java:11369)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$Delegator.installOnByteBuddyAgent(AgentBuilder.java:13161)
	at hbx.config.root.GrpcClientLoggingTestExecutionListener.addCallAppendersOverride(GrpcClientLoggingTestExecutionListener.java:54)
	at hbx.config.root.GrpcClientLoggingTestExecutionListener.testPlanExecutionStarted(GrpcClientLoggingTestExecutionListener.java:34)
	at org.junit.platform.launcher.core.CompositeTestExecutionListener.lambda$testPlanExecutionStarted$12(CompositeTestExecutionListener.java:80)
	at org.junit.platform.launcher.core.CompositeTestExecutionListener.lambda$notifyEach$19(CompositeTestExecutionListener.java:102)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at org.junit.platform.launcher.core.IterationOrder$1.forEach(IterationOrder.java:23)
	at org.junit.platform.launcher.core.CompositeTestExecutionListener.notifyEach(CompositeTestExecutionListener.java:100)
	at org.junit.platform.launcher.core.CompositeTestExecutionListener.testPlanExecutionStarted(CompositeTestExecutionListener.java:79)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:58)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:141)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:57)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:103)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:85)
	at org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.processAllTestClasses(JUnitPlatformTestClassProcessor.java:118)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.access$000(JUnitPlatformTestClassProcessor.java:93)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor.stop(JUnitPlatformTestClassProcessor.java:88)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:62)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
	at jdk.proxy2/jdk.proxy2.$Proxy5.stop(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker$3.run(TestWorker.java:193)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.executeAndMaintainThreadName(TestWorker.java:129)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:100)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:60)
	at org.gradle.process.internal.worker.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:56)
	at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:113)
	at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:65)
	at worker.org.gradle.process.internal.worker.GradleWorkerMain.run(GradleWorkerMain.java:69)
	at worker.org.gradle.process.internal.worker.GradleWorkerMain.main(GradleWorkerMain.java:74)

I guess it's because the ch.qos.logback.classic.Logger class is compiled with Java 6? The weird thing is that this has been working until now though. :thinking: But probably something in my app has changed to trigger this now...

perlun avatar Oct 26 '23 13:10 perlun

@raphw, maybe you have any ideas... We have started seeing this consistently after moving from using "normal" Gradle test targets to using Gradle test suites (https://docs.gradle.org/current/userguide/jvm_test_suite_plugin.html).

Previously, the rewriting would output something like this; it worked perfectly, AFAIK.

Gradle Test Executor 9 STANDARD_ERROR [Byte Buddy] TRANSFORM ch.qos.logback.classic.Logger [jdk.internal.loader.ClassLoaders$AppClassLoader@251a69d7, unnamed module @69504ae9, Thread[Test worker,5,main], loaded=true]

The Byte Buddy and Logback versions are the same before and after the Gradle test-related changes. Byte Buddy is 1.14.8. I unpacked the Logback .jar and checked, and tmp/ch/qos/logback/classic/Logger.class is really a Java 6 bytecode file... so I presume Byte Buddy must have used something else than invokedynamic previously or something. :thinking:

The actual JUnit TestExecutionListener doesn't do anything particularly odd in this case. Including its complete code here:

import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.none;

import org.junit.platform.launcher.TestExecutionListener;
import org.junit.platform.launcher.TestPlan;

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;

import net.bytebuddy.agent.ByteBuddyAgent;
import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.implementation.bytecode.Removal;
import net.bytebuddy.implementation.bytecode.assign.Assigner;

/**
 * Test which ensures that no `GrpcClient`-related messages are logged when integration tests are
 * executed.
 *
 * Uses Byte Buddy to inject custom code into Logback's {@link
 * ch.qos.logback.classic.Logger#callAppenders(ILoggingEvent)} method.
 *
 * @author Per Lundberg
 */
public class GrpcClientLoggingTestExecutionListener implements TestExecutionListener {

    @Override
    public void testPlanExecutionStarted( TestPlan testPlan ) {
        ByteBuddyAgent.install();

        addCallAppendersOverride();
    }

    private void addCallAppendersOverride() {
        // Add an Advice to the Logger.callAppenders() method, to be able to inject custom logic to
        // it which is only applied when integration tests are executed.
        new AgentBuilder.Default()
                .disableClassFormatChanges()
                .with( AgentBuilder.RedefinitionStrategy.RETRANSFORMATION )
                .with( AgentBuilder.RedefinitionStrategy.DiscoveryStrategy.Reiterating.INSTANCE )
                .with( AgentBuilder.Listener.StreamWriting.toSystemError().withTransformationsOnly() )
                .ignore( none() )
                .type( named( Logger.class.getName() ) )
                .transform( new AgentBuilder.Transformer.ForAdvice()
                        .with( AgentBuilder.LocationStrategy.ForClassLoader.STRONG )
                        .include( LoggerCallAppendersAdvice.class.getClassLoader() )
                        .with( Assigner.DEFAULT )
                        .withExceptionHandler( new Advice.ExceptionHandler.Simple( Removal.SINGLE ) )
                        .advice( named( "callAppenders" ), LoggerCallAppendersAdvice.class.getName() )
                )
                .installOnByteBuddyAgent();
    }


    // Note: This class must be public to avoid java.lang.IllegalAccessError, because of
    // ByteBuddy-rewriting of class files.
    public static class LoggerCallAppendersAdvice {

        @Advice.OnMethodExit
        private static synchronized void exit( @Advice.Argument( 0 ) ILoggingEvent event ) {
            if ( event.getLoggerName().contains( "GrpcClient" ) ) {
                throw new RuntimeException( "GrpcClient log message not expected. Message was: " + event.getFormattedMessage() );
            }
        }
    }
}

perlun avatar Oct 27 '23 08:10 perlun

We found this now, posting it here in case it helps someone else.

It turns out that if the GrpcClientLoggingTestExecutionListener is compiled with a "too modern" Java version (Java 17 in our case), it doesn't work; Byte Buddy is unable to weave in the updated method definition into the original class. Probably because javac uses Invoke Dynamic instructions in the compiled code in the Java 17 case, but not when targeting the older (Java 8 in our case) version. :thinking:

(JDK 17 was being used in both cases, it was just the Gradle sourceCompatibility and targetCompatibility which was different)

perlun avatar Oct 27 '23 11:10 perlun