Tomcat instances marked as unavailable or down

[ops]

Hi everybody,
I successfully installed jopr 2.2.1 and several agents to monitor some jboss and tomcat instances. While everything works fine while monitoring the jboss as, all tomcat instances are marked as down. But they are explicitly up and serving fine. Jopr seems not to recognize them. Wrong jmx settings?

Thanks for your help,
Oliver

[mazz]

Confirm that the Tomcat resource's connection settings (from the "Inventory > Connection" subtab) are correct. If they are, check the agent logs to see if there are any error messages that seem relevent.

[ops]

Hi,
the manager url in the connection tab is "service:jmx:rmi:///jndi/rmi://localhost:8999/jmxrmi". Not quite shure if there should be the dns name, since the tomcat instance runs on another machine. Or is that the address used by the local agent? The agent itself seems to recognize tomcat, saying state=started and avail=down. There is an error in the agents log, telling something about ssl handshake, but my CATALINA_OPTS have ssl disabled:

2009-07-29 20:09:51,995 INFO [ResourceContainer.invoker.daemon-1] (jboss.on.plugins.tomcat.TomcatServerComponent)- Loading connection [service:jmx:rmi:///jndi/rmi://localhost:8999/jmxrmi] with install path [D:\apache-tomcat-6.0.18] and temp directory [D:\ides\agent-1.2.1\data\tmp]
2009-07-29 20:09:52,698 WARN [ResourceContainer.invoker.daemon-1] (jboss.on.plugins.tomcat.TomcatServerComponent)- Could not establish connection to the Tomcat instance [1] times for resource [D:\apache-tomcat-6.0.18]
org.mc4j.ems.connection.EmsConnectException: Could not connect [service:jmx:rmi:///jndi/rmi://localhost:8999/jmxrmi] org.mc4j.ems.connection.EmsConnectException: IOException: Check service availability
 at org.mc4j.ems.impl.jmx.connection.support.providers.AbstractConnectionProvider.connect(AbstractConnectionProvider.java:103)
 at org.jboss.on.plugins.tomcat.TomcatServerComponent.loadConnection(TomcatServerComponent.java:214)
 at org.jboss.on.plugins.tomcat.TomcatServerComponent.start(TomcatServerComponent.java:290)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.rhq.core.pc.inventory.ResourceContainer$ComponentInvocationThread.call(ResourceContainer.java:511)
 at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
 at java.util.concurrent.FutureTask.run(FutureTask.java:123)
 at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
 at java.lang.Thread.run(Thread.java:595)
Caused by: org.mc4j.ems.connection.EmsConnectException: IOException: Check service availability
 at org.mc4j.ems.impl.jmx.connection.support.providers.JMXRemotingConnectionProvider.doConnect(JMXRemotingConnectionProvider.java:163)
 at org.mc4j.ems.impl.jmx.connection.support.providers.AbstractConnectionProvider.connect(AbstractConnectionProvider.java:99)
 ... 12 more
Caused by: java.rmi.ConnectIOException: error during JRMP connection establishment; nested exception is:
 javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
 at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:273)
 at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:171)
 at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:94)
 at javax.management.remote.rmi.RMIServerImpl_Stub.newClient(Unknown Source)
 at javax.management.remote.rmi.RMIConnector.getConnection(RMIConnector.java:2239)
 at javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:271)
 at javax.management.remote.JMXConnectorFactory.connect(JMXConnectorFactory.java:248)
 at org.mc4j.ems.impl.jmx.connection.support.providers.JMXRemotingConnectionProvider.doConnect(JMXRemotingConnectionProvider.java:144)
 ... 13 more
Caused by: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
 at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:150)
 at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:117)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.recvAlert(SSLSocketImpl.java:1584)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:866)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1030)
 at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:622)
 at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:59)
 at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
 at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
 at java.io.DataOutputStream.flush(DataOutputStream.java:106)
 at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:198)
 ... 20 more
