microsoft / ApplicationInsights-Java

Application Insights for Java
http://aka.ms/application-insights
Other
296 stars 199 forks source link

[Query] Error in capturing JMX Metrics for Standalone Apache Artemis #1858

Closed agrajm closed 3 years ago

agrajm commented 3 years ago

Expected behavior

  1. Deploy Java Application Agent with Apache Artemis. It should collect "all" exposed JMX Metrics that I can see in the JDK Mission Control for the application and I should be able to see them in Azure Portal. Is this assumption wrong? image

  2. By default the auto-collect for JMX is true so it should collect all the JMX metrics exposed by the application automatically. I explicitly turn this on in applicationinsights.json but that does not help either.

Actual behavior

Errors in logs and in-determinstic metrics seen in Portal. Some metrics are getting collected some time while others are not getting collected.

To Reproduce

  1. Create App Insights and note the instrumentation key
  2. Download Java Application agent and run that as javaagent with Apache Artemis as documented here.
  3. Configuration used for application insights -- tried with both empty jmxMetrics and specific metrics as below
    {
    "connectionString": "InstrumentationKey=b............................20ef2",
    "role": {
    "name": "Artemis Metrics"
    },
    "sampling": {
    "percentage": 100
    },
    "jmxMetrics":  [
    {
      "name": "JVM uptime (millis)",
      "objectName": "java.lang:type=Runtime",
      "attribute": "Uptime"
    },
    {
      "name": "Heap Memory Usage",
      "objectName": "java.lang:type=Memory",
      "attribute": "HeapMemoryUsage.used"
    },
    {
      "name": "Free Heap Memory",
      "objectName": "java.lang:type=Memory",
      "attribute": "FreeHeapMemory"
    },
    {
      "name": "MetaSpace Used",
      "objectName": "java.lang:type=MemoryPool,name=Metaspace",
      "attribute": "Usage.used"
    },
    {
      "name": "Test Queue Message Count",
      "objectName": "org.apache.activemq.artemis:broker=testbroker,component=addresses,address=test,subcomponent=queues,routing-type=anycast,queue=testQ",
      "attribute": "MessageCount"
    }
    ],
    "customDimensions": {
    },
    "instrumentation": {
    "logging": {
      "level": "DEBUG"
    },
    "micrometer": {
      "enabled": true
    },
    "jms": {
      "enabled": true
    }
    },
    "proxy": {
    },
    "preview": {
    "processors": [
    ]
    },
    "selfDiagnostics": {
    "destination": "file+console",
    "level": "INFO",
    "file": {
      "path": "applicationinsights.log",
      "maxSizeMb": 5,
      "maxHistory": 1
    }
    }
    }

    4.. Logs suggest error in fetching JMX objects

    2021-08-19 14:40:17.610+10 ERROR c.m.a.i.p.FreeMemoryPerformanceCounter - Error getting FreePhysicalMemorySize
    2021-08-19 14:40:19.844+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Runtime' with attribute 'Uptime':
    2021-08-19 14:40:19.853+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
    2021-08-19 14:40:19.855+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Threading' with attribute 'ThreadCount':
    2021-08-19 14:40:19.855+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
    2021-08-19 14:40:19.858+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=MemoryPool,name=Metaspace' with attribute 'Usage.used':
    2021-08-19 14:40:19.859+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
    2021-08-19 14:40:19.865+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Memory' with attribute 'HeapMemoryUsage.used':
    2021-08-19 14:40:19.866+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
    2021-08-19 14:40:19.868+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=ClassLoading' with attribute 'LoadedClassCount':
    2021-08-19 14:40:19.874+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
    2021-08-19 14:40:19.876+10 ERROR c.m.a.i.p.CpuPerformanceCounterCalculator - Error in getProcessCPUUsage
    2021-08-19 14:40:19.878+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.IllegalArgumentException: Cannot find object name 'org.apache.activemq.artemis:broker=testbroker,component=addresses,address=test,subcomponent=queues,routing-type=anycast,queue=testQ''

Sample Application

A plain vanilla installation of Apache Artemis run with -javaagent as application insight agent.

System information

Please provide the following information:

Logs

2021-08-19 14:39:21.852+10 INFO  c.m.applicationinsights.agent - ApplicationInsights Java Agent 3.1.1 started successfully
     _        _               _
    / \  ____| |_  ___ __  __(_) _____
   / _ \|  _ \ __|/ _ \  \/  | |/  __/
  / ___ \ | \/ |_/  __/ |\/| | |\___ \
 /_/   \_\|   \__\____|_|  |_|_|/___ /
 Apache ActiveMQ Artemis 2.18.0
