Bug 608597

Summary: Agent can not sync to server : PersistentMap not found
Product: [Other] RHQ Project Reporter: Heiko W. Rupp <hrupp>
Component: Communications SubsystemAssignee: RHQ Project Maintainer <rhq-maint>
Status: CLOSED CURRENTRELEASE QA Contact: Corey Welton <cwelton>
Severity: high Docs Contact:
Priority: urgent    
Version: 3.0.0CC: mazz
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 2.4 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2010-08-12 16:48:38 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 Heiko W. Rupp 2010-06-28 09:07:53 UTC
Re-started the agent with --purgedata. Since then it can not sync the re-discovered resources with the server. Log shows ClassNotFoundExceptions for hibernate PersistentMap:

2010-06-28 10:52:58,721 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server invento
ry...
2010-06-28 10:52:58,722 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Got unknown resource: 10001
2010-06-28 10:52:58,723 INFO  [ClientCommandSenderTask Timer Thread #0] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.not-sending-dup-connect}Not sending another connect message since one was recently sent: [servlet://snert:7080/jboss-remoting-servlet-invoker/ServerInvokerServlet@Mon Jun 
28 10:52:56 CEST 2010]
2010-06-28 10:53:01,305 INFO  [RHQ Agent Prompt Input Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.prompt-command-invoked}Prompt command invoked: [inventory]
2010-06-28 10:53:05,319 WARN  [ClientCommandSenderTask Timer Thread #0] (org.rhq.enterprise.agent.FailoverFailureCallback)- {AgentMain.too-many-failover-attempts}Too many failover attempts have been made [1]. Exception that triggered the failover: [org.jboss.remoting.CannotConnectException: Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200.]
2010-06-28 10:53:05,321 ERROR [InventoryManager.discovery-1] (enterprise.communications.command.client.ClientCommandSenderTask)- {ClientCommandSen
derTask.send-failed}Failed to send command [Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=snert, rhq.externalizable
-strategy=AGENT, rhq.security-token=rWHQs5jVwbzJBX/okOaTwt46Tb0FkIsxtzqVoh6yvBUyO3iZKmaoa2kB6ChI6aEmqhE=, rhq.send-throttle=true}]; params=[{invocation=NameBasedInvocation[getResources], targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService}]]. Cause: org.jboss.remoting.CannotConnectException:Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200. -> java.lang.ClassNotFoundException:org.hibernate.collection.PersistentMap. Cause: org.jboss.remoting.CannotConnectException: Can not connect http client invoker. org
.hibernate.collection.PersistentMap. Response: OK/200.
2010-06-28 10:53:05,322 WARN  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Failed to synchronize local inventory with 
Server inventory for Resource [10001] and its descendants: Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200.
2010-06-28 10:53:05,322 WARN  [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Exception caught while running server discovery
java.lang.RuntimeException: org.jboss.remoting.CannotConnectException: Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200.
        at org.rhq.core.pc.inventory.InventoryManager.synchInventory(InventoryManager.java:944)
        at org.rhq.core.pc.inventory.InventoryManager.handleReport(InventoryManager.java:891)
        at org.rhq.core.pc.inventory.AutoDiscoveryExecutor.call(AutoDiscoveryExecutor.java:121)
        at org.rhq.core.pc.inventory.AutoDiscoveryExecutor.run(AutoDiscoveryExecutor.java:92)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
        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:637)
Caused by: org.jboss.remoting.CannotConnectException: Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200.
        at org.jboss.remoting.transport.http.HTTPClientInvoker.useHttpURLConnection(HTTPClientInvoker.java:348)
        at org.jboss.remoting.transport.http.HTTPClientInvoker.transport(HTTPClientInvoker.java:137)
        at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
        at org.jboss.remoting.Client.invoke(Client.java:1634)
        at org.jboss.remoting.Client.invoke(Client.java:548)
        at org.rhq.enterprise.communications.command.client.JBossRemotingRemoteCommunicator.rawSend(JBossRemotingRemoteCommunicator.java:514)
        at org.rhq.enterprise.communications.command.client.JBossRemotingRemoteCommunicator.sendWithoutCallbacks(JBossRemotingRemoteCommunicator.java:456)
        at org.rhq.enterprise.communications.command.client.JBossRemotingRemoteCommunicator.sendWithoutInitializeCallback(JBossRemotingRemoteCommunicator.java:475)
        at org.rhq.enterprise.communications.command.client.JBossRemotingRemoteCommunicator.send(JBossRemotingRemoteCommunicator.java:496)
        at org.rhq.enterprise.communications.command.client.AbstractCommandClient.invoke(AbstractCommandClient.java:143)
        at org.rhq.enterprise.communications.command.client.ClientCommandSender.send(ClientCommandSender.java:1087)
        at org.rhq.enterprise.communications.command.client.ClientCommandSenderTask.send(ClientCommandSenderTask.java:229)
        at org.rhq.enterprise.communications.command.client.ClientCommandSenderTask.call(ClientCommandSenderTask.java:107)
        at org.rhq.enterprise.communications.command.client.ClientCommandSenderTask.call(ClientCommandSenderTask.java:55)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        ... 3 more
