apm-agent-java icon indicating copy to clipboard operation
apm-agent-java copied to clipboard

1.26.0 upgrade to 1.31.0 can't enhance class

Open LeePui opened this issue 3 years ago • 6 comments

Hi, when i upgrade elastic agent to 1.31.0, i can't found any transaction in kibana. i found some different log when i sent a http request to my app. in 1.31.0:

2022-09-24 17:33:37,430 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxStartAsyncInstrumentation: (not(isInterface()) and hasSuperType(erasure(name(equals(javax.servlet.ServletRequest))))) matches class io.undertow.servlet.spec.HttpServletRequestImpl
2022-09-24 17:33:37,430 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxRequestStreamRecordingInstrumentation: (hasSuperType(erasure(name(equals(javax.servlet.ServletRequest)))) and not(isInterface())) matches class io.undertow.servlet.spec.HttpServletRequestImpl
2022-09-24 17:33:37,521 [XNIO-1 task-1] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxFilterChainInstrumentation: (not(isInterface()) and hasSuperType(erasure(name(equals(javax.servlet.FilterChain))))) matches class io.undertow.servlet.handlers.FilterHandler$FilterChainImpl
2022-09-24 17:33:37,728 [XNIO-1 task-1] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxAsyncContextInstrumentation: (not(isInterface()) and hasSuperType(erasure(name(equals(javax.servlet.AsyncContext))))) matches class io.undertow.servlet.spec.AsyncContextImpl

in 1.26.0

2022-09-24 17:40:26,445 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxStartAsyncInstrumentation: (not(isInterface()) and hasSuperType(erasure(name(equals(javax.servlet.ServletRequest))))) matches class io.undertow.servlet.spec.HttpServletRequestImpl
2022-09-24 17:40:26,445 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxRequestStreamRecordingInstrumentation: (hasSuperType(erasure(name(equals(javax.servlet.ServletRequest)))) and not(isInterface())) matches class io.undertow.servlet.spec.HttpServletRequestImpl
2022-09-24 17:40:26,456 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation JavaxRequestStreamRecordingInstrumentation: (name(equals(getInputStream)) and returns(erasure(hasSuperType(erasure(name(equals(javax.servlet.ServletInputStream)))))) and not(isAbstract())) matches public javax.servlet.ServletInputStream io.undertow.servlet.spec.HttpServletRequestImpl.getInputStream() throws java.io.IOException
2022-09-24 17:40:26,457 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation JavaxStartAsyncInstrumentation: (isPublic() and name(equals(startAsync)) and returns(erasure(hasSuperType(erasure(name(equals(javax.servlet.AsyncContext)))))) and (hasParameter(ofSize(0)) or (hasParameter(hasTypes(with(0 matches erasure(name(equals(javax.servlet.ServletRequest)))))) and hasParameter(hasTypes(with(1 matches erasure(name(equals(javax.servlet.ServletResponse)))))))) and not(isAbstract())) matches public javax.servlet.AsyncContext io.undertow.servlet.spec.HttpServletRequestImpl.startAsync() throws java.lang.IllegalStateException
2022-09-24 17:40:26,458 [XNIO-1 I/O-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation JavaxStartAsyncInstrumentation: (isPublic() and name(equals(startAsync)) and returns(erasure(hasSuperType(erasure(name(equals(javax.servlet.AsyncContext)))))) and (hasParameter(ofSize(0)) or (hasParameter(hasTypes(with(0 matches erasure(name(equals(javax.servlet.ServletRequest)))))) and hasParameter(hasTypes(with(1 matches erasure(name(equals(javax.servlet.ServletResponse)))))))) and not(isAbstract())) matches public javax.servlet.AsyncContext io.undertow.servlet.spec.HttpServletRequestImpl.startAsync(javax.servlet.ServletRequest,javax.servlet.ServletResponse) throws java.lang.IllegalStateException
2022-09-24 17:40:26,492 [XNIO-1 task-1] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation JavaxFilterChainInstrumentation: (not(isInterface()) and hasSuperType(erasure(name(equals(javax.servlet.FilterChain))))) matches class io.undertow.servlet.handlers.FilterHandler$FilterChainImpl
2022-09-24 17:40:26,495 [XNIO-1 task-1] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation JavaxFilterChainInstrumentation: (name(equals(doFilter)) and hasParameter(hasTypes(with(0 matches erasure(name(equals(javax.servlet.ServletRequest)))))) and hasParameter(hasTypes(with(1 matches erasure(name(equals(javax.servlet.ServletResponse)))))) and not(isAbstract())) matches public void io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(javax.servlet.ServletRequest,javax.servlet.ServletResponse) throws java.io.IOException,javax.servlet.ServletException

when i debug apm , i found 1.31.0 will no step to co.elastic.apm.agent.bci.ElasticApmAgent#getTransformer, can you give me some suggestions to solve this problem?

LeePui avatar Sep 24 '22 10:09 LeePui

i found it can't be enhanced class since 1.27.0

LeePui avatar Sep 24 '22 10:09 LeePui

Which Jvm Version? JDK8 or JDK17? Is there any other agents go together with this apm agent?

zhangever avatar Sep 26 '22 07:09 zhangever

Hi @LeePui ,

Could you explain what framework/library are you using for handling the HTTP requests on your application ? It seems mosty servlet-based but we'd better check first to be sure.

The logs could be different, especially the ordering, thus looking for lines that contain Method match will provide you a list of all the methods that are actually instrumented by the agent, thus it would be easier to compare them between the two versions. If you can capture a complete log file for both versions using this procedure that would be helpful to investigate this further.

SylvainJuge avatar Sep 26 '22 08:09 SylvainJuge

Hi, @SylvainJuge , sorry, it took so long to reply. My application uses spring mvc. But we use two agent, the other agent is written by us and is used for business related logic. startup parameter like : java -javaagent:myAgent.jar -javaagent:elastic-apm-agent.jar -jar app.jar. Our agent structure is similar to skywalking, and the bytebuddy version is consistent with elastic APM.

Since elastic APM 1.27.0, i found the following exceptions during startup:

java.lang.AbstractMethodError
	at net.bytebuddy.asm.AsmVisitorWrapper$Compound.wrap(AsmVisitorWrapper.java:743)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ForInlining$WithFullProcessing$RedefinitionClassVisitor.visit(TypeWriter.java:4867)
	at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:569)
	at net.bytebuddy.jar.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ForInlining.create(TypeWriter.java:3918)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default.make(TypeWriter.java:2192)
	at net.bytebuddy.dynamic.scaffold.inline.RedefinitionDynamicTypeBuilder.make(RedefinitionDynamicTypeBuilder.java:224)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:11741)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11677)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1700(AgentBuilder.java:11395)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:12069)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:12016)
	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:11584)
	at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
	at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:144)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at net.bytebuddy.utility.Invoker$Dispatcher.invoke(Unknown Source)
	at net.bytebuddy.utility.dispatcher.JavaDispatcher$Dispatcher$ForNonStaticMethod.invoke(JavaDispatcher.java:1013)
	at net.bytebuddy.utility.dispatcher.JavaDispatcher$ProxiedInvocationHandler.invoke(JavaDispatcher.java:1142)
	at net.bytebuddy.agent.builder.$Proxy28.retransformClasses(Unknown Source)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Collector$ForRetransformation.doApply(AgentBuilder.java:7979)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Collector.apply(AgentBuilder.java:7794)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy.apply(AgentBuilder.java:5616)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.doInstall(AgentBuilder.java:10779)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.installOn(AgentBuilder.java:10687)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$Delegator.installOn(AgentBuilder.java:12417)
	at co.elastic.apm.agent.bci.ElasticApmAgent.initInstrumentation(ElasticApmAgent.java:251)
	at co.elastic.apm.agent.bci.ElasticApmAgent.initInstrumentation(ElasticApmAgent.java:136)
	at co.elastic.apm.agent.bci.ElasticApmAgent.initialize(ElasticApmAgent.java:122)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at co.elastic.apm.agent.premain.AgentMain.loadAndInitializeAgent(AgentMain.java:160)
	at co.elastic.apm.agent.premain.AgentMain.init(AgentMain.java:101)
	at co.elastic.apm.agent.premain.AgentMain.premain(AgentMain.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
	at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)

