Bug 1128614 - RHQ 4.12 high CPU usage in hibernate thread (java.util.regex.Pattern$Start.match)
Summary: RHQ 4.12 high CPU usage in hibernate thread (java.util.regex.Pattern$Start.ma...
Keywords:
Status: ON_QA
Alias: None
Product: RHQ Project
Classification: Other
Component: Core Server, Performance
Version: 4.12
Hardware: x86_64
OS: Linux
unspecified
high vote
Target Milestone: ---
: RHQ 4.13
Assignee: Thomas Segismont
QA Contact: Mike Foley
URL:
Whiteboard:
Depends On:
Blocks: 1132091
TreeView+ depends on / blocked
 
Reported: 2014-08-11 08:11 UTC by Stian Lund
Modified: 2014-08-25 20:54 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
: 1132091 (view as bug list)
Environment:
Last Closed:


Attachments (Terms of Use)
RHQ Cpu Usage (32.61 KB, image/png)
2014-08-11 08:11 UTC, Stian Lund
no flags Details
Plugin for 4.12 patched with cherry-picked commit b5e8b3b (2.06 MB, application/octet-stream)
2014-08-25 20:54 UTC, Elias Ross
no flags Details


Links
System ID Priority Status Summary Last Updated
Red Hat Bugzilla 1116345 None None None Never

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@redhat.com>
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


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