Bug 1628631

Summary: Calltime "Method Execution Time" on ejb3 for EAP 7 in Domain mode doesn't collect
Product: [JBoss] JBoss Operations Network Reporter: Filip Brychta <fbrychta>
Component: Plugin -- JBoss EAP 7Assignee: Michael Burman <miburman>
Status: CLOSED CURRENTRELEASE QA Contact: Filip Brychta <fbrychta>
Severity: urgent Docs Contact:
Priority: urgent    
Version: JON 3.3.6, JON 3.3.5CC: bkramer, dsteigne, fbrychta, mfoley, miburman, spinder
Target Milestone: CR02Keywords: Triaged
Target Release: One-off release   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1361200 Environment:
Last Closed: 2019-01-31 15:54:12 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:    
Bug Blocks: 1543522    
Attachments:
Description Flags
calltime on standalone eap none

Description Filip Brychta 2018-09-13 15:21:36 UTC 
+++ This bug was initially created as a clone of Bug #1361200 +++

Description of problem:
Calltime "Method Execution Time" on ejb3 for EAP 6 in Domain mode doesn't collect and errors in the agent.log with java.lang.UnsupportedOperationException even though statistics are enabled.  The same ejb on an EAP 6 Standalone works perfectly.

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

How reproducible:
Always

Steps to Reproduce:
1. Enable ejb3 statistics on the profile that your managed server is using (my is on default) with jboss-cli:
/profile=default/subsystem=ejb3:write-attribute(name=enable-statistics, value=true)
{
    "outcome" => "success",
    "result" => undefined,
    "server-groups" => {"main-server-group" => {"host" => {"master" => {"server-one" => {"response" => {"outcome" => "success"}}}}}}
}

2. Deploy EJB application, attached my HelloWorldSessionBean.jar.zip
3. Start the EAP server in Domain mode
4. Import that server into JBoss ON, enter valid credentials.
5. Once the ejb application is in inventory, change the metric schedules to collect the calltime Method Execution Time
6. Invoke the EJB method, query via jboss-cli to see values:
/host=master/server=server-one/deployment=HelloWorldSessionBean.jar/subsystem=ejb3/stateless-session-bean=HelloWorldBean:read-resource(include-runtime=true)
{
    "outcome" => "success",
    "result" => {
        "component-class-name" => "HelloWorldBean",
        "declared-roles" => [],
        "execution-time" => 1L,
        "invocations" => 9L,
        "methods" => {"sayHello" => {
            "execution-time" => 1L,
            "invocations" => 9L,
            "wait-time" => 11L
        }},
        "peak-concurrent-invocations" => 1L,
        "pool-available-count" => 20,
        "pool-create-count" => 1,
        "pool-current-size" => 1,
        "pool-max-size" => 20,
        "pool-name" => "slsb-strict-max-pool",
        "pool-remove-count" => 0,
        "run-as-role" => undefined,
        "security-domain" => "other",
        "timers" => [],
        "wait-time" => 11L,
        "service" => undefined
    }
}


Actual results:
No Method Execution Time is collected and the error in the agent.log:

