Logback instrumentation doesn't get applied when mismatching slf4j version is used

[trask]

When using logback 1.2.3 with slf4j 1.7.3, the logback instrumentation fails to transform ch.qos.logback.classic.Logger because it cannot resolve org.slf4j.event.LoggingEvent which is a parameter of one of the ch.qos.logback.classic.Logger methods:

ch.qos.logback.classic.Logger.log(org.slf4j.event.LoggingEvent)

I was surprised by this since we don't transform that method, so it doesn't seem like our instrumentation should care that org.slf4j.event.LoggingEvent is not available.

Probably related to @laurit's #5724 (comment):

Byte-buddy locates bytes for all annotations on all methods if you have a matcher that matches based on annotation.

here's the DEBUG output from the failure to transform:

DEBUG i.o.j.t.AgentInstaller$TransformLoggingListener - Failed to handle ch.qos.logback.classic.Logger for transformation on classloader weblogic.utils.classloaders.GenericClassLoader@b1d60bf finder: weblogic.utils.classloaders.CodeGenClassFinder@7a883df7 annotation: 
net.bytebuddy.pool.TypePool$Resolution$NoSuchTypeException: Cannot resolve type description for org.slf4j.event.LoggingEvent
	at net.bytebuddy.pool.TypePool$Resolution$Illegal.resolve(TypePool.java:167)
	at io.opentelemetry.javaagent.tooling.muzzle.AgentCachingPoolStrategy$CachingResolution.resolve(AgentCachingPoolStrategy.java:262)
	at net.bytebuddy.pool.TypePool$Default$WithLazyResolution$LazyTypeDescription.delegate(TypePool.java:1088)
	at net.bytebuddy.description.type.TypeDescription$AbstractBase$OfSimpleType$WithDelegation.getModifiers(TypeDescription.java:8464)
	at net.bytebuddy.description.ModifierReviewable$AbstractBase.matchesMask(ModifierReviewable.java:618)
	at net.bytebuddy.description.ModifierReviewable$AbstractBase.isPublic(ModifierReviewable.java:336)
	at net.bytebuddy.description.type.TypeDescription$AbstractBase.isVisibleTo(TypeDescription.java:7921)
	at net.bytebuddy.matcher.VisibilityMatcher.doMatch(VisibilityMatcher.java:48)
	at net.bytebuddy.matcher.VisibilityMatcher.doMatch(VisibilityMatcher.java:27)
	at net.bytebuddy.matcher.ElementMatcher$Junction$ForNonNullValues.matches(ElementMatcher.java:249)
	at net.bytebuddy.matcher.NegatingMatcher.matches(NegatingMatcher.java:47)
	at net.bytebuddy.matcher.ErasureMatcher.doMatch(ErasureMatcher.java:50)
	at net.bytebuddy.matcher.ErasureMatcher.doMatch(ErasureMatcher.java:29)
	at net.bytebuddy.matcher.ElementMatcher$Junction$ForNonNullValues.matches(ElementMatcher.java:249)
	at net.bytebuddy.matcher.MethodParameterTypeMatcher.doMatch(MethodParameterTypeMatcher.java:48)
	at net.bytebuddy.matcher.MethodParameterTypeMatcher.doMatch(MethodParameterTypeMatcher.java:27)
	at net.bytebuddy.matcher.ElementMatcher$Junction$ForNonNullValues.matches(ElementMatcher.java:249)
	at net.bytebuddy.matcher.CollectionItemMatcher.doMatch(CollectionItemMatcher.java:48)
	at net.bytebuddy.matcher.CollectionItemMatcher.doMatch(CollectionItemMatcher.java:26)
	at net.bytebuddy.matcher.ElementMatcher$Junction$ForNonNullValues.matches(ElementMatcher.java:249)
	at net.bytebuddy.matcher.NegatingMatcher.matches(NegatingMatcher.java:47)
	at net.bytebuddy.matcher.MethodParametersMatcher.doMatch(MethodParametersMatcher.java:49)
	at net.bytebuddy.matcher.MethodParametersMatcher.doMatch(MethodParametersMatcher.java:28)
	at net.bytebuddy.matcher.ElementMatcher$Junction$ForNonNullValues.matches(ElementMatcher.java:249)
	at net.bytebuddy.matcher.ElementMatcher$Junction$Conjunction.matches(ElementMatcher.java:146)
	at net.bytebuddy.dynamic.scaffold.MethodRegistry$Default.prepare(MethodRegistry.java:482)
	at net.bytebuddy.dynamic.scaffold.inline.RedefinitionDynamicTypeBuilder.make(RedefinitionDynamicTypeBuilder.java:204)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:11757)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11692)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1700(AgentBuilder.java:11405)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:12092)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:12032)
	at java.security.AccessController.doPrivileged(Native Method)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doPrivileged(AgentBuilder.java)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11597)
	at sun.instrument.TransformerManager.transform(TransformerManager.java:188)

[laurit]

Apparently during transformation (matchers have passes at this point) byte-buddy performs some validation on the type. Here it tries to validate that all methods in the class have parameters and return type that are visible to the transformed class. See https://github.com/raphw/byte-buddy/blob/da140f71c2044ae70e98140c721e81a777a4b0fd/byte-buddy-dep/src/main/java/net/bytebuddy/dynamic/scaffold/MethodRegistry.java#L482 If it finds a method where parameters or return type isn't visible it generates some kind of bridge. As our transformations only change methods bodies this shouldn't be necessary. The only person who knows why exactly this is done and whether it is needed for our use case or whether this can be disabled is the author of byte-buddy.

[xiangtianyu]

The same issue for me, is there any solution?

[trask]

@xiangtianyu currently you will need to use matching logback and slf4j versions