Bug 1132091

Summary:	High CPU usage in hibernate thread (java.util.regex.Pattern$Start.match)
Product:	[JBoss] JBoss Operations Network	Reporter:	Heiko W. Rupp <hrupp>
Component:	Plugin -- JBoss EAP 6	Assignee:	Michael Burman <miburman>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Mike Foley <mfoley>
Severity:	high	Docs Contact:
Priority:	unspecified
Version:	JON 3.2	CC:	hrupp, loleary, mfoley, stianlund+bugzilla, tsegismo
Target Milestone:	ER02	Keywords:	Triaged
Target Release:	JON 3.3.0
Hardware:	All
OS:	All
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:	1128614	Environment:
Last Closed:	2014-12-11 14:02:36 UTC	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:	1128614
Bug Blocks:

Description Heiko W. Rupp 2014-08-20 16:11:03 UTC

+++ This bug was initially created as a clone of Bug #1128614 +++

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

--- Additional comment from Stian Lund on 2014-08-20 03:21:31 EDT ---

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.

--- Additional comment from Thomas Segismont on 2014-08-20 11:27:44 EDT ---

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 2 Michael Burman 2014-08-21 09:59:45 UTC

Cherry-picked to release/jon3.3.x

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

    Bug 1128614 - RHQ 4.12 high CPU usage in hibernate thread (java.util.regex.Pattern$Start.match)
    
    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 :re
    
    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 defaul
    
    * 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).
    
    (cherry picked from commit b5e8b3b09d5f05506ecd723feeeb1be5be1af6e5)

Comment 3 Simeon Pinder 2014-09-03 20:31:39 UTC

Moving to ON_QA as available for test with the following brew build:
https://brewweb.devel.redhat.com//buildinfo?buildID=381194