Bug 1028468

Summary: rhq.ear/rhq-core-domain-ejb3.jar#rhqpu resource unavailable
Product: [JBoss] JBoss Operations Network Reporter: Filip Brychta <fbrychta>
Component: Core ServerAssignee: Thomas Segismont <tsegismo>
Status: CLOSED CURRENTRELEASE QA Contact: Filip Brychta <fbrychta>
Severity: medium Docs Contact:
Priority: unspecified    
Version: JON 3.2CC: bkramer, harshada, lzoubek, mfoley, myarboro, tsegismo
Target Milestone: ER02   
Target Release: JON 3.3.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-12-11 13:59:35 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:
Attachments:
Description Flags
resource tree screen shot
none
screenshot showing availability none

Description Filip Brychta 2013-11-08 14:18:58 UTC
Created attachment 821644 [details]
resource tree screen shot

Description of problem:
Resource rhq.ear/rhq-core-domain-ejb3.jar#rhqpu (see resource tree screen shot) is unavailable and rhq server is throwing following exception:

09:14:00,024 ERROR [org.jboss.as.controller.management-operation] (HttpManagementService-threads - 14) JBAS014612: Operation ("read-resource") failed - address: ([
    {"deployment" => "rhq.ear"},
    {"subdeployment" => "rhq-core-domain-ejb3.jar"},
    {"subsystem" => "jpa"},
    {"hibernate-persistence-unit" => "rhq.ear/rhq-core-domain-ejb3.jar#rhqpu"}
]): java.lang.StringIndexOutOfBoundsException: String index out of range: 0
	at java.lang.String.charAt(String.java:694) [rt.jar:1.6.0_24]
	at org.jboss.as.controller.PathElement.<init>(PathElement.java:103) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.PathElement.pathElement(PathElement.java:68) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.registry.PlaceholderResource$PlaceholderResourceEntry.<init>(PlaceholderResource.java:142) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.jpa.hibernate4.management.HibernateStatisticsResource.getChildren(HibernateStatisticsResource.java:219)
	at org.jboss.as.controller.OperationContextImpl.readResourceFromRoot(OperationContextImpl.java:509) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.OperationContextImpl.readResource(OperationContextImpl.java:466) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.operations.global.ReadResourceHandler.nullSafeReadResource(ReadResourceHandler.java:298) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.operations.global.ReadResourceHandler.doExecute(ReadResourceHandler.java:158) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.operations.global.GlobalOperationHandlers$AbstractMultiTargetHandler.execute(GlobalOperationHandlers.java:264) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:440) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.AbstractOperationContext.doCompleteStep(AbstractOperationContext.java:322) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.AbstractOperationContext.completeStepInternal(AbstractOperationContext.java:229) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:224) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:194) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:115) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.ModelControllerImpl$3.execute(ModelControllerImpl.java:398) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.controller.ModelControllerImpl$3.execute(ModelControllerImpl.java:388) [jboss-as-controller-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.domain.http.server.DomainApiHandler.processRequest(DomainApiHandler.java:320) [jboss-as-domain-http-interface-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.domain.http.server.DomainApiHandler.doHandle(DomainApiHandler.java:226) [jboss-as-domain-http-interface-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.domain.http.server.DomainApiHandler.handle(DomainApiHandler.java:233) [jboss-as-domain-http-interface-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.domain.http.server.security.SubjectAssociationHandler.handle(SubjectAssociationHandler.java:51) [jboss-as-domain-http-interface-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	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) [jboss-as-domain-http-interface-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	at org.jboss.as.domain.http.server.DmrFailureReadinessFilter.doFilter(DmrFailureReadinessFilter.java:45) [jboss-as-domain-http-interface-7.2.1.Final-redhat-10.jar:7.2.1.Final-redhat-10]
	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:1110) [rt.jar:1.6.0_24]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.6.0_24]
	at java.lang.Thread.run(Thread.java:679) [rt.jar:1.6.0_24]
	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.0.Final-redhat-1.jar:2.1.0.Final-redhat-1]


Version-Release number of selected component (if applicable):
Version :	
3.2.0.ER5
Build Number :	
2cb2bc9:225c796

Unfortunately no repo steps. Any idea what could cause this exception?

Comment 1 Libor Zoubek 2013-11-19 11:19:52 UTC
Created attachment 826013 [details]
screenshot showing availability

I am hitting this issue as well and I might have repro steps: 

keep rhq server running at least 2.7 days

see screenshot2

Comment 3 Filip Brychta 2014-02-17 13:06:58 UTC
Prepared set up which monitors availability of rhq.ear/rhq-core-domain-ejb3.jar#rhqpu. Let's see after a few days.

Comment 4 Filip Brychta 2014-02-20 15:16:15 UTC
The rhq.ear/rhq-core-domain-ejb3.jar#rhqpu resource is still UP after ~3 days -> VERIFIED

Version :	
4.10.0-SNAPSHOT
Build Number :	
c526922

Comment 5 Filip Brychta 2014-02-20 15:21:33 UTC
Ignore comment 4. It applies on RHQ master. I will do it again with JON3.2.1

Comment 6 Filip Brychta 2014-03-06 10:10:29 UTC
The issue is still visible on JON3.2.1.DR2 Build Number :	
d18651a:f535707

TODO: Another retest on JON3.3.x

Comment 8 Filip Brychta 2014-08-27 14:47:36 UTC
Still visible in
Version :	
3.3.0.ER01.1
Build Number :	
9941660:f3aa7e7

The exception from description is not visible in server.log but the resource rhq.ear/rhq-core-domain-ejb3.jar#rhqpu is still down.

Following warning is visible in agent.log:
2014-08-27 10:44:51,836 WARN  [InventoryManager.availability-1] (rhq.core.pc.inventory.AvailabilityExecutor)- Availability collection failed with exception on Resource[id=10235, uuid=980c0b17-b9af-4738-a462-596ae39f730b, type={JBossAS7}Hibernate Persistence Unit, key=deployment=rhq.ear,subdeployment=rhq-core-domain-ejb3.jar,subsystem=jpa,hibernate-persistence-unit=rhq.ear/rhq-core-domain-ejb3.jar#rhqpu, name=rhq.ear/rhq-core-domain-ejb3.jar#rhqpu, parent=jpa], availability will be reported as DOWN, reason=Availability check ran too long [60015ms], canceled for [ResourceContainer[resource=Resource[id=10235, uuid=980c0b17-b9af-4738-a462-596ae39f730b, type={JBossAS7}Hibernate Persistence Unit, key=deployment=rhq.ear,subdeployment=rhq-core-domain-ejb3.jar,subsystem=jpa,hibernate-persistence-unit=rhq.ear/rhq-core-domain-ejb3.jar#rhqpu, name=rhq.ear/rhq-core-domain-ejb3.jar#rhqpu, parent=jpa], syncState=SYNCHRONIZED, componentState=STARTED, avail=DOWN]]; Stack trace includes the timed out thread's stack trace.


Stack trace visible in UI:
org.rhq.core.pc.inventory.TimeoutException: Availability check ran too long [60015ms], canceled for [ResourceContainer[resource=Resource[id=10235, uuid=980c0b17-b9af-4738-a462-596ae39f730b, type={JBossAS7}Hibernate Persistence Unit, key=deployment=rhq.ear,subdeployment=rhq-core-domain-ejb3.jar,subsystem=jpa,hibernate-persistence-unit=rhq.ear/rhq-core-domain-ejb3.jar#rhqpu, name=rhq.ear/rhq-core-domain-ejb3.jar#rhqpu, parent=jpa], syncState=SYNCHRONIZED, componentState=STARTED, avail=DOWN]]; Stack trace includes the timed out thread's stack trace.
	at org.rhq.core.pc.inventory.AvailabilityProxy.getAvailability(AvailabilityProxy.java:187)
	at org.rhq.core.pc.inventory.AvailabilityExecutor.checkInventory(AvailabilityExecutor.java:339)
	at org.rhq.core.pc.inventory.AvailabilityExecutor.startScan(AvailabilityExecutor.java:174)
	at org.rhq.core.pc.inventory.CustomScanRootAvailabilityExecutor.startScan(CustomScanRootAvailabilityExecutor.java:71)
	at org.rhq.core.pc.inventory.AvailabilityExecutor.call(AvailabilityExecutor.java:130)
	at org.rhq.core.pc.inventory.AvailabilityExecutor.call(AvailabilityExecutor.java:60)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
	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)
Caused by: java.lang.Throwable
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:152)
	at java.net.SocketInputStream.read(SocketInputStream.java:122)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:166)
	at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:90)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:281)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:92)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:715)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:520)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
	at org.rhq.modules.plugins.jbossas7.ASConnection.executeRaw(ASConnection.java:301)
	at org.rhq.modules.plugins.jbossas7.ASConnection.execute(ASConnection.java:512)
	at org.rhq.modules.plugins.jbossas7.ASConnection.execute(ASConnection.java:465)
	at org.rhq.modules.plugins.jbossas7.BaseComponent.getAvailability(BaseComponent.java:154)
	at org.rhq.core.pc.inventory.AvailabilityProxy.call(AvailabilityProxy.java:141)
	at org.rhq.core.pc.inventory.AvailabilityProxy.call(AvailabilityProxy.java:50)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	... 3 more

Comment 9 Thomas Segismont 2014-08-27 16:03:22 UTC
Filip, this is not the same stack trace. The stack trace you pasted in Comment 8 is a consequence of the problem described in Bug 1132091 - High CPU usage in hibernate thread (java.util.regex.Pattern$Start.match)

I'm setting the BZ to MODIFIED and target milestone ER02, in case you want to verify this one after Bug 1132091.

Comment 10 Simeon Pinder 2014-09-03 20:31:36 UTC
Moving to ON_QA as available for test with the following brew build:
https://brewweb.devel.redhat.com//buildinfo?buildID=381194

Comment 11 Filip Brychta 2014-09-05 13:24:19 UTC
Verified on
Version :	
3.3.0.ER02
Build Number :	
4fbb183:7da54e2