I unified the bytebuddy version of the two agents and still have this exception. if i delete this line of code, apm agent can be enhanced normally: co.elastic.apm.agent.bci.ElasticApmAgent#applyAdvice:

......
        return agentBuilder
            .type(instrumentationStats.shouldMeasureMatching() ? statsCollectingMatcher : matcher)
            .transform(new PatchBytecodeVersionTo51Transformer())
            .transform(getTransformer(instrumentation, logger, methodMatcher))
            .transform(new AgentBuilder.Transformer() {
                @Override
                public DynamicType.Builder<?> transform(DynamicType.Builder<?> builder, TypeDescription typeDescription,
                                                        ClassLoader classLoader, JavaModule module) {
                    return builder
// delete the line below
//                        .visit(MinimumClassFileVersionValidator.V1_4)
                        // As long as we allow 1.4 bytecode, we need to add this constant pool adjustment as well
                        .visit(TypeConstantAdjustment.INSTANCE);
                }
            });

LeePui avatar Oct 08 '22 09:10 LeePui

Hi @LeePui ,

It indeed looks like a dependency problem induced by your other agent.

In the agent version 1.27.0 we upgraded bytebuddy from version 1.11.22 to 1.12.1. Which bytebuddy version did you use in your custom agent?

JonasKunz avatar Oct 10 '22 14:10 JonasKunz

You problem might also be resolved by upgrading the elastic-agent to at least 1.34.0. This version contains a change (#2728) which should isolate the elastic agent from any dependencies your custom agent loads. In addition this should save you the overhead of always keeping the dependencies of both in sync.

JonasKunz avatar Oct 10 '22 14:10 JonasKunz

You problem might also be resolved by upgrading the elastic-agent to at least 1.34.0. This version contains a change (#2728) which should isolate the elastic agent from any dependencies your custom agent loads. In addition this should save you the overhead of always keeping the dependencies of both in sync.

Thanks for your reply. I will try the version 1.34.0

LeePui avatar Oct 17 '22 03:10 LeePui

Hi @LeePui did that resolve the issue?

jackshirazi avatar Nov 14 '22 15:11 jackshirazi

Hi @LeePui did that resolve the issue?

yes, thanks.

LeePui avatar Nov 15 '22 06:11 LeePui