search

cangwolf / javamelody

Automatically exported from code.google.com/p/javamelody
0 stars 0 forks source link

SQL monitoring doesn't work with Tomcat 6 and JNDI #391

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
1. Install 1.49 and j-robin 1.5.9.1
2. Update web.xml for specific app
3. Restart Tomcat 6
4. browse to ../monitoring

What is the expected output? What do you see instead?
I am seeking JDBC and SQL stats

What version of the product are you using? On what application server, JDK,
operating system?
Tomcat 6, JDK 1.6.0_29, Oracle Solaris 10 9/10 s10x_u9wos_14a X86

Please provide any additional information below.
All the stats are working as expected, except for JDBC and SQL.
Latest debugging log:
Thu Mar 20 18:11:03 CET 2014     DEBUG     JavaMelody listener init started
Thu Mar 20 18:11:03 CET 2014     DEBUG     datasources found in JNDI: 
[java:comp/env/jdbc/xxxx]
Thu Mar 20 18:11:03 CET 2014     DEBUG     rebinding datasources failed, 
skipping
Thu Mar 20 18:11:03 CET 2014     DEBUG     JavaMelody listener init done in 24 
ms
Thu Mar 20 18:11:03 CET 2014     DEBUG     JavaMelody filter init started
Thu Mar 20 18:11:03 CET 2014     DEBUG     OS: SunOS unknown, x86/32
Thu Mar 20 18:11:03 CET 2014     DEBUG     Java: Java(TM) SE Runtime 
Environment, 1.6.0_29-b11
Thu Mar 20 18:11:03 CET 2014     DEBUG     Server: XXXX Application Server
Thu Mar 20 18:11:03 CET 2014     DEBUG     Webapp context: /xxxx
Thu Mar 20 18:11:03 CET 2014     DEBUG     JavaMelody version: 1.49.0
Thu Mar 20 18:11:03 CET 2014     DEBUG     JavaMelody classes loaded from: 
file:/var/www/webapps/xxxx/WEB-INF/lib/javamelody.jar
Thu Mar 20 18:11:03 CET 2014     DEBUG     Host: xxxxxxx@192.168.102.102
Thu Mar 20 18:11:03 CET 2014     DEBUG     log listeners initialized
Thu Mar 20 18:11:03 CET 2014     DEBUG     datasources found in JNDI: 
[java:comp/env/jdbc/xxxx]
Thu Mar 20 18:11:03 CET 2014     DEBUG     rebinding datasources failed, 
skipping
Thu Mar 20 18:11:03 CET 2014     DEBUG     job global listener initialized
Thu Mar 20 18:11:03 CET 2014     DEBUG     counters initialized
Thu Mar 20 18:11:03 CET 2014     DEBUG     counters data read from files in 
/var/www/servidores/tomcat8080/temp/javamelody/xxxx_xxxxxxxx
Thu Mar 20 18:11:03 CET 2014     DEBUG     collect task scheduled every 60s
Thu Mar 20 18:11:03 CET 2014     DEBUG     first collect of data done
Thu Mar 20 18:11:03 CET 2014     DEBUG     JavaMelody filter init done in 326 ms

Original issue reported on code.google.com by jll...@gmail.com on 20 Mar 2014 at 5:52

GoogleCodeExporter commented 9 years ago 
It's just a bit strange.
SQL monitoring worked first in Tomcat 6 and JNDI, and for more than 4 years now.

Can you give the xml definition of the datasource (without private information 
of course)?
And after that, can you debug and say why rebinding failed inside 
net.bull.javamelody.JdbcWrapper?

Original comment by evernat@free.fr on 20 Mar 2014 at 11:51

GoogleCodeExporter commented 9 years ago 
Datasource:
<Context docBase="/var/www/webapps/xxxx" path="/xxxx" debug="0" 
reloadable="true">
  <WatchedResource>WEB-INF/web.xml</WatchedResource>
  <Resource name="jdbc/xxxx"
            auth="Container"
            type="javax.sql.DataSource"
            maxActive="50"
            maxIdle="30"
            maxWait="10000"
            removeAbandoned="true"
            removeAbandonedTimeout="5000"
            logAbandoned="true"
            username="xxxx"
            password="xxxx"
            driverClassName="oracle.jdbc.driver.OracleDriver"
            url="jdbc:oracle:thin:@192.168.102.102:1684:XXXXXXX" />