2016-07-28 07:17:21,299 DEBUG [MeasurementManager.collector-1] (rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler)- Call to [org.rhq.modules.plugins.jbossas7.Ejb3BeanRuntimeComponent.getValues()] with args [[org.rhq.core.domain.measurement.MeasurementReport@4f354051, [ScheduledMeasurementInfo[res=23259, name=invocations, sched=180852], ScheduledMeasurementInfo[res=23259, name=__calltime:execution-time, sched=180854], ScheduledMeasurementInfo[res=23259, name=pool-remove-count, sched=180849], ScheduledMeasurementInfo[res=23259, name=pool-available-count, sched=180845], ScheduledMeasurementInfo[res=23259, name=pool-create-count, sched=180846], ScheduledMeasurementInfo[res=23259, name=peak-concurrent-invocations, sched=180850], ScheduledMeasurementInfo[res=23259, name=execution-time, sched=180844], ScheduledMeasurementInfo[res=23259, name=pool-max-size, sched=180848], ScheduledMeasurementInfo[res=23259, name=invocations, sched=180851], ScheduledMeasurementInfo[res=23259, name=execution-time, sched=180843], ScheduledMeasurementInfo[res=23259, name=wait-time, sched=180853], ScheduledMeasurementInfo[res=23259, name=pool-current-size, sched=180847]]]] failed.
java.util.concurrent.ExecutionException: java.lang.UnsupportedOperationException
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:202)
	at org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invokeInNewThreadWithLock(ResourceContainer.java:650)
	at org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invoke(ResourceContainer.java:638)
	at com.sun.proxy.$Proxy102.getValues(Unknown Source)
	at org.rhq.core.pc.measurement.MeasurementCollectorRunner.getValues(MeasurementCollectorRunner.java:131)
	at org.rhq.core.pc.measurement.MeasurementCollectorRunner.call(MeasurementCollectorRunner.java:111)
	at org.rhq.core.pc.measurement.MeasurementManager$MeasurementCollectionRequester.run(MeasurementManager.java:191)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	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.UnsupportedOperationException
	at org.rhq.modules.plugins.jbossas7.BaseComponent.getServerAddress(BaseComponent.java:845)
	at org.rhq.modules.plugins.jbossas7.Ejb3BeanRuntimeComponent.ensureGlobalEJB3StatisticsEnabled(Ejb3BeanRuntimeComponent.java:305)
	at org.rhq.modules.plugins.jbossas7.Ejb3BeanRuntimeComponent.getValues(Ejb3BeanRuntimeComponent.java:129)
	at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.rhq.core.pc.inventory.ResourceContainer$ComponentInvocation.call(ResourceContainer.java:759)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	... 3 more

Expected results:
All enabled ejb3 metrics are collected as they are in EAP Standalone Mode

Additional info:

--- Additional comment from bkramer on 2018-06-14 11:23:28 EDT ---

According to my test, the same issue happens for other EJB stats (and not only for calltime metrics). My log file shows:

*****************************************
2018-06-14 15:24:26,273 DEBUG [MeasurementManager.collector-1] (rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler)- Call to [org.rhq.modules.plugins.wildfly10.Ejb3BeanRuntimeComponent.getValues()] with args [[org.rhq.core.domain.measurement.MeasurementReport@22326a70, [ScheduledMeasurementInfo[res=25141, name=peak-concurrent-invocations, sched=334083], ScheduledMeasurementInfo[res=25141, name=wait-time, sched=334085], ScheduledMeasurementInfo[res=25141, name=invocations, sched=334082], ScheduledMeasurementInfo[res=25141, name=execution-time, sched=334079], ScheduledMeasurementInfo[res=25141, name=execution-time, sched=334080], ScheduledMeasurementInfo[res=25141, name=__calltime:execution-time, sched=334078], ScheduledMeasurementInfo[res=25141, name=invocations, sched=334081]]]] failed.
java.util.concurrent.ExecutionException: java.lang.UnsupportedOperationException
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:206)
	at org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invokeInNewThreadWithLock(ResourceContainer.java:650)
	at org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invoke(ResourceContainer.java:638)
	at com.sun.proxy.$Proxy77.getValues(Unknown Source)
	at org.rhq.core.pc.measurement.MeasurementCollectorRunner.getValues(MeasurementCollectorRunner.java:131)
	at org.rhq.core.pc.measurement.MeasurementCollectorRunner.call(MeasurementCollectorRunner.java:111)
	at org.rhq.core.pc.measurement.MeasurementManager$MeasurementCollectionRequester.run(MeasurementManager.java:191)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.UnsupportedOperationException
	at org.rhq.modules.plugins.wildfly10.BaseComponent.getServerAddress(BaseComponent.java:845)
	at org.rhq.modules.plugins.wildfly10.Ejb3BeanRuntimeComponent.ensureGlobalEJB3StatisticsEnabled(Ejb3BeanRuntimeComponent.java:305)
	at org.rhq.modules.plugins.wildfly10.Ejb3BeanRuntimeComponent.getValues(Ejb3BeanRuntimeComponent.java:129)
	at sun.reflect.GeneratedMethodAccessor102.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.rhq.core.pc.inventory.ResourceContainer$ComponentInvocation.call(ResourceContainer.java:759)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	... 3 more
