Bug 644871 - NPE in agent - after --cleanconfig and "failed to authentize"
Summary: NPE in agent - after --cleanconfig and "failed to authentize"
Keywords:
Status: NEW
Alias: None
Product: RHQ Project
Classification: Other
Component: Agent
Version: 3.0.1
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
: ---
Assignee: Nobody
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks: 1114672
TreeView+ depends on / blocked
 
Reported: 2010-10-20 14:00 UTC by Ondřej Žižka
Modified: 2022-03-31 04:28 UTC (History)
3 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2014-06-27 21:11:57 UTC
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Knowledge Base (Legacy) 53660 0 None None None Never

Description Ondřej Žižka 2010-10-20 14:00:48 UTC
Happened when I did:

1) Have two RHEL 6 systems
1) Install EAP 5.1.0.GA (CR3.5)  noauth
2) Install JON 3.0.0.GA + all JOPR plugins
3) Run the agent
4) Inventorize that EAP
5) Stop the agent
6) Run the agent --cleanconfig
7) The agent's log shown the following:


[hudson@stacks2 rhel6]$ rhq-agent/bin/rhq-agent.sh --cleanconfig
RHQ 3.0.0.GA [8fb6059] (Wed Jul 28 15:17:44 EDT 2010)
Answer the following questions to setup this RHQ Agent instance.
- After each prompt, a default value will appear in square brackets.
  If you press the ENTER key without providing any value,
  the new preference value will be set to that default value.
- If you wish to rely on the system internal default value and
  not define any preference value, enter '!*'.
- If you wish to stop before finishing all the questions but still
  retain those preferences you already set, enter '!+'.
- If you wish to cancel before finishing all the questions and revert
  all preferences back to their original values, enter '!-'.
- If you need help for a particular preference, enter '!?'.

Agent Name [stacks2.mw.lab.eng.bos.redhat.com] :
Agent Hostname or IP Address [!*] :
Agent Port [16163] :
RHQ Server Hostname or IP Address [10.16.90.25] : stacks4.mw.lab.eng.bos.redhat.com
RHQ Server Port [7080] :
The setup has been completed for the preferences at node [/rhq-agent/default].
>
>
> discovery --full --verbose
Full discovery run in [384] ms
=== Server Scan Inventory Report ===
Start Time:     Oct 20, 2010 9:50:40 AM
Finish Time:    Oct 20, 2010 9:50:40 AM
Resource Count: 4

Resource: Resource[id=0, type=Linux, key=stacks2.mw.lab.eng.bos.redhat.com, name=stacks2.mw.lab.eng.bos.redhat.com, parent=<null>, version=Linux 2.6.32-71.el6.i686]
Error: org.rhq.enterprise.communications.command.server.AuthenticationException:Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=stacks2.mw.lab.eng.bos.redhat.com, rhq.security-token=x9GFkjII3bRcS8d321LLOo8wBQaTkxUS8dCPvEsr+97GTml7N7M7zzCWNUolGtu/z74=, rhq.externalizable-strategy=AGENT, rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService, invocation=NameBasedInvocation[mergeInventoryReport]}]

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




------------------------------------------------------------------------
relevant last lines of rhq-agent/logs/agent.log :


2010-10-20 09:50:41,188 WARN  [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Exception caught while running server discovery
org.rhq.enterprise.communications.command.server.AuthenticationException: Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=stacks2.mw.lab.eng.bos.redhat.com, rhq.security-token=x9GFkjII3bRcS8d321LLOo8wBQaTkxUS8dCPvEsr+97GTml7N7M7zzCWNUolGtu/z74=, rhq.externalizable-strategy=AGENT, rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService, invocation=NameBasedInvocation[mergeInventoryReport]}]
        at org.rhq.enterprise.communications.command.server.CommandProcessor.handleIncomingInvocationRequest(CommandProcessor.java:259)
        at org.rhq.enterprise.communications.command.server.CommandProcessor.invoke(CommandProcessor.java:184)
        at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:809)
        at org.jboss.remoting.transport.servlet.ServletServerInvoker.processRequest(ServletServerInvoker.java:232)
        at sun.reflect.GeneratedMethodAccessor944.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:592)
        at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
        at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
        at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
        at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
        at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
        at javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:201)
        at $Proxy425.processRequest(Unknown Source)
        at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.processRequest(ServerInvokerServlet.java:128)
        at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.doPost(ServerInvokerServlet.java:157)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.rhq.helpers.rtfilter.filter.RtFilter.doFilter(RtFilter.java:124)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
        at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
        at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
        at java.lang.Thread.run(Thread.java:595)
