No JMX metrics in JBoss EAP 7.3.0

sopgreg · June 24, 2020, 10:52am

Kibana version: 7.7.1

Elasticsearch version: 7.7.1

APM Server version: 7.7.1

APM Agent language and version: Java, 1.17

Browser version: not relevant

Original install method (e.g. download page, yum, deb, from source, etc.) and version: download

Fresh install or upgraded from other version? fresh install

Is there anything special in your setup? no, plain "quick setup" installation

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

The Java agent does not capture JMX metrics as defined like this in JBoss EAP 7.3.0:

capture_jmx_metrics=object_name[jboss.as:subsystem=datasources,data-source=NomTDS_Pool,statistics=pool] attribute[AvailableCount] attribute[ActiveCount] attribute[InUseCount] attribute[TimedOut] attribute[WaitCount]

Also tried with wildcard for the pool name:

capture_jmx_metrics=object_name[jboss.as:subsystem=datasources,data-source=*,statistics=pool] attribute[AvailableCount] attribute[ActiveCount] attribute[InUseCount] attribute[TimedOut] attribute[WaitCount]

The only logs that appear can be seen below. JBoss/Wildfly creates the ObjectName at runtime when it discovers the various data sources in the standalone.xml configuration. See screenshot from JConsole, the MBean is available with all the attributes defined:

grafik

Steps to reproduce:

Start JBoss with Agent via --javagent (standalone.conf.bat)
Use configuration above

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

These are the only logs related to "jmx" in JBoss:

2020-06-23 17:14:35.172 [main] DEBUG co.elastic.apm.agent.configuration.StartupInfo - capture_jmx_metrics: 'object_name[jboss.as:subsystem=datasources,data-source=NomTDS_Pool,statistics=pool] attribute[AvailableCount] attribute[ActiveCount] attribute[InUseCount] attribute[TimedOut] attribute[WaitCount]' (source: C:\Server\JBoss_NomT\bin/elasticapm.properties)
2020-06-23 17:14:36.414 [main] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Deferring initialization of JMX metric tracking until log manager is initialized

2020-06-23 17:19:12.350 [elastic-apm-jmx-init] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Init JMX metric tracking with server com.sun.jmx.mbeanserver.JmxMBeanServer@402f88d
2020-06-23 17:19:12.356 [elastic-apm-jmx-init] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found mbeans for object name jboss.as:subsystem=datasources,data-source=NomTDS_Pool,statistics=pool

felixbarny · June 24, 2020, 2:14pm

Hi and thanks for your question!

Maybe what's happening here is that JBoss creates a special MBeanServer where it registers the metrics to. Currently, we only track metrics from the platfrom MBean server (ManagementFactory.getPlatformMBeanServer()).