Caused by: java.lang.ClassNotFoundException: org.hibernate.collection.PersistentMap
        at org.jboss.remoting.serialization.ClassLoaderUtility.loadClass(ClassLoaderUtility.java:82)
        at org.jboss.remoting.loading.RemotingClassLoader.loadClass(RemotingClassLoader.java:76)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:247)
        at org.jboss.remoting.loading.ObjectInputStreamWithClassLoader.resolveClass(ObjectInputStreamWithClassLoader.java:174)
        at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1575)
        at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1496)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1732)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
        at java.util.HashSet.readObject(HashSet.java:291)
        at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:974)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1849)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
        at java.util.HashSet.readObject(HashSet.java:291)
        at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:974)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1849)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
        at java.util.HashSet.readObject(HashSet.java:291)
        at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:974)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1849)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1947)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1871)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1753)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
        at org.jboss.remoting.serialization.impl.java.JavaSerializationManager.receiveObjectVersion2_2(JavaSerializationManager.java:239)
        at org.jboss.remoting.serialization.impl.java.JavaSerializationManager.receiveObject(JavaSerializationManager.java:133)
        at org.jboss.remoting.marshal.serializable.SerializableUnMarshaller.read(SerializableUnMarshaller.java:120)
        at org.jboss.remoting.marshal.http.HTTPUnMarshaller.read(HTTPUnMarshaller.java:69)
        at org.jboss.remoting.transport.http.HTTPClientInvoker.readResponse(HTTPClientInvoker.java:516)
        at org.jboss.remoting.transport.http.HTTPClientInvoker.useHttpURLConnection(HTTPClientInvoker.java:307)
        ... 18 more

Comment 1 Heiko W. Rupp 2010-06-28 10:04:23 UTC
This PeristentMap is indirectly coming from Configuration.class

Comment 2 Heiko W. Rupp 2010-06-28 14:29:26 UTC
Agent log (notice the 'unknown resource' ) 

2010-06-28 16:26:37,764 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server invento
ry...
2010-06-28 16:26:37,765 INFO  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Got unknown resource: 10001
2010-06-28 16:26:43,078 WARN  [ClientCommandSenderTask Timer Thread #0] (org.rhq.enterprise.agent.FailoverFailureCallback)- {AgentMain.too-many-fa
ilover-attempts}Too many failover attempts have been made [1]. Exception that triggered the failover: [org.jboss.remoting.CannotConnectException: 
Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200.]
2010-06-28 16:26:43,079 ERROR [InventoryManager.discovery-1] (enterprise.communications.command.client.ClientCommandSenderTask)- {ClientCommandSen
derTask.send-failed}Failed to send command [Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=snert, rhq.externalizable
-strategy=AGENT, rhq.security-token=ioMuLI52d3baqlwmr8NJRg79Lu9K8Ih1SusXw5ALcERHCCVDMgEcOZrkhxBW0flPSJs=, rhq.send-throttle=true}]; params=[{invoc
ation=NameBasedInvocation[getResources], targetInterfaceName=org.rhq.core.clientapi.server.discovery.DiscoveryServerService}]]. Cause: org.jboss.r
emoting.CannotConnectException:Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: OK/200. -> java.lang.ClassNo
tFoundException:org.hibernate.collection.PersistentMap. Cause: org.jboss.remoting.CannotConnectException: Can not connect http client invoker. org
.hibernate.collection.PersistentMap. Response: OK/200.
2010-06-28 16:26:43,079 WARN  [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Failed to synchronize local inventory with 
Server inventory for Resource [10001] and its descendants: Can not connect http client invoker. org.hibernate.collection.PersistentMap. Response: 
OK/200.
2010-06-28 16:26:43,079 ERROR [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Error running runtime report
java.lang.RuntimeException: org.jboss.remoting.CannotConnectException: Can not connect http client invoker. org.hibernate.collection.PersistentMap
. Response: OK/200.
        at org.rhq.core.pc.inventory.InventoryManager.synchInventory(InventoryManager.java:944)
        at org.rhq.core.pc.inventory.InventoryManager.handleReport(InventoryManager.java:891)
        at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:119)
        at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.run(RuntimeDiscoveryExecutor.java:87)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)