2010-10-20 09:50:41,191 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Found 1 servers.
2010-10-20 09:50:41,191 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Running runtime discovery scan rooted at [platform]
2010-10-20 09:50:41,191 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Scanned [0] servers and found [0] total descendant Resources.
2010-10-20 09:50:41,191 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Sending [runtime] inventory report to Server...
2010-10-20 09:50:41,207 ERROR [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Error running runtime report
org.rhq.enterprise.communications.command.server.AuthenticationException: Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=stacks2.mw.lab.eng.bos.redhat.com, rhq.security-token=x9GFkjII3bRcS8d321LLOo8wBQaTkxUS8dCPvEsr+97GTml7N7M7zzCWNUolGtu/z74=, rhq.externalizable-strategy=AGENT, rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService, invocation=NameBasedInvocation[mergeInventoryReport]}]
        at org.rhq.enterprise.communications.command.server.CommandProcessor.handleIncomingInvocationRequest(CommandProcessor.java:259)
        at org.rhq.enterprise.communications.command.server.CommandProcessor.invoke(CommandProcessor.java:184)
        at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:809)
        at org.jboss.remoting.transport.servlet.ServletServerInvoker.processRequest(ServletServerInvoker.java:232)
        at sun.reflect.GeneratedMethodAccessor944.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:592)
        at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
        at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
        at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
        at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
        at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
        at javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:201)
        at $Proxy425.processRequest(Unknown Source)
        at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.processRequest(ServerInvokerServlet.java:128)
        at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.doPost(ServerInvokerServlet.java:157)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.rhq.helpers.rtfilter.filter.RtFilter.doFilter(RtFilter.java:124)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
        at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
        at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
        at java.lang.Thread.run(Thread.java:595)
                                                                     

------------------------------------------------------------------
$ tail -10f jon-server-2.4.0.GA/logs/rhq-server-log4j.log 

