Bug 1128614

Summary: RHQ 4.12 high CPU usage in hibernate thread (java.util.regex.Pattern$Start.match)
Product: [Other] RHQ Project Reporter: Stian Lund <stianlund+bugzilla>
Component: Core Server, PerformanceAssignee: Thomas Segismont <tsegismo>
Status: ON_QA --- QA Contact:
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.12CC: genman, hrupp, tsegismo
Target Milestone: ---   
Target Release: RHQ 4.13   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1132091 (view as bug list) Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1132091    
Attachments:
Description Flags
RHQ Cpu Usage
none
Plugin for 4.12 patched with cherry-picked commit b5e8b3b none

Description Stian Lund 2014-08-11 08:11:53 UTC 
Created attachment 925643 [details]
RHQ Cpu Usage

Description of problem:

Since 4.12 installation I've noticed a steady increase in CPU usage for RHQ. At appears threads started by Hibernate doing some regex matching is locked and will not finish.

This is the stack trace of the threads:

    "HttpManagementService-threads - 529" prio=10 tid=0x00007faee836e000 nid=0x2e32 runnable [0x00007faed63de000]  
       java.lang.Thread.State: RUNNABLE  
        at java.util.regex.Pattern$Start.match(Pattern.java:3408)  
        at java.util.regex.Matcher.search(Matcher.java:1199)  
        at java.util.regex.Matcher.find(Matcher.java:592)  
        at java.util.regex.Matcher.replaceAll(Matcher.java:902)  
        at java.lang.String.replace(String.java:2180)  
        at org.jboss.as.jpa.hibernate4.management.QueryName.displayable(QueryName.java:174)  
        at org.jboss.as.jpa.hibernate4.management.QueryName.<init>(QueryName.java:120)  
        at org.jboss.as.jpa.hibernate4.management.QueryName.queryName(QueryName.java:110)  
        at org.jboss.as.jpa.hibernate4.management.HibernateStatisticsResource.getQueryNames(HibernateStatisticsResource.java:345)  
        at org.jboss.as.jpa.hibernate4.management.HibernateStatisticsResource.hasQuery(HibernateStatisticsResource.java:332)  
        at org.jboss.as.jpa.hibernate4.management.HibernateStatisticsResource.hasChild(HibernateStatisticsResource.java:81)  
        at org.jboss.as.controller.OperationContextImpl.getAuthorizationResource(OperationContextImpl.java:1171)  
        at org.jboss.as.controller.OperationContextImpl.getBasicAuthorizationResponse(OperationContextImpl.java:1129)  
        at org.jboss.as.controller.OperationContextImpl.authorize(OperationContextImpl.java:1052)  
        at org.jboss.as.controller.OperationContextImpl.authorize(OperationContextImpl.java:848)  
        at org.jboss.as.controller.operations.global.ReadResourceHandler.doExecuteInternal(ReadResourceHandler.java:265)  
        at org.jboss.as.controller.operations.global.ReadResourceHandler.doExecute(ReadResourceHandler.java:142)  
        at org.jboss.as.controller.operations.global.GlobalOperationHandlers$AbstractMultiTargetHandler.execute(GlobalOperationHandlers.java:249)  
        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:230)  
        at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:136)  
        at org.jboss.as.controller.ModelControllerImpl$3.execute(ModelControllerImpl.java:436)  
        at org.jboss.as.controller.ModelControllerImpl$3.execute(ModelControllerImpl.java:426)  
        at org.jboss.as.domain.http.server.DomainApiHandler.processRequest(DomainApiHandler.java:263)  
        at org.jboss.as.domain.http.server.DomainApiHandler.doHandle(DomainApiHandler.java:167)  
        at org.jboss.as.domain.http.server.DomainApiHandler.handle(DomainApiHandler.java:174)  
        at org.jboss.as.domain.http.server.security.SubjectAssociationHandler$1.run(SubjectAssociationHandler.java:69)  
        at org.jboss.as.domain.http.server.security.SubjectAssociationHandler$1.run(SubjectAssociationHandler.java:65)  
        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.domain.http.server.security.SubjectAssociationHandler.handleRequest(SubjectAssociationHandler.java:65)  
        at org.jboss.as.domain.http.server.security.SubjectAssociationHandler.handle(SubjectAssociationHandler.java:59)  
        at org.jboss.as.domain.http.server.DomainApiCheckHandler.handle(DomainApiCheckHandler.java:45)  
        at org.jboss.com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:78)  
        at org.jboss.sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:69)  
        at org.jboss.com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:81)  
        at org.jboss.sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:710)  
        at org.jboss.com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:78)  
        at org.jboss.as.domain.http.server.RealmReadinessFilter.doFilter(RealmReadinessFilter.java:47)  
        at org.jboss.as.domain.http.server.DmrFailureReadinessFilter.doFilter(DmrFailureReadinessFilter.java:45)  
        at org.jboss.com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:81)  
        at org.jboss.sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:682)  
        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)  
        at org.jboss.threads.JBossThread.run(JBossThread.java:122)  
		