Same time server log



2010-06-28 16:26:34,298 INFO  [org.rhq.enterprise.server.core.CoreServerServiceImpl] Agent [snert] has connected to this server at Mon Jun 28 16:26:34 CEST 2010
2010-06-28 16:26:34,298 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.complete}<<=CoreServerService.connectAgent|?|success
2010-06-28 16:26:34,303 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.initiate}<==DiscoveryServerService.getResources|?
2010-06-28 16:26:36,055 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.complete}<<=DiscoveryServerService.getResources|?|success
2010-06-28 16:26:37,408 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.initiate}<==DiscoveryServerService.mergeInventoryReport|?
2010-06-28 16:26:37,738 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.complete}<<=DiscoveryServerService.mergeInventoryReport|?|success
2010-06-28 16:26:37,767 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.initiate}<==DiscoveryServerService.getResources|?
2010-06-28 16:26:39,682 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.complete}<<=DiscoveryServerService.getResources|?|success
2010-06-28 16:26:40,449 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.initiate}<==DiscoveryServerService.getResources|?
2010-06-28 16:26:42,257 TRACE [org.rhq.enterprise.communications.command.server.IncomingCommandTrace] {recv.complete}<<=DiscoveryServerService.getResources|?|success

Comment 3 Heiko W. Rupp 2010-06-28 14:33:56 UTC
pilhuhn: and this calls org.rhq.enterprise.server.discovery.DiscoveryServerServiceImpl#convertToPojoResource
[16:31] pilhuhn: and then pojoResource.setPluginConfiguration(resource.getPluginConfiguration());
[16:32] pilhuhn: after this the pojoResource contains Javassist proxies - which may end up as those hibernate Map

Comment 4 John Mazzitelli 2010-06-28 18:27:03 UTC
looks like DiscoveryServerServiceImpl doesn't take a deep copy of the plugin configuration.

here's a potential patch:

@@ -31,2 +31,3 @@ import org.rhq.core.clientapi.server.discovery.InventoryReport;
 import org.rhq.core.domain.auth.Subject;
+import org.rhq.core.domain.configuration.Configuration;
 import org.rhq.core.domain.discovery.AvailabilityReport;
@@ -185,3 +186,7 @@ public class DiscoveryServerServiceImpl implements DiscoveryServerService {
         pojoResource.setInventoryStatus(resource.getInventoryStatus());
-        pojoResource.setPluginConfiguration(resource.getPluginConfiguration());
+        Configuration pcCopy = resource.getPluginConfiguration();
+        if (pcCopy != null) {
+            pcCopy = pcCopy.deepCopy();
+        }
+        pojoResource.setPluginConfiguration(pcCopy);
         pojoResource.setName(resource.getName());

Comment 5 Heiko W. Rupp 2010-06-28 18:34:32 UTC
Just for completeness: Inventory on agent when this error happens:

> inventory
+ Resource[id=0, type=Mac OS X, key=snert, name=snert, parent=<null>, version=MacOSX 10.6.4] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)
   + Resource[id=0, type=File Template Bundle Handler Server, key=file-template-bundle, name=File Template Bundle Handler, parent=snert, version=3.0.0-SNAPSHOT] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)
   + Resource[id=0, type=JBossAS Server, key=/im/dev-container/jbossas/server/default, name=snert RHQ Server, parent=snert, version=4.2.3.GA] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)
   + Resource[id=0, type=RHQ Agent, key=RHQ Agent, name=RHQ Agent, parent=snert, version=3.0.0-SNAPSHOT] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)
   + Resource[id=0, type=Ant Bundle Handler Server, key=ant-bundle, name=Ant Bundle Handler, parent=snert, version=3.0.0-SNAPSHOT] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)
   + Resource[id=0, type=server-d, key=server-d-0, name=server-d-0, parent=snert, version=1.0] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)
   + Resource[id=0, type=Postfix Server, key=/etc/postfix/main.cf, name=snert, parent=snert] (sync=NEW, state=STOPPED, avail=UNKNOWN, sched=0/0)

Total Resources: 7 (1 Platforms, 6 Servers, 0 Services)

Comment 6 John Mazzitelli 2010-06-28 19:42:16 UTC
commited to release-3.0.0 branch: 358f16a670cdba71c5fa222ee2df72d7aa252a71

I have no idea how to test this. No replication procedures that I know of.

Comment 7 Corey Welton 2010-06-30 17:05:16 UTC
QA Closing - I have not been seeing these messages in the latest build with either "old" or --clean agents.

Comment 8 Corey Welton 2010-08-12 16:48:38 UTC
Mass-closure of verified bugs against JON.