2010-10-20 09:30:41,114 WARN  [org.hibernate.hql.ast.QueryTranslatorImpl] firstResult/maxResults specified with collection fetch; applying in memory!
2010-10-20 09:31:00,583 INFO  [org.rhq.enterprise.server.discovery.DiscoveryServerServiceImpl] Processed AV:[stacks2.mw.lab.eng.bos.redhat.com][2][full] - need full=[false] in (20)ms
2010-10-20 09:31:02,657 INFO  [org.rhq.enterprise.server.discovery.DiscoveryServerServiceImpl] Processed AV:[stacks2.mw.lab.eng.bos.redhat.com][16][full] - need full=[false] in (91)ms
2010-10-20 09:31:28,739 INFO  [org.rhq.enterprise.server.cloud.instance.CacheConsistencyManagerBean] stacks4.mw.lab.eng.bos.redhat.com took [57]ms to reload cache for 1 agents
2010-10-20 09:33:09,866 INFO  [org.rhq.enterprise.server.scheduler.jobs.AsyncResourceDeleteJob] Async resource deletion - 18 successful, 0 failed, took [2615] ms
2010-10-20 09:33:38,705 INFO  [org.rhq.enterprise.server.core.AgentManagerBean] Agent with name [stacks2.mw.lab.eng.bos.redhat.com] just went down
2010-10-20 09:41:36,733 INFO  [org.rhq.enterprise.server.core.CoreServerServiceImpl] Got agent registration request for existing agent: stacks2.mw.lab.eng.bos.redhat.com[10.16.90.25:16163][3.0.0.GA(8fb6059)] - Will not regenerate a new token
2010-10-20 09:41:37,082 INFO  [org.rhq.enterprise.server.core.CoreServerServiceImpl] Agent [stacks2.mw.lab.eng.bos.redhat.com][3.0.0.GA(8fb6059)] would like to connect to this server
2010-10-20 09:41:37,166 INFO  [org.rhq.enterprise.server.core.CoreServerServiceImpl] Agent [stacks2.mw.lab.eng.bos.redhat.com] has connected to this server at Wed Oct 20 09:41:37 EDT 2010
2010-10-20 09:41:45,503 WARN  [org.hibernate.hql.ast.QueryTranslatorImpl] firstResult/maxResults specified with collection fetch; applying in memory!
2010-10-20 09:41:48,316 INFO  [org.rhq.enterprise.server.resource.ResourceManagerBean] User [org.rhq.core.domain.auth.Subject[id=2,name=rhqadmin]] is marking resource [Resource[id=10025, type=Linux, key=stacks2.mw.lab.eng.bos.redhat.com, name=stacks2.mw.lab.eng.bos.redhat.com, parent=<null>, version=Linux 2.6.32-71.el6.i686]] for asynchronous uninventory
2010-10-20 09:41:48,396 WARN  [org.rhq.enterprise.server.core.comm.ServerCommunicationsService] {Failed to truncate/delete spool for deleted agent [Agent[id=10011,name=stacks2.mw.lab.eng.bos.redhat.com,address=10.16.90.25,port=16163,remote-endpoint=socket://10.16.90.25:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200,last-availability-report=1287581462572]] please manually remove the file: null}!!! missing resource message key=[Failed to truncate/delete spool for deleted agent [Agent[id=10011,name=stacks2.mw.lab.eng.bos.redhat.com,address=10.16.90.25,port=16163,remote-endpoint=socket://10.16.90.25:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200,last-availability-report=1287581462572]] please manually remove the file: null] args=[java.lang.NullPointerException]
2010-10-20 09:41:48,396 INFO  [org.rhq.enterprise.server.core.AgentManagerBean] Removed agent: Agent[id=10011,name=stacks2.mw.lab.eng.bos.redhat.com,address=10.16.90.25,port=16163,remote-endpoint=socket://10.16.90.25:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200,last-availability-report=1287581462572]
2010-10-20 09:41:51,601 WARN  [org.hibernate.hql.ast.QueryTranslatorImpl] firstResult/maxResults specified with collection fetch; applying in memory!
2010-10-20 09:41:56,987 ERROR [org.rhq.enterprise.server.discovery.DiscoveryServerServiceImpl] Received invalid inventory report from agent [Agent[id=0,name=stacks2.mw.lab.eng.bos.redhat.com,address=null,port=0,remote-endpoint=null,last-availability-report=null]]: Unknown Agent named [stacks2.mw.lab.eng.bos.redhat.com] sent an inventory report - that report will be ignored
2010-10-20 09:42:05,874 ERROR [org.rhq.enterprise.server.discovery.DiscoveryServerServiceImpl] Received invalid inventory report from agent [Agent[id=0,name=stacks2.mw.lab.eng.bos.redhat.com,address=null,port=0,remote-endpoint=null,last-availability-report=null]]: Unknown Agent named [stacks2.mw.lab.eng.bos.redhat.com] sent an inventory report - that report will be ignored
2010-10-20 09:43:09,553 INFO  [org.rhq.enterprise.server.scheduler.jobs.AsyncResourceDeleteJob] Async resource deletion - 18 successful, 0 failed, took [2300] ms
2010-10-20 09:50:41,183 WARN  [org.rhq.enterprise.communications.command.server.CommandProcessor] {CommandProcessor.failed-authentication}Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=stacks2.mw.lab.eng.bos.redhat.com, rhq.security-token=x9GFkjII3bRcS8d321LLOo8wBQaTkxUS8dCPvEsr+97GTml7N7M7zzCWNUolGtu/z74=, rhq.externalizable-strategy=AGENT, rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService, invocation=NameBasedInvocation[mergeInventoryReport]}]
2010-10-20 09:50:41,202 WARN  [org.rhq.enterprise.communications.command.server.CommandProcessor] {CommandProcessor.failed-authentication}Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=stacks2.mw.lab.eng.bos.redhat.com, rhq.security-token=x9GFkjII3bRcS8d321LLOo8wBQaTkxUS8dCPvEsr+97GTml7N7M7zzCWNUolGtu/z74=, rhq.externalizable-strategy=AGENT, rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService, invocation=NameBasedInvocation[mergeInventoryReport]}]
2010-10-20 09:56:57,347 WARN  [org.rhq.enterprise.communications.command.server.CommandProcessor] {CommandProcessor.failed-authentication}Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=stacks2.mw.lab.eng.bos.redhat.com, rhq.security-token=x9GFkjII3bRcS8d321LLOo8wBQaTkxUS8dCPvEsr+97GTml7N7M7zzCWNUolGtu/z74=, rhq.externalizable-strategy=AGENT, rhq.timeout=1800000, rhq.send-throttle=true}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService, invocation=NameBasedInvocation[mergeInventoryReport]}]

Comment 1 Ondřej Žižka 2011-03-12 03:21:01 UTC
Reproduced with 2.4.1
Probably misconfiguration, but I can't remember what was the problem.

Comment 2 Ondřej Žižka 2011-03-12 03:22:50 UTC
JON FAQ suggests to re-run agent with --clean,
http://docs.redhat.com/docs/en-US/JBoss_Operations_Network/2.3/html/FAQ/chap-FAQs-Chapter.html
but that doesn't help. After filling the information, it gets to the same state.

Comment 3 Jay Shaughnessy 2014-06-27 21:13:43 UTC
Uhm, just noticed the recent activity, re-opening and asking for a GSS update as to whether this is still relevant.

Comment 4 bkramer 2014-06-30 07:26:02 UTC
Jay, yes it seems to be the case. This issue customer reported in the JBoss ON 3.1.2 - ticket 01100483.

Comment 5 Larry O'Leary 2014-06-30 14:28:21 UTC
@bkramer, please capture a product bug for customer related cases.


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