-
1. Re: monitoring via rhq
galder.zamarreno Aug 2, 2011 11:53 AM (in response to kullmann)Andre, we need a bit more info to narrow down the issue, i.e.
- Version of RHQ server and agent in use
- Verion of Infinispan tested
Finally, if you could enable TRACE on org.infinispan package in the RHQ agent process, then it'd help us better find out what is wrong.
-
2. Re: monitoring via rhq
kullmann Aug 3, 2011 2:06 AM (in response to galder.zamarreno)Hello,
thanks for the quick response and interest in my problem.
And now the informations
infinispan
==========
version 5.0.0.CR7
RHQ-Server
==========
Version 4.0.1
Build Number ecd91b2
GWT VErsion 2.0.4
SmartGWT Version 2.4
RHQ-Agent
=========
>version
Build-Date: Fri May 20 18:41:18 CEST 2011
uild-Jdk: 1.6.0_24
Build-Jdk-Vendor: Sun Microsystems Inc.
Build-Number: ecd91b2
Build-OS-Name: Linux
Build-OS-Version: 2.6.32-71.el6.i686
Module-Name: RHQ Enterprise Agent
Module-Version: 4.0.1
Product-Name: RHQ
Product-Version: 4.0.1
>plugins info
...
infinispan-rhq-plugin.jar
Plugin Name: Infinispan
Display Name: InfinispanPlugin
Last Updated: August 2, 2011 9:14:00 AM CEST
File Size: 1,361,862 bytes
MD5 Hashcode: df6b0a1a9673ab1ba2fba5c30f70459c
...
>inventory
...
+ Resource[id=12201, type=JMX Server, key=6996, name=org.infinispan.server.core.Main (6996), parent=tarc-db.ov.otto.de] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=0/0)
+ Resource[id=12216, type=java.util.logging, key=java.util.logging:type=Logging, name=Logging, parent=org.infinispan.server.core.Main (6996)] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=0/0)
+ Resource[id=12211, type=Operating System, key=java.lang:type=OperatingSystem, name=Operating system information, parent=org.infinispan.server.core.Main (6996)] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=4/5)
+ Resource[id=12213, type=VM Memory System, key=java.lang:type=Memory, name=Memory Subsystem, parent=org.infinispan.server.core.Main (6996)] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=8/9)
+ Resource[id=12217, type=Memory Pool, key=java.lang:name=Code Cache,type=MemoryPool, name=Code Cache, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=6/6)
+ Resource[id=12218, type=Memory Pool, key=java.lang:name=PS Eden Space,type=MemoryPool, name=PS Eden Space, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=6/6)
+ Resource[id=12220, type=Memory Pool, key=java.lang:name=PS Perm Gen,type=MemoryPool, name=PS Perm Gen, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=6/6)
+ Resource[id=12219, type=Memory Pool, key=java.lang:name=PS Old Gen,type=MemoryPool, name=PS Old Gen, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=6/6)
+ Resource[id=12222, type=Garbage Collector, key=java.lang:name=PS Scavenge,type=GarbageCollector, name=PS Scavenge, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=3/5)
+ Resource[id=12223, type=Garbage Collector, key=java.lang:name=PS MarkSweep,type=GarbageCollector, name=PS MarkSweep, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=3/5)
+ Resource[id=12221, type=Memory Pool, key=java.lang:name=PS Survivor Space,type=MemoryPool, name=PS Survivor Space, parent=Memory Subsystem] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=6/6)
+ Resource[id=12214, type=VM Compilation System, key=java.lang:type=Compilation, name=Compilation, parent=org.infinispan.server.core.Main (6996)] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=1/1)
+ Resource[id=12215, type=VM Class Loading System, key=java.lang:type=ClassLoading, name=Class Loading, parent=org.infinispan.server.core.Main (6996)] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=2/5)
+ Resource[id=12212, type=Threading, key=java.lang:type=Threading, name=Threading, parent=org.infinispan.server.core.Main (6996)] (sync=SYNCHRONIZED, state=STARTED, avail=UP, sched=4/6)
...
> discovery
...
JMX.JMX Server: Starting discovery...
JMX.JMX Server: Process scan detected a server - scan=[ProcessScan: query=[process|basename|match=^java.*], name=[java]], process=[process: pid=[2221], name=[/var/opt/noa/noa02/current/process/jdk1.6.0_24/bin/java], ppid=[2194]]
JMX.JMX Server: Process scan detected a server - scan=[ProcessScan: query=[process|basename|match=^java.*], name=[java]], process=[process: pid=[12273], name=[/var/opt/noa/noa02/current/process/jdk1.6.0_24/bin/java], ppid=[12264]]
JMX.JMX Server: key=[6996], name=[org.infinispan.server.core.Main (6996)], version=[], description=[Standalone JVM Process]
JMX.JMX Server: Done.
...
The new entry in log4j.xml
<category name="org.infinispan">
<priority value="TRACE"/>
</category>
and the change of the threshold of the appender to TRACE deliver no new information.
This is the content of the agent.log a few second after the start of the agent.
2011-08-03 07:45:03,805 INFO [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.identify-version}Version=[RHQ 4.0.1], Build Number=[ecd91b2], Build Date=[May 20, 2011 6:41 PM]
2011-08-03 07:45:03,870 INFO [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.global-concurrency-limit-disabled}Global concurrency limit has been disabled - there is no limit to the number of incoming commands allowed
2011-08-03 07:45:04,102 INFO [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.started}Service container started - ready to accept incoming commands
2011-08-03 07:45:05,605 INFO [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.agent-registration-results}Agent has successfully registered with the server. The results are: [AgentRegistrationResults: [agent-token=immdJOAVHld+lXB+UxW0rYAHIkE7KxmPqOImfckG6fOjxXZrXizvEolfoXQBp9N+xR4=]]
2011-08-03 07:45:06,053 INFO [RHQ Server Polling Thread] (org.rhq.enterprise.agent.PluginUpdate)- {PluginUpdate.updating-complete}Completed updating the plugins to their latest versions.
2011-08-03 07:45:06,065 INFO [RHQ Server Polling Thread] (enterprise.communications.command.client.ServerPollingThread)- {ServerPollingThread.server-online}The server has come back online; client has been told to start sending commands again
2011-08-03 07:45:08,130 INFO [main] (org.rhq.core.pc.PluginContainer)- Initializing Plugin Container v4.0.1...
2011-08-03 07:45:14,400 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Initializing Inventory Manager...
2011-08-03 07:45:14,404 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Loading inventory from data file [data/inventory.dat]...
2011-08-03 07:45:16,329 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Inventory with size [80] loaded from data file in [1925ms]
2011-08-03 07:45:16,356 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Starting resource activation and upgrade.
2011-08-03 07:45:16,356 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Executing the initial inventory synchronization before upgrade.
2011-08-03 07:45:16,356 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Sending [server] inventory report to Server...
2011-08-03 07:45:16,523 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server inventory...
2011-08-03 07:45:16,559 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Starting to activate (and upgrade) resources.
2011-08-03 07:45:16,580 INFO [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.platform.LinuxPlatformComponent)- Internal yum server is disabled.
2011-08-03 07:45:16,700 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.sudoers.SudoersComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:17,231 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.postfix.PostfixServerComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:17,240 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.cron.CronComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:17,251 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.cobbler.CobblerComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:17,267 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.aliases.AliasesComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:17,523 INFO [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.jmx.JMXServerComponent)- Starting connection to JMX Server 6996
2011-08-03 07:45:17,901 INFO [ResourceContainer.invoker.daemon-1] (ems.impl.jmx.connection.DConnection)- Querying MBeanServer for all MBeans
2011-08-03 07:45:17,906 INFO [ResourceContainer.invoker.daemon-1] (ems.impl.jmx.connection.DConnection)- Found 33 MBeans, starting load
2011-08-03 07:45:17,944 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.samba.SambaServerComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:18,157 WARN [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.hosts.HostsComponent)- Augeas not found - if on Fedora or RHEL, `yum install augeas`.
2011-08-03 07:45:18,171 INFO [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.jmx.JMXServerComponent)- Starting connection to JMX Server RHQ Agent
2011-08-03 07:45:18,173 INFO [ResourceContainer.invoker.daemon-1] (ems.impl.jmx.connection.DConnection)- Querying MBeanServer for all MBeans
2011-08-03 07:45:18,173 INFO [ResourceContainer.invoker.daemon-1] (ems.impl.jmx.connection.DConnection)- Found 27 MBeans, starting load
2011-08-03 07:45:18,180 INFO [ResourceContainer.invoker.daemon-1] (org.rhq.plugins.jmx.JMXServerComponent)- Starting connection to JMX Server InternalVM
2011-08-03 07:45:18,180 INFO [ResourceContainer.invoker.daemon-1] (ems.impl.jmx.connection.DConnection)- Querying MBeanServer for all MBeans
2011-08-03 07:45:18,180 INFO [ResourceContainer.invoker.daemon-1] (ems.impl.jmx.connection.DConnection)- Found 27 MBeans, starting load
2011-08-03 07:45:18,221 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Inventory activated and upgrade requests gathered in 1865ms.
2011-08-03 07:45:18,221 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Sending the upgrade requests to the server.
2011-08-03 07:45:18,221 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Resource activation and upgrade finished.
2011-08-03 07:45:18,228 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Inventory Manager initialized.
2011-08-03 07:45:18,285 INFO [main] (rhq.core.pc.inventory.ResourceFactoryManager)- Initializing
2011-08-03 07:45:18,287 INFO [main] (rhq.core.pc.content.ContentManager)- Initializing Content Manager...
2011-08-03 07:45:18,288 INFO [main] (rhq.core.pc.content.ContentManager)- Initializing scheduled content discovery...
2011-08-03 07:45:18,291 INFO [main] (rhq.core.pc.content.ContentManager)- Content Manager initialized...
2011-08-03 07:45:18,293 INFO [main] (org.rhq.core.pc.PluginContainer)- Plugin Container initialized.
2011-08-03 07:45:18,296 INFO [RHQ Primary Server Switchover Thread] (org.rhq.enterprise.agent.AgentMain)- {PrimaryServerSwitchoverThread.started}The primary server switchover thread has started.
2011-08-03 07:45:23,404 INFO [InventoryManager.availability-1] (rhq.core.pc.inventory.InventoryManager)- Sending availability report to Server...
2011-08-03 07:45:28,230 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Executing server discovery scan...
2011-08-03 07:45:28,438 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.script.ScriptDiscoveryComponent)- Processing discovered management script resources
2011-08-03 07:45:28,452 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Process scan auto-detected new server resource: scan=[ProcessScan: query=[process|basename|match=^java.*], name=[java]], discovered-process=[process: pid=[15907], name=[/var/opt/noa/noa02/current/process/jdk1.6.0_24/bin/java], ppid=[15898]]
2011-08-03 07:45:28,452 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Process scan auto-detected new server resource: scan=[ProcessScan: query=[process|basename|match=^java.*], name=[java]], discovered-process=[process: pid=[14784], name=[/var/opt/noa/noa02/current/process/jdk1.6.0_24/bin/java], ppid=[14757]]
2011-08-03 07:45:28,512 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.agent.AgentDiscoveryComponent)- Discovering RHQ Agent...
2011-08-03 07:45:28,735 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Process scan auto-detected new server resource: scan=[ProcessScan: query=[process|basename|match=sshd,process|basename|nomatch|parent=sshd], name=[SSHD]], discovered-process=[process: pid=[28257], name=[sshd], ppid=[1]]
2011-08-03 07:45:28,773 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Sending [server] inventory report to Server...
2011-08-03 07:45:30,998 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server inventory...
2011-08-03 07:45:31,033 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Found 5 servers.
2011-08-03 07:45:38,230 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Running runtime discovery scan rooted at [platform]
2011-08-03 07:45:38,763 ERROR [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Error in runtime discovery
java.lang.NoClassDefFoundError: org/jboss/logging/BasicLogger
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClassCond(ClassLoader.java:632)
at java.lang.ClassLoader.defineClass(ClassLoader.java:616)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:141)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:283)
at java.net.URLClassLoader.access$000(URLClassLoader.java:58)
at java.net.URLClassLoader$1.run(URLClassLoader.java:197)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
at org.rhq.core.pc.plugin.PluginClassLoader.loadClass(PluginClassLoader.java:63)
at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClassCond(ClassLoader.java:632)
at java.lang.ClassLoader.defineClass(ClassLoader.java:616)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:141)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:283)
at java.net.URLClassLoader.access$000(URLClassLoader.java:58)
at java.net.URLClassLoader$1.run(URLClassLoader.java:197)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
at org.rhq.core.pc.plugin.PluginClassLoader.loadClass(PluginClassLoader.java:63)
at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
at org.infinispan.rhq.CacheManagerDiscovery.<clinit>(CacheManagerDiscovery.java:48)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:247)
at org.rhq.core.pc.plugin.PluginComponentFactory.instantiateClass(PluginComponentFactory.java:246)
at org.rhq.core.pc.plugin.PluginComponentFactory.getDiscoveryComponent(PluginComponentFactory.java:113)
at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.discoverForResource(RuntimeDiscoveryExecutor.java:244)
at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.discoverForResourceRecursive(RuntimeDiscoveryExecutor.java:158)
at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.runtimeDiscover(RuntimeDiscoveryExecutor.java:140)
at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.call(RuntimeDiscoveryExecutor.java:99)
at org.rhq.core.pc.inventory.RuntimeDiscoveryExecutor.run(RuntimeDiscoveryExecutor.java:88)
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:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
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)
Caused by: java.lang.ClassNotFoundException: org.jboss.logging.BasicLogger
at java.net.URLClassLoader$1.run(URLClassLoader.java:202)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
at org.rhq.core.pc.plugin.PluginClassLoader.loadClass(PluginClassLoader.java:63)
at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
... 43 more
2011-08-03 07:45:38,819 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.agent.AgentEnvironmentScriptDiscoveryComponent)- Discovering RHQ Agent's environment setup script...
2011-08-03 07:45:38,832 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.agent.AgentLauncherScriptDiscoveryComponent)- Discovering RHQ Agent's launcher script service...
2011-08-03 07:45:38,836 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.agent.AgentJavaServiceWrapperDiscoveryComponent)- Discovering RHQ Agent's JSW service...
2011-08-03 07:45:38,882 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Scanned [0] servers and found [0] total descendant Resources.
2011-08-03 07:45:38,882 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Sending [runtime] inventory report to Server...
2011-08-03 07:45:39,068 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server inventory...
2011-08-03 07:46:18,236 WARN [MeasurementManager.sender-1] (rhq.core.pc.measurement.MeasurementSenderRunner)- Numeric fileSystemUsage.diskQueue with id 38292 is invalid, value was 'NaN'
2011-08-03 07:46:18,237 INFO [MeasurementManager.sender-1] (rhq.core.pc.measurement.MeasurementSenderRunner)- Measurement collection for [14] metrics took 52ms - sending report to Server...
2011-08-03 07:46:48,235 INFO [MeasurementManager.sender-1] (rhq.core.pc.measurement.MeasurementSenderRunner)- Measurement collection for [5] metrics took 509ms - sending report to Server...
André
-
3. Re: monitoring via rhq
galder.zamarreno Aug 30, 2011 4:17 AM (in response to kullmann)André, thanks for the extra info and apologies for the delay (holiday season in full flow at the moment)
Seems like a missing jar is halting the discovery. I've created https://issues.jboss.org/browse/ISPN-1357 and I'll check whether anything else might be missing with the RHQ version you're using.