Unable to dynamically update instrumentation=true

Ananda_Babu · May 14, 2020, 12:44pm

Kibana version: 7.6.2

Elasticsearch version: 7.6.2

APM Server version: 7.6.2

APM Agent language and version: Java - elastic-apm-agent-1.15.0.jar

Original install method and version: APT repository

Fresh install or upgraded from other version? Fresh install

Is there anything special in your setup? None

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant):

Hi

I'm trying to start my tomcat with recording and instrumentation set to false, and then on demand i'm trying to set them to true during debug sessions.

The configs are kept in the elasticapm.properties file in the same directory as the jar file (/opt/).

While setting recording=true, I could see the JVM metrics are sent to apm-server thus displayed in Kibana.

However setting instrumentation=true, I couldn't get any data captured (the application is constantly accessed by a script to simulate the traffic for the demo)

I couldn't find any error in my apm-agent.log file (set via log_file=/var/log/tomcat9/apm-agent.log parameter).

But the syslog from tomcat9 throws the below exception.

java.lang.ClassNotFoundException: co.elastic.apm.agent.shaded.bytebuddy.agent.Installer

I've attached the logs for further reference. The same applies to when you try to set the instrumentation to false from true. The data is continued to sent to apm-server.

Steps to reproduce:

Start the agent with recording & instrumentation set to false
After starting the tomcat9, change the instrumentation to true in the elaspticapm.properties
watch the syslog (tail -f /var/log/syslog | grep apm)

Provide logs and/or server output (if relevant):

#tail -f /var/log/syslog | grep apm

        May 14 12:12:15 tomcat tomcat9[6687]: #011at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default.patchOnByteBuddyAgent(AgentBuilder.java:9435)
        May 14 12:12:15 tomcat tomcat9[6687]: #011at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Delegator.patchOnByteBuddyAgent(AgentBuilder.java:11007)
        May 14 12:12:15 tomcat tomcat9[6687]: #011at co.elastic.apm.agent.bci.ElasticApmAgent.doReInitInstrumentation(ElasticApmAgent.java:196)
        May 14 12:12:15 tomcat tomcat9[6687]: #011at co.elastic.apm.agent.bci.ElasticApmAgent$3.run(ElasticApmAgent.java:183)
        May 14 12:12:15 tomcat tomcat9[6687]: Caused by: java.lang.ClassNotFoundException: co.elastic.apm.agent.shaded.bytebuddy.agent.Installer
        May 14 12:12:15 tomcat tomcat9[6687]: #011at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default.patchOnByteBuddyAgent(AgentBuilder.java:9429)

apm-agent.log = https://gist.github.com/Anandababu/dc3b04f4284157c0f240acc55934c9ec

Eyal_Koren · May 14, 2020, 12:58pm

Hi and welcome to the forum!
How did you install the agent?

Ananda_Babu · May 14, 2020, 1:01pm

Apologies , should have included the info..

The apm-agent is attched via the -javaagent flag in the setenv.sh file in the catalina_base like
below

export CATALINA_OPTS="$CATALINA_OPTS -javaagent:/opt/elastic-apm-agent-1.15.0.jar"
export CATALINA_OPTS="$CATALINA_OPTS -Delastic.apm.service_name=my-application"
export CATALINA_OPTS="$CATALINA_OPTS -Delastic.apm.server_url=http://apm.com:8200"

The dashboards are all fine in displaying the metrics when tomcat9 started with instrumentation=true.

Its just that not possible to update them dynamically.

Ananda_Babu · May 14, 2020, 1:57pm

May 14 13:56:43 tomcat tomcat9[7665]: java.lang.IllegalStateException: The Byte Buddy agent is not installed or not accessible
May 14 13:56:43 tomcat tomcat9[7665]: #011at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default.patchOnByteBuddyAgent(AgentBuilder.java:9435)
May 14 13:56:43 tomcat tomcat9[7665]: #011at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Delegator.patchOnByteBuddyAgent(AgentBuilder.java:11007)
May 14 13:56:43 tomcat tomcat9[7665]: #011at co.elastic.apm.agent.bci.ElasticApmAgent.doReInitInstrumentation(ElasticApmAgent.java:196)
May 14 13:56:43 tomcat tomcat9[7665]: #011at co.elastic.apm.agent.bci.ElasticApmAgent$3.run(ElasticApmAgent.java:183)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/java.lang.Thread.run(Thread.java:834)
May 14 13:56:43 tomcat tomcat9[7665]: Caused by: java.lang.ClassNotFoundException: co.elastic.apm.agent.shaded.bytebuddy.agent.Installer
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:581)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:178)
May 14 13:56:43 tomcat tomcat9[7665]: #011at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
May 14 13:56:43 tomcat tomcat9[7665]: #011at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default.patchOnByteBuddyAgent(AgentBuilder.java:9429)
May 14 13:56:43 tomcat tomcat9[7665]: #011... 8 more

I've added my tomcat9 log from syslog for further help - https://gist.github.com/Anandababu/a51571ce94e310c78abf65001ac75597

Sylvain_Juge · May 15, 2020, 12:37pm

Thanks for this comprehensive report @Ananda_Babu, I've managed to reproduce it locally and opened an issue to fix it https://github.com/elastic/apm-agent-java/issues/1186.

It seems the issue does not happen when only the recording property is switched from false to true (and it's even available in remote config). Thus in the mean time you should be able to use only the recording property and remove instrument=false from your properties to use the default value.

The only difference with what you tried to do and using instrument=true (default) + recording=false is that it will use a no-op instrumentation and nothing is recorded. Doing like this also avoids any performance hit when enabling instrumentation afterwards as bytecode transformation is a short but cpu-intensive task.

Sylvain_Juge · May 15, 2020, 2:31pm

Also, I've found that this issue does not happen with latest version of the agent released yesterday (1.16.0), and it behaves as you would expect.

system · June 5, 2020, 10:31am

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