APM java agent ver 1.20.0 - no such method issue

Elastic Observability APM
1

Hi,
We have the problem with latest version of APM Java agent ver 1.20.0 which is also registered in ver 1.18

ERROR:

INFO   | jvm 5    | 2021/01/15 11:51:45 | 11:51:45.428 [AD Agent init] ERROR co.elastic.apm.agent.bci.IndyBootstrap - no such method: co.elastic.apm.agent.httpclient.ApacheHttpClientInstrumentation$ApacheHttpClientAdvice.onBeforeExecute(HttpRoute,HttpRequestWrapper)Object/invokeStatic
INFO   | jvm 5    | 2021/01/15 11:51:45 | java.lang.IllegalAccessException: no such method: co.elastic.apm.agent.httpclient.ApacheHttpClientInstrumentation$ApacheHttpClientAdvice.onBeforeExecute(HttpRoute,HttpRequestWrapper)Object/invokeStatic
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MemberName.makeAccessException(MemberName.java:867) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1003) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MethodHandles$Lookup.resolveOrFail(MethodHandles.java:1386) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MethodHandles$Lookup.findStatic(MethodHandles.java:780) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at co.elastic.apm.agent.bci.IndyBootstrap.bootstrap(IndyBootstrap.java:329) [?:?]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source) ~[?:?]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.IndyBootstrapDispatcher.bootstrap(IndyBootstrapDispatcher.java:31) [?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.CallSite.makeSite(CallSite.java:310) [?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MethodHandleNatives.linkCallSiteImpl(MethodHandleNatives.java:307) [?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MethodHandleNatives.linkCallSite(MethodHandleNatives.java:297) [?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:96) [httpclient-4.5.12.jar:4.5.12]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) [httpclient-4.5.12.jar:4.5.12]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72) [httpclient-4.5.12.jar:4.5.12]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.util.httpclient.SimpleHttpClientWrapper.executeHttpOperation(SimpleHttpClientWrapper.java:282) [appagent.jar:?]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.util.httpclient.SimpleHttpClientWrapper.executeHttpOperation(SimpleHttpClientWrapper.java:197) [appagent.jar:?]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.rest.RESTRequest.sendRequestTracked(RESTRequest.java:384) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.rest.RESTRequest.sendRequest(RESTRequest.java:337) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.rest.controller.request.AControllerRequest.sendRequest(AControllerRequest.java:130) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.rest.controller.request.ABinaryControllerRequest.sendRequest(ABinaryControllerRequest.java:36) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.config.xml.ConfigurationChannel.registerApplicationServer(ConfigurationChannel.java:1412) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.config.xml.ConfigurationChannel.access$100(ConfigurationChannel.java:120) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.config.xml.ConfigurationChannel$UnregisteredConfigurationState.nextTransition(ConfigurationChannel.java:764) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.config.xml.ConfigurationChannel.refreshConfiguration(ConfigurationChannel.java:534) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.config.xml.XMLConfigManager$AgentConfigurationRefreshTask.run(XMLConfigManager.java:631) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.config.xml.XMLConfigManager.initialize(XMLConfigManager.java:308) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.AgentKernel.start(AgentKernel.java:160) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.JavaAgent.initialize(JavaAgent.java:588) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.kernel.JavaAgent.initialize(JavaAgent.java:347) [appagent.jar:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at com.singularity.ee.agent.appagent.AgentEntryPoint$1.run(AgentEntryPoint.java:637) [?:Server Agent #20.6.0.30246 v20.6.0 GA compatible with 4.4.1.0 r6b0f05b34dd990b8006acb06d3820d0b2cb31f7f master]
INFO   | jvm 5    | 2021/01/15 11:51:45 | Caused by: java.lang.LinkageError: bad method type alias: (HttpRoute,HttpRequestWrapper)Object not visible from class co.elastic.apm.agent.httpclient.ApacheHttpClientInstrumentation$ApacheHttpClientAdvice
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MemberName.checkForTypeAlias(MemberName.java:793) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MemberName$Factory.resolve(MemberName.java:976) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       at java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1000) ~[?:1.8.0_212]
INFO   | jvm 5    | 2021/01/15 11:51:45 |       ... 33 more

what do we need to do on our side?
ver 1.17 works fine

thanks
tomislav

2

Hi @tmihaldinec,

We changed how plugin delegation works in version 1.18.0, which explains why it did not happen with previous versions.

As you also get the Caused by: java.lang.LinkageError: bad method type alias in the stack trace, it's clearly the same symptom as in the linked discussion, and should be fixed in 1.20.0.

It seems that the exception is related to AppDynamics agent with the com.singularity package, do you also get the exception when AD agent is removed ?

3

Hi,

yes

INFO | jvm 5 | 2021/01/15 11:51:45 | Caused by: java.lang.LinkageError: bad method type alias: (HttpRoute,HttpRequestWrapper)Object not visible from class co.elastic.apm.agent.httpclient.ApacheHttpClientInstrumentation$ApacheHttpClientAdvice
INFO | jvm 5 | 2021/01/15 11:51:45 | at java.lang.invoke.MemberName.checkForTypeAlias(MemberName.java:793) ~[?:1.8.0_212]
INFO | jvm 5 | 2021/01/15 11:51:45 | at java.lang.invoke.MemberName$Factory.resolve(MemberName.java:976) ~[?:1.8.0_212]
INFO | jvm 5 | 2021/01/15 11:51:45 | at java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1000) ~[?:1.8.0_212]
INFO | jvm 5 | 2021/01/15 11:51:45 | ... 33 more

i was not removing AD agent and i am not even sure i can.. we are using both systems

tomislav

4

Sorry, I read your message a bit fast, I've edited my response above.

I will check what could be wrong here and if a similar fix could be applied.

5

Many thanks @Sylvain_Juge

tomislav

6

In the mean time, could you try without the AD agent to see if that makes a difference ?

Running with more than one APM agent is definitely not recommended and might trigger unpredictable results due to having classes instrumented by more than one agent.

Also, does the issue happens when hot re-deploying the application or also when restarting the whole JVM ?

7

because of type of application we are not doing hot deployments but full deploy/restart

let me try and will get back to you
basically we are using both systems but for pretty different reasons

tomislav

8

I can confirm that this error doen't show with AD disabled

9

As we're catching the Exception in our agent and just log it, I think there's no impact of it besides that we won't trace requests that the AppD agent does to their backend. But I don't think it's an issue and you can probably safely ignore it.
Did you see any effect of this other than that the exception is being logged?

[internal note]
The following is just speculation but what might be going on is that AppD runs a part of their agent (com.singularity.ee.agent.appagent.AgentEntryPoint$1.run) in a separate class loader where the lookup of some types does not work as expected. If we could identify the class loader where com.singularity.ee.agent.appagent.AgentEntryPoint is loaded from, we might be able to exclude all classes loaded by that CL in our agent setup.

To find out what the classloader is we could log lookup.lookupClass().getClassLoader() in the catch block of co.elastic.apm.agent.bci.IndyBootstrap#bootstrap. Maybe it's class name starts with com.singularity. which would make it easy to skip by adding an exclude matcher in co.elastic.apm.agent.bci.ElasticApmAgent#getAgentBuilder.

10

Thanks for your response

yes, to be honest both AD and Elastic APM are OK and working.. problem is Tanuki java wrapper which kills JVM because startup time is 3x longer now with this agent.

for now as a workaround i changed startup time in tanuki to wrapper.startup.timeout=0 but it would be nice if you can try to fix this exceptions when you get time

thanks
tomislav

11

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.