ApplicationInsights-Java icon indicating copy to clipboard operation
ApplicationInsights-Java copied to clipboard

Application insight profiler is not working in Spring boot App

Open Sachin1O1 opened this issue 1 year ago • 15 comments

Expected behavior

Profiler should run

Actual behavior

Getting following exception 2022-07-06 09:21:52.725Z ERROR c.m.a.a.i.profiler.GcEventMonitor - Failed to monitor gc mxbeans 2022-07-06 09:21:52.749Z WARN c.m.a.s.JfrProfilerService - INITIALISING JFR PROFILING SUBSYSTEM THIS FEATURE IS IN BETA 2022-07-06 09:21:52.832Z ERROR c.m.a.s.profiler.JfrProfiler - Failed to connect to mbean javax.management.InstanceNotFoundException: com.sun.management:type=DiagnosticCommand at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1083) at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getObjectInstance(DefaultMBeanServerInterceptor.java:458) at java.management/com.sun.jmx.mbeanserver.JmxMBeanServer.getObjectInstance(JmxMBeanServer.java:564) at com.microsoft.jfr.dcmd.FlightRecorderDiagnosticCommandConnection.connect(FlightRecorderDiagnosticCommandConnection.java:76) at com.microsoft.applicationinsights.serviceprofilerapi.profiler.JfrProfiler.initialize(JfrProfiler.java:164) at com.microsoft.applicationinsights.serviceprofilerapi.JfrProfilerService.initialiseProfiler(JfrProfilerService.java:143) at com.microsoft.applicationinsights.serviceprofilerapi.JfrProfilerService.lambda$initialize$0(JfrProfilerService.java:114) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:871) 2022-07-06 09:21:52.833Z ERROR c.m.a.s.JfrProfilerService - Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown 2022-07-06 09:21:52.835Z ERROR c.m.a.a.i.p.ProfilerServiceInitializer - Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown java.util.concurrent.ExecutionException: java.lang.RuntimeException: Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999) at com.microsoft.applicationinsights.agent.internal.profiler.ProfilerServiceInitializer.lambda$initialize$0(ProfilerServiceInitializer.java:151) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:871) Caused by: java.lang.RuntimeException: Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown at com.microsoft.applicationinsights.serviceprofilerapi.JfrProfilerService.lambda$initialize$0(JfrProfilerService.java:115) ... 6 common frames omitted

To Reproduce

Enable application insight profiler in spring boot app using applicationinsight.json config using following code "preview": { "profiler":{ "configPollPeriodSeconds": 60, "enabled":true },

Sample Application

System information

Please provide the following information:

  • SDK Version: 3.3.0
  • OS type and version: linux
  • Application Server type and version (if applicable):
  • Using spring-boot? yes
  • Additional relevant libraries (with version, if applicable):

Logs

2022-07-06 09:21:52.725Z ERROR c.m.a.a.i.profiler.GcEventMonitor - Failed to monitor gc mxbeans 2022-07-06 09:21:52.749Z WARN c.m.a.s.JfrProfilerService - INITIALISING JFR PROFILING SUBSYSTEM THIS FEATURE IS IN BETA 2022-07-06 09:21:52.832Z ERROR c.m.a.s.profiler.JfrProfiler - Failed to connect to mbean javax.management.InstanceNotFoundException: com.sun.management:type=DiagnosticCommand at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1083) at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getObjectInstance(DefaultMBeanServerInterceptor.java:458) at java.management/com.sun.jmx.mbeanserver.JmxMBeanServer.getObjectInstance(JmxMBeanServer.java:564) at com.microsoft.jfr.dcmd.FlightRecorderDiagnosticCommandConnection.connect(FlightRecorderDiagnosticCommandConnection.java:76) at com.microsoft.applicationinsights.serviceprofilerapi.profiler.JfrProfiler.initialize(JfrProfiler.java:164) at com.microsoft.applicationinsights.serviceprofilerapi.JfrProfilerService.initialiseProfiler(JfrProfilerService.java:143) at com.microsoft.applicationinsights.serviceprofilerapi.JfrProfilerService.lambda$initialize$0(JfrProfilerService.java:114) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:871) 2022-07-06 09:21:52.833Z ERROR c.m.a.s.JfrProfilerService - Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown 2022-07-06 09:21:52.835Z ERROR c.m.a.a.i.p.ProfilerServiceInitializer - Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown java.util.concurrent.ExecutionException: java.lang.RuntimeException: Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999) at com.microsoft.applicationinsights.agent.internal.profiler.ProfilerServiceInitializer.lambda$initialize$0(ProfilerServiceInitializer.java:151) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:871) Caused by: java.lang.RuntimeException: Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled. JFR profiling system will shutdown at com.microsoft.applicationinsights.serviceprofilerapi.JfrProfilerService.lambda$initialize$0(JfrProfilerService.java:115) ... 6 common frames omitted