Could you try to find out if there are indeed multiple MBean servers by calling MBeanServerFactory.findMBeanServer(null)? If so, whats the domain (MBeanServer#getDefaultDomain) of the MBean server that contains the metrics you are looking for?

sopgreg · June 24, 2020, 3:29pm

This is strange. There is only one MBean server, but querying the MBeans (returns more than 200), does not return the ones in question. Still, JConsole returns such MBeans and they can also be queried using a Jolokia servlet.

sopgreg · June 24, 2020, 4:39pm

The MBean seems to be there:

sopgreg · June 25, 2020, 7:54am

I built a snapshot of the agent myself and put a breakpoint here:

JmxMetricTracker.java:192

Seems that no MBeans of domain "jboss:as" are caught here at all - maybe some kind of race condition/timing issue? Imho the listener is registered early enough.

But what's also interesting is, is that in JmxMetricTracker#init and via ManagementFactory.getPlatformMBeanServer(), this time the MBean server seems to be something different:

org.jboss.as.jmx.PluggableMBeanServerImpl@6c89032e

felixbarny · June 25, 2020, 8:10am

That's interesting. Maybe JBoss overrides the default platform MBean server with a new one by calling javax.management.MBeanServerFactory.createMBeanServer(null).

felixbarny · June 25, 2020, 9:13am

Actually, it seems like the platform MBean server can't be overridden once set.

This seems to be the toString() representation whereas PluggableMBeanServerImpl@4986 is the object id. Could you check again if it's the same instance of the object?

What you could also try is to add the capture_jmx_metrics config after the server has already started. The agent will load the new configuration from elasticapm.properties every 30s.

sopgreg · June 25, 2020, 9:52am

The MBean server seems to be the same during #init and later on once the server is started. This time, the name again changed to JmxMBeanServer instead of PluggableMBeanServerImpl

Adding capture_jmx_metrics at runtime finally worked:

2020-06-25 11:37:59,197 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Init JMX metric tracking with server org.jboss.as.jmx.PluggableMBeanServerImpl@bd63369
2020-06-25 11:37:59,978 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found mbeans for object name jboss.as:subsystem=datasources,data-source=*,statistics=pool
2020-06-25 11:38:00,060 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute AvailableCount=0
2020-06-25 11:38:00,252 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute ActiveCount=0
2020-06-25 11:38:00,324 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute InUseCount=0
2020-06-25 11:38:00,400 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute TimedOut=0
2020-06-25 11:38:00,440 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute WaitCount=0
2020-06-25 11:38:00,489 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute AvailableCount=100
2020-06-25 11:38:00,497 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute ActiveCount=10
2020-06-25 11:38:00,501 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute InUseCount=0
2020-06-25 11:38:00,540 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found number attribute TimedOut=0

felixbarny · June 25, 2020, 12:20pm

Ok, there seems to be something going on with the NotificationListener then. Could you try the artifacts from this PR and set the log level to trace to test this out?

sopgreg · June 25, 2020, 2:56pm

This is what we get. The agent gets notified of around 400 MBeans, but there are more than 3000 in JConsole. The "jboss:as" ones are not logged.

2: 2020-06-25 16:49:57,400 [main] INFO  co.elastic.apm.agent.util.JmxUtils - Found JVM-specific OperatingSystemMXBean interface: com.sun.management.OperatingSystemMXBean

    246: 2020-06-25 16:49:59,006 [main] DEBUG co.elastic.apm.agent.configuration.StartupInfo - capture_jmx_metrics: 'object_name[jboss.as:subsystem=datasources,data-source=*,statistics=pool] attribute[AvailableCount] attribute[ActiveCount] attribute[InUseCount] attribute[TimedOut] attribute[WaitCount]' (source: C:\Server\apm/elasticapm.properties)

    277: 2020-06-25 16:50:00,694 [main] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Deferring initialization of JMX metric tracking until log manager is initialized

    279: 2020-06-25 16:50:01,853 [elastic-apm-jmx-init] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Init JMX metric tracking with server com.sun.jmx.mbeanserver.JmxMBeanServer@224ab400

    280: 2020-06-25 16:50:01,866 [elastic-apm-jmx-init] DEBUG co.elastic.apm.agent.jmx.JmxMetricTracker - Found no mbeans for object name jboss.as:subsystem=datasources,data-source=*,statistics=pool. Listening for MBeans added later.

    281: 2020-06-25 16:50:02,001 [main] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.modules:type=ModuleLoader,name=ModuleLoader-2

    282: 2020-06-25 16:50:02,001 [main] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.modules:type=ModuleLoader,name=LocalModuleLoader-3

    513: 2020-06-25 16:50:02,641 [main] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.threads:name="threadpool-1",type=thread-pool

    514: 2020-06-25 16:50:02,649 [main] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.msc:type=container,name=jboss-as

    515: 2020-06-25 16:50:02,835 [main] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.root:type=state

    516: 2020-06-25 16:50:02,895 [MSC service thread 1-3] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.modules:type=ModuleLoader,name=ServiceModuleLoader-4

    517: 2020-06-25 16:50:03,017 [MSC service thread 1-5] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.threads:name="threadpool-2",type=thread-pool

    659: 2020-06-25 16:50:13,420 [MSC service thread 1-3] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.threads:name="threadpool-3",type=thread-pool

    660: 2020-06-25 16:50:13,431 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.threads:name="threadpool-4",type=thread-pool

    661: 2020-06-25 16:50:13,514 [MSC service thread 1-8] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for org.xnio:type=Xnio,provider="nio"

    689: 2020-06-25 16:50:13,768 [MSC service thread 1-8] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.threads:name="management",type=thread-pool

    690: 2020-06-25 16:50:13,914 [MSC service thread 1-8] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for org.xnio:type=Xnio,provider="nio",worker="management"

    719: 2020-06-25 16:50:14,095 [MSC service thread 1-5] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.threads:name="default",type=thread-pool

    747: 2020-06-25 16:50:14,135 [MSC service thread 1-5] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for org.xnio:type=Xnio,provider="nio",worker="default"

    796: 2020-06-25 16:50:14,216 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.endpoint:name=Remoting-node_a-760439895

    861: 2020-06-25 16:50:14,278 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-remote-691247730

    862: 2020-06-25 16:50:14,279 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-remote+tls-282658987

    863: 2020-06-25 16:50:14,280 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-remoting-1331247756

    864: 2020-06-25 16:50:14,280 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-remote+http-136111724

    865: 2020-06-25 16:50:14,281 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-remote+https-896731320

    866: 2020-06-25 16:50:14,303 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-http-remoting-1843901870

    867: 2020-06-25 16:50:14,303 [MSC service thread 1-1] TRACE co.elastic.apm.agent.jmx.JmxMetricTracker - Receiving MBean registration notification for jboss.remoting.handler:name=Remoting-node_a-https-remoting-1548565077

    + 300 more

felixbarny · June 29, 2020, 7:51am

I have found the issue. Could you try out the build artifact from this PR: https://github.com/elastic/apm-agent-java/pull/1258#issuecomment-650985749

sopgreg · June 29, 2020, 11:58am

While it does capture a lot more now, it still seems to miss the ",statistics=pool" beans:

Sylvain_Juge · July 1, 2020, 3:35pm

Hi @sopgreg, I've managed to reproduce the issue locally

only when installing agent with -javaagent option
MBean is not available on startup but registered at a later time.

Sylvain_Juge · July 2, 2020, 1:08pm

We found a way to make it work, could you try this snapshot to check if it's now working as expected ?

The underlying issue is that Jboss does not seem to always trigger notifications for beans that are in the boss.as domain, but if you configure it with jboss.as.expr it should work. The fix in the snapshot just applies a fallback to detect when the bean is added, so you just can use the beans as you see them in jconsole.

sopgreg · July 3, 2020, 6:10am

This fix/fallback solves the issue.

It's a bit weird what JBoss is doing here, as they recommend themselves to use the jboss:as MBean for the query (see https://access.redhat.com/solutions/268793).

Thanks a lot for the efforts!

system · July 24, 2020, 2:15am

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