.....
.....
2021-08-19 14:39:30,125 INFO  [org.apache.activemq.artemis.core.server] AMQ221007: Server is now live
2021-08-19 14:39:30,126 INFO  [org.apache.activemq.artemis.core.server] AMQ221001: Apache ActiveMQ Artemis Message Broker version 2.18.0 [0.0.0.0, nodeID=08d3fab8-0001-11ec-8e68-2816a85e6aaa]
2021-08-19 14:39:31,768 INFO  [org.apache.activemq.hawtio.branding.PluginContextListener] Initialized activemq-branding plugin
2021-08-19 14:39:32,076 INFO  [org.apache.activemq.hawtio.plugin.PluginContextListener] Initialized artemis-plugin plugin
2021-08-19 14:39:32,926 INFO  [io.hawt.HawtioContextListener] Initialising hawtio services
2021-08-19 14:39:32,959 INFO  [io.hawt.system.ConfigManager] Configuration will be discovered via system properties
2021-08-19 14:39:32,962 INFO  [io.hawt.jmx.JmxTreeWatcher] Welcome to Hawtio 2.13.5
2021-08-19 14:39:33,005 INFO  [io.hawt.web.auth.AuthenticationConfiguration] Starting hawtio authentication filter, JAAS realm: "activemq" authorized role(s): "amq" role principal classes: "org.apache.activemq.artemis.spi.core.security.jaas.RolePrincipal"
2021-08-19 14:39:33,191 INFO  [io.hawt.web.proxy.ProxyServlet] Proxy servlet is disabled
2021-08-19 14:39:33,224 INFO  [io.hawt.web.servlets.JolokiaConfiguredAgentServlet] Jolokia overridden property: [key=policyLocation, value=file:/C:/Users/agmangal/softwares/apache-artemis-2.18.0/bin/testbroker/etc/\jolokia-access.xml]
2021-08-19 14:39:33,785 INFO  [org.apache.activemq.artemis] AMQ241001: HTTP Server started at http://localhost:8161
2021-08-19 14:39:33,786 INFO  [org.apache.activemq.artemis] AMQ241002: Artemis Jolokia REST API available at http://localhost:8161/console/jolokia
2021-08-19 14:39:33,787 INFO  [org.apache.activemq.artemis] AMQ241004: Artemis Console available at http://localhost:8161/console
2021-08-19 14:40:17.610+10 ERROR c.m.a.i.p.FreeMemoryPerformanceCounter - Error getting FreePhysicalMemorySize
2021-08-19 14:40:19.844+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Runtime' with attribute 'Uptime':
2021-08-19 14:40:19.853+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
2021-08-19 14:40:19.855+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Threading' with attribute 'ThreadCount':
2021-08-19 14:40:19.855+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
2021-08-19 14:40:19.858+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=MemoryPool,name=Metaspace' with attribute 'Usage.used':
2021-08-19 14:40:19.859+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
2021-08-19 14:40:19.865+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Memory' with attribute 'HeapMemoryUsage.used':
2021-08-19 14:40:19.866+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
2021-08-19 14:40:19.868+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=ClassLoading' with attribute 'LoadedClassCount':
2021-08-19 14:40:19.874+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.SecurityException: Insufficient roles/credentials for operation'
2021-08-19 14:40:19.876+10 ERROR c.m.a.i.p.CpuPerformanceCounterCalculator - Error in getProcessCPUUsage
2021-08-19 14:40:19.878+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.IllegalArgumentException: Cannot find object name 'org.apache.activemq.artemis:broker=testbroker,component=addresses,address=test,subcomponent=queues,routing-type=anycast,queue=testQ''
2021-08-19 14:41:17.605+10 ERROR c.m.a.i.p.FreeMemoryPerformanceCounter - Error getting FreePhysicalMemorySize
2021-08-19 14:41:18.117+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Runtime' with attribute 'Uptime':
2021-08-19 14:41:18.118+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Threading' with attribute 'ThreadCount':
2021-08-19 14:41:18.118+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=MemoryPool,name=Metaspace' with attribute 'Usage.used':
2021-08-19 14:41:18.120+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Memory' with attribute 'HeapMemoryUsage.used':
2021-08-19 14:41:18.120+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=ClassLoading' with attribute 'LoadedClassCount':
2021-08-19 14:41:18.121+10 ERROR c.m.a.i.p.CpuPerformanceCounterCalculator - Error in getProcessCPUUsage
2021-08-19 14:42:17.605+10 ERROR c.m.a.i.p.FreeMemoryPerformanceCounter - Error getting FreePhysicalMemorySize
2021-08-19 14:42:18.119+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Runtime' with attribute 'Uptime':
2021-08-19 14:42:18.120+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Threading' with attribute 'ThreadCount':
2021-08-19 14:42:18.120+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=MemoryPool,name=Metaspace' with attribute 'Usage.used':
2021-08-19 14:42:18.121+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Memory' with attribute 'HeapMemoryUsage.used':
2021-08-19 14:42:18.122+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=ClassLoading' with attribute 'LoadedClassCount':
2021-08-19 14:42:18.122+10 ERROR c.m.a.i.p.CpuPerformanceCounterCalculator - Error in getProcessCPUUsage
2021-08-19 14:43:17.614+10 ERROR c.m.a.i.p.FreeMemoryPerformanceCounter - Error getting FreePhysicalMemorySize
2021-08-19 14:43:18.161+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Runtime' with attribute 'Uptime':
2021-08-19 14:43:18.162+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Threading' with attribute 'ThreadCount':
2021-08-19 14:43:18.162+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=MemoryPool,name=Metaspace' with attribute 'Usage.used':
2021-08-19 14:43:18.164+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=Memory' with attribute 'HeapMemoryUsage.used':
2021-08-19 14:43:18.164+10 WARN  c.m.a.internal.jmx.JmxDataFetcher - Failed to fetch JMX object 'java.lang:type=ClassLoading' with attribute 'LoadedClassCount':
2021-08-19 14:43:18.165+10 ERROR c.m.a.i.p.CpuPerformanceCounterCalculator - Error in getProcessCPUUsage

