Bug 800141

Summary: a NullPointerException (NPE) occurs when "discovery -f" Agent prompt command is run when the Agent is not connected to the Server (i.e. not in "sending" mode)
Product: [Other] RHQ Project Reporter: Ian Springer <ian.springer>
Component: AgentAssignee: Charles Crouch <ccrouch>
Status: CLOSED CURRENTRELEASE QA Contact: Mike Foley <mfoley>
Severity: high Docs Contact:
Priority: medium    
Version: 4.2CC: ccrouch, hbrock, hrupp, skondkar
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-09-03 17:00:03 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Ian Springer 2012-03-05 20:10:20 UTC
started> discovery -f
Full discovery run in [2,119] ms
=== Server Scan Inventory Report ===
Start Time:     Mar 5, 2012 2:24:57 PM
Finish Time:    Mar 5, 2012 2:24:57 PM
Resource Count: 2


Failed to execute prompt command [discovery -f]. Cause: java.lang.NullPointerException:null

---

And here's the relevant lines from the Agent log:

2012-03-05 14:24:59,628 ERROR [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Error running runtime report
java.lang.IllegalStateException: The sender object is currently not sending commands now. Command not sent: [Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{invocation=NameBasedInvocation[mergeInventoryReport], targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService}]]
	at org.rhq.enterprise.communications.command.client.ClientCommandSender.sendSynch(ClientCommandSender.java:631)
	at org.rhq.enterprise.communications.command.client.ClientRemotePojoFactory$RemotePojoProxyHandler.invoke(ClientRemotePojoFactory.java:407)
	at $Proxy2.mergeInventoryReport(Unknown Source)
	at org.rhq.core.pc.inventory.InventoryManager.handleReport(InventoryManager.java:996)
	at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:119)
	at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:55)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)
2012-03-05 14:24:59,630 DEBUG [RHQ Agent Prompt Input Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.command-failure-stack-trace}Command failure stack trace follows:
java.lang.NullPointerException
	at org.rhq.enterprise.agent.promptcmd.DiscoveryPromptCommand.printInventoryReport(DiscoveryPromptCommand.java:398)
	at org.rhq.enterprise.agent.promptcmd.DiscoveryPromptCommand.processCommand(DiscoveryPromptCommand.java:214)
	at org.rhq.enterprise.agent.promptcmd.DiscoveryPromptCommand.execute(DiscoveryPromptCommand.java:95)
	at org.rhq.enterprise.agent.AgentMain.executePromptCommand(AgentMain.java:2878)
	at org.rhq.enterprise.agent.AgentMain$5.run(AgentMain.java:2786)
	at java.lang.Thread.run(Thread.java:662)

Comment 1 Ian Springer 2012-03-05 20:30:47 UTC
Fixed in master: http://git.fedorahosted.org/git/?p=rhq/rhq.git;a=commitdiff;h=09be553 

The NPE is fixed, and we now print a note warning the user the reports won't get sent to the Server:

started> discovery -f
NOTE: The Agent is not currently connected to the Server, so the discovery reports will not be sent to the Server.
Full discovery run in [2,138] ms
=== Server Scan Inventory Report ===
Start Time:     Mar 5, 2012 3:23:18 PM
Finish Time:    Mar 5, 2012 3:23:18 PM
Resource Count: 1


=== Service Scan Inventory Report ===
Start Time:     Mar 5, 2012 3:23:18 PM
Finish Time:    Mar 5, 2012 3:23:20 PM
Resource Count: 0

---

And here's the relevant lines from the Agent log:

2012-03-05 15:23:20,274 WARN  [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Exception caught while executing runtime discovery scan rooted at [platform].
java.lang.IllegalStateException: The sender object is currently not sending commands now. Command not sent: [Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{invocation=NameBasedInvocation[mergeInventoryReport], targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService}]]
	at org.rhq.enterprise.communications.command.client.ClientCommandSender.sendSynch(ClientCommandSender.java:631)
	at org.rhq.enterprise.communications.command.client.ClientRemotePojoFactory$RemotePojoProxyHandler.invoke(ClientRemotePojoFactory.java:407)
	at $Proxy2.mergeInventoryReport(Unknown Source)
	at org.rhq.core.pc.inventory.InventoryManager.handleReport(InventoryManager.java:996)
	at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:121)
	at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:56)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)

Comment 2 Mike Foley 2012-03-12 15:42:36 UTC
per BZ traige (crouch, foley, loleary), medium priority, not targetted for JON 3.1

Comment 3 Sunil Kondkar 2012-04-27 09:39:56 UTC
Verified on build#1416 (Version: 4.4.0-SNAPSHOT Build Number: a3caf42)

NPE does not occur and it prints a note as below:

> discovery -f
NOTE: The Agent is not currently connected to the Server, so the discovery reports will not be sent to the Server.
Full discovery run in [120] ms
=== Server Scan Inventory Report ===
Start Time:         Apr 27, 2012 3:04:17 PM
Finish Time:        Apr 27, 2012 3:04:17 PM
New Resource Count: 8


=== Service Scan Inventory Report ===
Start Time:         Apr 27, 2012 3:04:17 PM
Finish Time:        Apr 27, 2012 3:04:17 PM
New Resource Count: 0

The agent log displays warning message as below:

2012-04-27 15:04:17,468 WARN  [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Exception caught while executing runtime discovery scan rooted at [platform].
java.lang.IllegalStateException: The sender object is currently not sending commands now. Command not sent: [Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{invocation=NameBasedInvocation[mergeInventoryReport], targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService}]]
	at org.rhq.enterprise.communications.command.client.ClientCommandSender.sendSynch(ClientCommandSender.java:631)
	at org.rhq.enterprise.communications.command.client.ClientRemotePojoFactory$RemotePojoProxyHandler.invoke(ClientRemotePojoFactory.java:407)
	at $Proxy3.mergeInventoryReport(Unknown Source)
	at org.rhq.core.pc.inventory.InventoryManager.handleReport(InventoryManager.java:1026)
	at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:121)
	at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:56)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:619)

Comment 6 Heiko W. Rupp 2013-09-03 17:00:03 UTC
Bulk closing of old issues that are in VERIFIED state.