2009-07-29 20:09:53,214 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Inventory with size [13] initialized from data file in [1719ms]
2009-07-29 20:09:53,245 ERROR [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.perftest.ScenarioManager)- Cannot find scenario name. Make sure the property on.perftest.scenario is set.
2009-07-29 20:09:53,260 INFO [main] (rhq.core.pc.inventory.InventoryManager)- Inventory Manager initialized.
2009-07-29 20:09:53,292 INFO [main] (rhq.core.pc.inventory.ResourceFactoryManager)- Initializing
2009-07-29 20:09:53,292 INFO [main] (rhq.core.pc.content.ContentManager)- Initializing Content Manager...
2009-07-29 20:09:53,292 INFO [main] (rhq.core.pc.content.ContentManager)- Initializing scheduled content discovery...
2009-07-29 20:09:53,292 INFO [main] (rhq.core.pc.content.ContentManager)- Content Manager initialized...
2009-07-29 20:09:53,292 INFO [RHQ Primary Server Switchover Thread] (org.rhq.enterprise.agent.AgentMain)- {PrimaryServerSwitchoverThread.started}The primary server switchover thread has started.
2009-07-29 20:09:58,401 INFO [ResourceContainer.invoker.daemon-1] (org.mc4j.ems.connection.ConnectionFactory)- Connection library dependancy [catalina-cluster.jar] not found in directory: D:\apache-tomcat-6.0.18
2009-07-29 20:09:58,464 INFO [ResourceContainer.invoker.daemon-1] (org.mc4j.ems.connection.ConnectionFactory)- Connection library dependancy [catalina-optional.jar] not found in directory: D:\apache-tomcat-6.0.18
2009-07-29 20:09:58,464 INFO [ResourceContainer.invoker.daemon-1] (org.mc4j.ems.connection.ConnectionFactory)- Discovered libraries in 141 ms
2009-07-29 20:09:58,464 INFO [ResourceContainer.invoker.daemon-1] (jboss.on.plugins.tomcat.TomcatServerComponent)- Loading connection [service:jmx:rmi:///jndi/rmi://localhost:8999/jmxrmi] with install path [D:\apache-tomcat-6.0.18] and temp directory [D:\ides\agent-1.2.1\data\tmp]
2009-07-29 20:09:58,479 INFO [InventoryManager.availability-1] (rhq.core.pc.inventory.InventoryManager)- Sending availability report to Server...
2009-07-29 20:10:03,245 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Executing server discovery scan...
2009-07-29 20:10:03,510 WARN [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.virt.VirtualizationDiscoveryComponent)- Can not load native library for libvirt: Unable to load library 'virt': Das angegebene Modul wurde nicht gefunden.

2009-07-29 20:10:03,682 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Process scan auto-detected new server resource: scan=[ProcessScan: query=[process|basename|match=^java.*,arg|org.apache.catalina.startup.Bootstrap|match=.*], name=[Tomcat]], discovered-process=[process: pid=[2448], name=[D:\ides\ide-studentcopy\jdk1.5.0_13\bin\java.exe], ppid=[1164]]
2009-07-29 20:10:04,042 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.agent.AgentDiscoveryComponent)- Discovering RHQ Agent...
2009-07-29 20:10:04,135 INFO [ResourceDiscoveryComponent.invoker.daemon-1] (org.rhq.plugins.cli.CliDiscoveryComponent)- Processing discovered CLI resources
2009-07-29 20:10:04,167 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Sending server inventory report to Server...
2009-07-29 20:10:04,214 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server inventory...
2009-07-29 20:10:04,229 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.AutoDiscoveryExecutor)- Found 2 servers.
2009-07-29 20:10:13,245 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Running runtime discovery scan rooted at platform...
2009-07-29 20:10:13,370 INFO [ResourceContainer.invoker.daemon-1] (org.mc4j.ems.connection.ConnectionFactory)- Connection library dependancy [catalina-cluster.jar] not found in directory: D:\apache-tomcat-6.0.18
2009-07-29 20:10:13,432 INFO [ResourceContainer.invoker.daemon-1] (org.mc4j.ems.connection.ConnectionFactory)- Connection library dependancy [catalina-optional.jar] not found in directory: D:\apache-tomcat-6.0.18
2009-07-29 20:10:13,432 INFO [ResourceContainer.invoker.daemon-1] (org.mc4j.ems.connection.ConnectionFactory)- Discovered libraries in 140 ms
2009-07-29 20:10:13,432 INFO [ResourceContainer.invoker.daemon-1] (jboss.on.plugins.tomcat.TomcatServerComponent)- Loading connection [service:jmx:rmi:///jndi/rmi://localhost:8999/jmxrmi] with install path [D:\apache-tomcat-6.0.18] and temp directory [D:\ides\agent-1.2.1\data\tmp]
2009-07-29 20:10:13,620 INFO [InventoryManager.discovery-1] (org.mc4j.ems.connection.ConnectionFactory)- Connection library dependancy [catalina-cluster.jar] not found in directory: D:\apache-tomcat-6.0.18
2009-07-29 20:10:13,698 INFO [InventoryManager.discovery-1] (org.mc4j.ems.connection.ConnectionFactory)- Connection library dependancy [catalina-optional.jar] not found in directory: D:\apache-tomcat-6.0.18
2009-07-29 20:10:13,698 INFO [InventoryManager.discovery-1] (org.mc4j.ems.connection.ConnectionFactory)- Discovered libraries in 156 ms
2009-07-29 20:10:13,698 INFO [InventoryManager.discovery-1] (jboss.on.plugins.tomcat.TomcatServerComponent)- Loading connection [service:jmx:rmi:///jndi/rmi://localhost:8999/jmxrmi] with install path [D:\apache-tomcat-6.0.18] and temp directory [D:\ides\agent-1.2.1\data\tmp]
2009-07-29 20:10:13,823 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.RuntimeDiscoveryExecutor)- Scanned 0 servers and found 0 total descendant Resources.
2009-07-29 20:10:13,823 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Sending runtime inventory report to Server...
2009-07-29 20:10:13,839 INFO [InventoryManager.discovery-1] (rhq.core.pc.inventory.InventoryManager)- Syncing local inventory with Server inventory...
2009-07-29 20:10:14,245 INFO [RHQ Agent Prompt Input Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.prompt-command-invoked}Prompt command invoked: [inventory]

Any ideas?

Greets,
Oliver

[ops]

Hi,
i found something. Tomcat does not open an jmx port if I start it by console. When I try using Eclipse the jmx port is opened and after doing a rediscovery the agent lists tomcat as available. I'm confused. Both VMs get the same start parameters:

-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=8999
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false

In Eclipse I put this directly on the vm-parameters tab and the console tomcat has it in his startup.bat:

JAVA_OPTS=-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=8999
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false

I also tried setting this by CATALINA_OPTS.

So what could be the difference starting one and the same tomcat installation by console or by Eclipse? Strange!

Greets, Oliver

[mazz]

Are the Java versions the same?

i.e. what version of VM is Eclipse using when it starts Tomcat and what version of the VM are you using when starting Tomcat from the console?

I don't know if it would matter but, its something to look at.

[ops]

Oh man! I tried to run all vms consequently on the newest jdk 1.6.0_14. But when I start the agent now I get a fatal error:

D:\ides\managers\jopr-agent-2.2.1\bin>rhq-agent
RHQ 1.2.1 [4026] (Wed Jun 03 15:52:53 CEST 2009)
> #
# A fatal error has been detected by the Java Runtime Environment:
#
# EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x0243ae14, pid=4740, tid=6140
#
# JRE version: 6.0_14-b08
# Java VM: Java HotSpot(TM) Client VM (14.0-b16 mixed mode windows-x86 )
# Problematic frame:
# C 0x0243ae14
#
# An error report file with more information is saved as:
# D:\ides\managers\jopr-agent-2.2.1\hs_err_pid4740.log
#
# If you would like to submit a bug report, please visit:
# http://java.sun.com/webapps/bugreport/crash.jsp
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

This is really horrible. I'm wasting hours and hours on a simple server/agent architecture. grrr!

[mazz]

The fact that even your Tomcat is behaving differently based on the different ways you are starting it is telling me there is something more going on.

What platform/OS is this?

BTW: If you see crashes in the agent, you can start it with the "--nonative" command line option - that will not load the JNI native layer it uses and sometimes avoids the crashes.

[ops]

Sorry, I found out that I made several mistakes.
Problem a) the jmx port was not open due to the following misconfiguration:
set CATALINA_OPTS="-D... -D..." - the " only work on unix, not on windows. My Eclipse config didn't contain those and so the port was opened.
Problem b)
the agents must be reinstalled , not copied. The native access violation seems to occur in case of i.e. using another jdk with an agent that already saved something into his data directory.
Problem c)
Running an "discovery" on an "old" but jdk-reconfigured client containing data is useless, even in --nonative mode. He will find no tomcat instances.
Problem d)
the server hangs himself completely with thousands of exceptions, in case of using an "old" agent data with an reinstalled server instance. and in this scenario it won't react on quit-messages and has to be removed by a process explorer.

My agens and server run fine on jdk 1.5 now and I was able to evaluate some of the basic features. Thanks for your help.