Bug 1077536 - [GSS] (6.3.0) High CPU usage by JMX monitoring client, RBAC seems the hotspot
Summary: [GSS] (6.3.0) High CPU usage by JMX monitoring client, RBAC seems the hotspot
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: JBoss Enterprise Application Platform 6
Classification: JBoss
Component: Domain Management
Version: 6.2.1
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ER2
: EAP 6.3.0
Assignee: Brian Stansberry
QA Contact: Petr Kremensky
Russell Dickenson
URL:
Whiteboard:
Depends On:
Blocks: 1089616
TreeView+ depends on / blocked
 
Reported: 2014-03-18 08:23 UTC by Osamu Nagano
Modified: 2018-12-05 17:44 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
A performance issue affecting JMX Query was identified, where the CPU load was much higher than expected in previous JBoss EAP releases. The cause of the issue was that role-based access control (RBAC) was checking the address of every query, regardless of whether that address was relevant to JMX Query. To resolve this issue the processing of querie was changed to first check if the address is relevant to JMX Query and if not, avoid the processing involved. The result of this change is that CPU load of JMX monitoring is again at a normal level.
Clone Of:
: 1089616 (view as bug list)
Environment:
Last Closed: 2014-06-28 15:25:49 UTC
Type: Bug


Attachments (Terms of Use)
jmxclient.zip (5.02 KB, application/zip)
2014-03-18 08:23 UTC, Osamu Nagano
no flags Details
hprof.samples.txt (31.12 KB, text/plain)
2014-03-18 08:26 UTC, Osamu Nagano
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker WFLY-3161 0 Major Resolved Optimize org.jboss.as.jmx.model.RootResourceIterator 2020-09-11 13:50:06 UTC

Description Osamu Nagano 2014-03-18 08:23:34 UTC
Created attachment 875831 [details]
jmxclient.zip

Description of problem:
A simple JMX client causes about 30 to 40 % CPU utilization, even when resuing a JMXConnector.  The client is reading some MBeans in every 2 seconds.  On EAP 6.1.0, it was less than 5 %.


Steps to Reproduce:
1. Start EAP 6.2.1 standalone.
2. Run attached client.
~~~
unzip jmxclient.zip
cd jmxclient
JBOSS_HOME=<EAP621home> ./run.sh
~~~
3. Monitor CPU usage by 'top -H -p $PID'


Actual results:
Thread named like "pool-2-thread-1" constantly takes about 30 % CPU.


Expected results:
30 % is too high.  This JMX monitoring capability is one of musts for the customer.


Additional info:
Sample stack is here.
~~~
"pool-2-thread-1" prio=10 tid=0x00007f84481e6000 nid=0x1d09 runnable [0x00007f848b3b3000]
   java.lang.Thread.State: RUNNABLE
        at org.jboss.as.controller.access.rbac.DefaultPermissionFactory.configureRolePermissions(DefaultPermissionFactory.java:256)
        - locked <0x00000000aea33c20> (a org.jboss.as.controller.access.rbac.DefaultPermissionFactory)
        at org.jboss.as.controller.access.rbac.DefaultPermissionFactory.getUserPermissions(DefaultPermissionFactory.java:120)
        at org.jboss.as.controller.access.rbac.DefaultPermissionFactory.getUserPermissions(DefaultPermissionFactory.java:102)
        at org.jboss.as.controller.access.permission.ManagementPermissionAuthorizer.authorize(ManagementPermissionAuthorizer.java:88)
        at org.jboss.as.controller.access.management.DelegatingConfigurableAuthorizer.authorize(DelegatingConfigurableAuthorizer.java:93)
        at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:918)
        at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:105)
        at org.jboss.as.controller.operations.global.ReadResourceDescriptionHandler$CheckResourceAccessHandler.execute(ReadResourceDescriptionHandler.java:408)
        at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:601)
        at org.jboss.as.controller.AbstractOperationContext.doCompleteStep(AbstractOperationContext.java:479)
        at org.jboss.as.controller.AbstractOperationContext.completeStepInternal(AbstractOperationContext.java:283)
        at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:278)
        at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:231)
        at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:137)
        at org.jboss.as.jmx.model.ResourceAccessControlUtil.getResourceAccess(ResourceAccessControlUtil.java:85)
        at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:48)
        at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:59)
        at org.jboss.as.jmx.model.RootResourceIterator.iterate(RootResourceIterator.java:41)
        at org.jboss.as.jmx.model.ModelControllerMBeanHelper.queryMBeans(ModelControllerMBeanHelper.java:131)
        at org.jboss.as.jmx.model.ModelControllerMBeanServerPlugin.queryMBeans(ModelControllerMBeanServerPlugin.java:153)
        at org.jboss.as.jmx.PluggableMBeanServerImpl.queryMBeans(PluggableMBeanServerImpl.java:815)
        at org.jboss.remotingjmx.protocol.v2.ServerProxy$QueryMBeansHandler.handle(ServerProxy.java:1082)
        at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1$1.run(ServerCommon.java:153)
        at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:75)
        at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:70)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:415)
        at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:94)
        at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor.handleEvent(ServerInterceptorFactory.java:70)
        at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1.run(ServerCommon.java:149)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)