Be sure to remove any private information from the logs before posting!

Screenshots

If applicable, add screenshots to help explain your problem.

Sachin1O1 avatar Jul 06 '22 13:07 Sachin1O1

hey @Sachin1O1

Unable to obtain JFR connection, this may indicate that your JVM does not have JFR enabled

What Java distribution are you using? What does java -version report? thx!

trask avatar Jul 06 '22 17:07 trask

Hi @trask, I am using the following image openjdk version "11.0.15" 2022-04-19 IBM Semeru Runtime Open Edition 11.0.15.0 (build 11.0.15+10)

Sachin1O1 avatar Jul 07 '22 06:07 Sachin1O1

Hi @Sachin1O1,

The profiler uses MBean operations.

You may use a Spring Boot version greater than 2.2 for which JMX is disabled by default.

You can enable JMX:

  • From a JVM property
-Dspring.jmx.enabled=true
  • From a .properties file
spring.jmx.enabled=true
  • From a YAML file
spring:
   jmx:
       enabled: true

Does this answer solve your problem?

jeanbisutti avatar Jul 07 '22 09:07 jeanbisutti

Hi @Sachin1O1, Please ignore my previous message. The error seems in fact related to the IBM Semeru JDK and not Spring.

jeanbisutti avatar Jul 07 '22 17:07 jeanbisutti

Hi @jeanbisutti , I tried what you suggested above but the issue still persists. I am also suspecting it's related to IBM Semeru JDK.

Sachin1O1 avatar Jul 08 '22 06:07 Sachin1O1

Hi @trask and @jeanbisutti , I think we are trying to use the commercial feature so it would be available in selective JDK images. Can you suggest some or any other workaround?

Sachin1O1 avatar Jul 08 '22 07:07 Sachin1O1

Hi @Sachin1O1, Could you please try with an image that does not contain an IBM Semeru or another OpenJ9-related JDK?

jeanbisutti avatar Jul 08 '22 11:07 jeanbisutti

Hi @jeanbisutti , I tried with adoptopenjdk:11-jre but no luck.

Sachin1O1 avatar Jul 08 '22 11:07 Sachin1O1

Hi @Sachin1O1, The image you have used seems to contain both HotSpot and OpenJ9 JREs. Could you please try starting your application with the HotSpot JRE?

jeanbisutti avatar Jul 08 '22 12:07 jeanbisutti

Hi @jeanbisutti, will update you soon with outcomes.

Sachin1O1 avatar Jul 18 '22 07:07 Sachin1O1

Hi @jeanbisutti , I used adoptopenjdk:11-jre-hotspot to test and it's not working, giving the following error. image

The similar thing you can see here https://github.com/sbt/sbt-jmh/issues/106,

Sachin1O1 avatar Jul 20 '22 06:07 Sachin1O1

Hi @Sachin1O1, -XX:+UnlockCommercialFeatures JVM option seems to be added. Could you please check your JVM options and remove -XX:+UnlockCommercialFeatures? Thanks! This issue does not seem related to Application Insights code.

jeanbisutti avatar Jul 20 '22 09:07 jeanbisutti

Hi @trask and @jeanbisutti, It finally works with adoptopenjdk:11-jre-hotspot but again this image is deprecated and we need to find another similar image. I want to thank both of you for your support. :)

Sachin1O1 avatar Jul 21 '22 06:07 Sachin1O1

Hi @Sachin1O1, It should also work with an 11.0.15_10-jdk-alpine image that is based on Hotpsot.

jeanbisutti avatar Jul 21 '22 09:07 jeanbisutti

re-opening, we should log a warning message if the profiler is enabled but it is not supported on the given JVM

trask avatar Jul 29 '22 21:07 trask

re-opening, we should log a warning message if the profiler is enabled but it is not supported on the given JVM

Fixed with #2465

jeanbisutti avatar Aug 29 '22 20:08 jeanbisutti