This is affecting both or Test RHQ installations, running RHEL 6.5 with Java 1.7_45. They are dual CPU VMs and currently two threads are running at 100% causing almost full load.

The CPU is slowly building over time, see attached graph of user load.

This is actually an EAP problem as the high cpu apparently comes from very intensive code in the EAP JPA libraries, according to some other BZ and Jira I found.


Version-Release number of selected component (if applicable):

RHQ 4.12
Jboss EAP 6.3 Alpha running RHQ
Red Hat Enterprise Linux Server release 6.5 (Santiago)
Linux 2.6.32-431.23.3.el6.x86_64 #1 SMP Wed Jul 16 06:12:23 EDT 2014 x86_64 x86_64 x86_64 GNU/Linux

How reproducible:

Always.

Steps to Reproduce:
1. Fresh installation of RHQ 4.12
2. Let run for some time 12 hours plus.
3. See CPU usage stadily increase to 100%.

Additional info:
https://bugzilla.redhat.com/show_bug.cgi?id=1116345

https://access.redhat.com/solutions/1120463

https://issues.jboss.org/browse/JIPI-32
Comment 1 Stian Lund 2014-08-20 07:21:31 UTC 
If anyone knows a temp workaround or have a binary build of jars that could fix this I'd be glad to test it in our environment.
Comment 2 Thomas Segismont 2014-08-20 15:27:44 UTC 
Fixed in master

commit b5e8b3b09d5f05506ecd723feeeb1be5be1af6e5
Author: Thomas Segismont <tsegismo>
Date:   Wed Aug 20 17:24:56 2014 +0200

EAP up to 6.3 included has an issue with the JIPI implementation which cause high CPU usage when reading the Hibernate Persistence Unit with :read-resource.

High CPU usage was detected when checking for availability and loading configuration. So the fix consists in:

* BaseComponent#getAvailability change
Read only minimum information as we just want to make sure we can read the resource. There's no need to read the children names, evaluate defaults, and retrieve runtime attributes.

* HibernatePersistenceUnitComponent#loadConfiguration addition
Reading the "enabled" attribute is the only thing needed.

These changes not only fix the issue but generally improve performance in the AS7 plugin (less data sent over the AS7 management connection).
Comment 3 Stian Lund 2014-08-22 08:36:22 UTC 
I have tested overnight with the 4.13 snapshot built with Thomas' fix. It seems to have worked and CPU usage (user load) is now down to almost nothing, like is expected in this small test env.

There was a bit of a hack to install the plugin as plugin.xml had to be changed because import failed at first but I got it imported.

I have another installation I did the same but I think I forgot to update the agents so to double check I need to run it over the weekend.

Thanks to Thomas for the fix!
Comment 4 Elias Ross 2014-08-25 20:54:43 UTC 
Created attachment 930635 [details]
Plugin for 4.12 patched with cherry-picked commit b5e8b3b