Screenshots

Trying to see the metrics in Portal in AppInsights -> Metrics -> Log Based Metrics

jmxmetricsportal

Questions

  1. Which "namespace" are these JMX metrics collected in? - "azure.applicationinsights" or "microsoft.insights/components/kusto" (Log Based Metrics) ?

  2. Are these metrics also available in customMetrics table in Logs?

  3. How to capture & see all the JMX metrics in AppInsights or Azure Portal that I can see in Zulu Mission Control ?

  4. Once able to capture these JMX metrics, the actual goal is to capture the JMS queue level metrics exposed by Apache Artemis. It provides a GUI which shows other queue level relevant metrics like message count, no of messages acknowledged, consumer count, durable message count (shown below) image

For achieving above, I tried with following jmxMetrics in applicationinsights.json but it did not work and raised an IllegalArgumentException - probably need to expose these from Artemis first and I cannot see them in Zulu Mission Control also!

{
      "name": "Test Queue Message Count",
      "objectName": "org.apache.activemq.artemis:broker=testbroker,component=addresses,address=test,subcomponent=queues,routing-type=anycast,queue=testQ",
      "attribute": "MessageCount"
    }

Error when I configure this

2021-08-19 14:40:19.878+10 ERROR c.m.a.i.p.AbstractJmxPerformanceCounter - Error while fetching JMX data: 'java.lang.IllegalArgumentException: Cannot find object name 'org.apache.activemq.artemis:broker=testbroker,component=addresses,address=test,subcomponent=queues,routing-type=anycast,queue=testQ''
agrajm commented 3 years ago

Update: Able to figure out some details

  1. By default the 3.0 agent collects only these JMX metrics. For the rest you would need to configure in the applicationinsights.json file.
  2. Yes, the metrics are present in the customMetrics table and can also be seen in the portal in Metrics -> Log Based Metrics under "Custom"

I still don't know the reason behind the intermittent errors I'm observing in the logs Also, where can I find the complete schema for the applicationinsights.json file ?

kryalama commented 3 years ago

@agrajm we tried reproducing the issue locally. Looks like the fix will be on the Artemis side. Looking at the exception you shared, after whitelisting the "java.lang" object in the management.xml file resolved the issue. image

ghost commented 3 years ago

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 4 days. It will be closed if no further activity occurs within 3 days of this comment.

agrajm commented 3 years ago

Thanks @kryalama this works after whitelisting at Artemis end.