</Context>

It's a real environment. It will be difficult to debug... Anyway, maybe I can 
get more info if I add log4j.xml and library to the classpath. Or is there any 
way to get more debug info?

Thanks!

Original comment by jll...@gmail.com on 21 Mar 2014 at 10:36

GoogleCodeExporter commented 9 years ago 
Your datasource is mostly classic. No problem with that.

Why the serverInfo says "Server: XXXX Application Server" in the log above?
And what is XXX?

For Tomcat, it should be something like "Server: Apache Tomcat/6.0.26".
Your server is not really Tomcat?

Original comment by evernat@free.fr on 21 Mar 2014 at 10:46

GoogleCodeExporter commented 9 years ago 
XXX = name of my company

I suppose it's getting it from one config file.

Anyway, I'm sure it's a Tomcat 6

Original comment by jll...@gmail.com on 21 Mar 2014 at 10:53

GoogleCodeExporter commented 9 years ago 
It's a bit strange, I have never seen a company changing the name of the Tomcat 
server. Why would someone do that?

I suggest to look into the server logs (logged with Logback or Log4J or 
java.util.logging).
You should see the stack-trace of an exception near the message "rebinding 
datasources failed, skipping". This stack-trace and its "caused by" may give us 
an hint of the problem.

Original comment by evernat@free.fr on 22 Mar 2014 at 1:26

GoogleCodeExporter commented 9 years ago 
[deleted comment]
GoogleCodeExporter commented 9 years ago 
I don't know why sysadmins changed the name of Tomcat Server...

Here it is the log (with the stack-trace):
13:42:26,097 DEBUG [net.bull.javamelody] rebinding datasources failed, skipping
javax.naming.NamingException: Context is read only
    at org.apache.naming.NamingContext.checkWritable(NamingContext.java:903)
    at org.apache.naming.NamingContext.bind(NamingContext.java:831)
    at org.apache.naming.NamingContext.rebind(NamingContext.java:208)
    at org.apache.naming.NamingContext.rebind(NamingContext.java:223)
    at org.apache.naming.SelectorContext.rebind(SelectorContext.java:222)
    at javax.naming.InitialContext.rebind(InitialContext.java:408)
    at net.bull.javamelody.JdbcWrapperHelper.rebindDataSource(JdbcWrapperHelper.java:109)
    at net.bull.javamelody.JdbcWrapper.rebindDataSources(JdbcWrapper.java:445)
    at net.bull.javamelody.FilterContext.<init>(FilterContext.java:83)
    at net.bull.javamelody.MonitoringFilter.init(MonitoringFilter.java:111)
    at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:295)
    at org.apache.catalina.core.ApplicationFilterConfig.setFilterDef(ApplicationFilterConfig.java:422)
    at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:115)
    at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4071)
    at org.apache.catalina.core.StandardContext.start(StandardContext.java:4725)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
    at org.apache.catalina.core.StandardHost.start(StandardHost.java:840)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
    at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:463)
    at org.apache.catalina.core.StandardService.start(StandardService.java:525)
    at org.apache.catalina.core.StandardServer.start(StandardServer.java:754)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:595)
    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:597)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)

Any idea?

Thanks!

Original comment by jll...@gmail.com on 26 Mar 2014 at 12:50

GoogleCodeExporter commented 9 years ago 
I understand now.
In fact, javamelody knows how to work around this "read only context", when it 
recognize a Tomcat server, that is when the name of the server contains 
"Tomcat".
Given that your sysadmins have changed the name of "Tomcat", javamelody don't 
know what to do and it skips datasource monitoring.

It is clear to me that your issue is invalid, because you can't expect 
javamelody to recognize "Tomcat" when you have changed the name of the server.

That said, it may work to add the parameter "rewrap-datasources" = "true" (no 
guarantee). For example, with the system property 
-Djavamelody.rewrap-datasources=true

Otherwise, you can change back the name of the server to "Apache Tomcat/6.x.x"

Original comment by evernat@free.fr on 28 Mar 2014 at 3:25

GoogleCodeExporter commented 9 years ago 
Forgot to say that "rewrap-datasources" is a non official parameter: not 
documented, no support, no guarantee.

Original comment by evernat@free.fr on 28 Mar 2014 at 3:26