~~~

Comment 1 Osamu Nagano 2014-03-18 08:26:18 UTC
Created attachment 875832 [details]
hprof.samples.txt

Sampling by HPROF, every 10 ms, stack depth is 4.
~~~
   JAVA_OPTS="$JAVA_OPTS -agentlib:hprof=cpu=samples,file=hprof.samples,force=n"
~~~
http://docs.oracle.com/javase/7/docs/technotes/samples/hprof.html

Comment 2 Osamu Nagano 2014-03-18 08:32:48 UTC
I took a simple hprof sample for 10 minites run.

rank   self  accum   count trace method
   1 78.14% 78.14%  560102 300903 sun.nio.ch.EPollArrayWrapper.epollWait
   2 15.63% 93.77%  112023 301249 java.net.PlainSocketImpl.socketAccept
   3  2.97% 96.73%   21255 301430 java.security.AccessController.getStackAccessControlContext
   4  0.70% 97.43%    5027 301450 java.security.AccessController.doPrivileged
   5  0.33% 97.76%    2348 301585 java.lang.Class.getClassLoader0
   6  0.25% 98.02%    1816 300753 java.lang.Object.hashCode
   7  0.22% 98.24%    1604 301496 org.jboss.as.controller.access.rbac.DefaultPermissionFactory.configureRolePermissions
   8  0.09% 98.32%     612 301506 java.lang.Throwable.fillInStackTrace
   9  0.07% 98.40%     512 301498 java.util.regex.Pattern$5.isSatisfiedBy

TRACE 301430:
        java.security.AccessController.getStackAccessControlContext(AccessController.java:Unknown line)
        java.security.AccessController.getContext(AccessController.java:495)
        org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:132)
        org.jboss.as.controller.AbstractOperationContext.getCaller(AbstractOperationContext.java:846)

TRACE 301450:
        java.security.AccessController.doPrivileged(AccessController.java:Unknown line)
        javax.security.auth.Subject.getSubject(Subject.java:296)
        org.jboss.as.controller.SecurityActions$CallerActions$1.getCaller(SecurityActions.java:193)
        org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:133)

TRACE 301496:
        org.jboss.as.controller.access.rbac.DefaultPermissionFactory.configureRolePermissions(DefaultPermissionFactory.java:256)
        org.jboss.as.controller.access.rbac.DefaultPermissionFactory.getUserPermissions(DefaultPermissionFactory.java:120)
        org.jboss.as.controller.access.rbac.DefaultPermissionFactory.getUserPermissions(DefaultPermissionFactory.java:107)
        org.jboss.as.controller.access.permission.ManagementPermissionAuthorizer.authorize(ManagementPermissionAuthorizer.java:99)

Comment 10 Petr Kremensky 2014-04-30 08:27:11 UTC
Verified on EAP 6.3.0.ER2.


Note You need to log in before you can comment on or make changes to this bug.