2018-06-14 15:24:26,273 WARN  [MeasurementManager.collector-1] (rhq.core.pc.measurement.MeasurementCollectorRunner)- Failure to collect measurement data for Resource[id=25141, uuid=4ab1128d-9250-40e6-80f8-eb01cf984a96, type={EAP7}Singleton Bean Runtime, key=host=master,server=server-two,deployment=ejb31-timer.jar,subsystem=ejb3,singleton-bean=SimpleScheduleSingletonTimerBean, name=SimpleScheduleSingletonTimerBean, parent=ejb3], requests=[ScheduledMeasurementInfo[res=25141, name=peak-concurrent-invocations, sched=334083], ScheduledMeasurementInfo[res=25141, name=wait-time, sched=334085], ScheduledMeasurementInfo[res=25141, name=invocations, sched=334082], ScheduledMeasurementInfo[res=25141, name=execution-time, sched=334079], ScheduledMeasurementInfo[res=25141, name=execution-time, sched=334080], ScheduledMeasurementInfo[res=25141, name=__calltime:execution-time, sched=334078], ScheduledMeasurementInfo[res=25141, name=invocations, sched=334081]], report.size()=13
java.lang.UnsupportedOperationException
	at org.rhq.modules.plugins.wildfly10.BaseComponent.getServerAddress(BaseComponent.java:845)
	at org.rhq.modules.plugins.wildfly10.Ejb3BeanRuntimeComponent.ensureGlobalEJB3StatisticsEnabled(Ejb3BeanRuntimeComponent.java:305)
	at org.rhq.modules.plugins.wildfly10.Ejb3BeanRuntimeComponent.getValues(Ejb3BeanRuntimeComponent.java:129)
	at sun.reflect.GeneratedMethodAccessor102.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.rhq.core.pc.inventory.ResourceContainer$ComponentInvocation.call(ResourceContainer.java:759)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

*****************************************
Comment 1 Michael Burman 2018-11-07 18:05:03 UTC 
Fixed in the master, see BZ 1361200 for explanation:

commit 2b018fadf6adaaee99ab2d57d08a6525bc39b512 (HEAD -> master)
Author: Michael Burman <miburman>
Date:   Wed Nov 7 20:04:10 2018 +0200

    [BZ 1628631] Fetch ManagedASComponent before trying to access getServerAddress() if running under HostController
Comment 3 Simeon Pinder 2018-11-21 11:55:18 UTC 
Moving to ON_QA. See https://bugzilla.redhat.com/show_bug.cgi?id=1543522#c1 for test setup gory details.
Comment 7 Filip Brychta 2018-11-29 08:37:37 UTC 
Created attachment 1509756 [details]
calltime on standalone eap
Comment 8 Michael Burman 2018-11-30 14:08:09 UTC 
In the master, for both tickets (this and the one for EAP6 also):

commit 8f7f6be45ef25acf3823fc69a78f36b46b203b6d (HEAD -> master)
Author: Michael Burman <miburman>
Date:   Fri Nov 30 16:07:15 2018 +0200

    [BZ 1628631] [BZ 1361200] Managed server requires different path for server start time than standalone
Comment 11 Filip Brychta 2018-12-13 12:47:36 UTC 
Verified on CR02 for both standalone and domain