JDBC Monitoring not working

[Andrea Mariottini]

I have a multi tenant application and a db for each tenant.

The jdbc connection parameters are set at runtime so I tried to use this to monitor access to the db:

<property name="hibernate.jdbc.factory_class" value="net.bull.javamelody.HibernateBatcherFactory" />

But it seems to not work. I don't have errors, simply no monitoring (of course I use Hibernate):

Fri Jun 28 12:01:07 CEST 2013     DEBUG     JavaMelody listener init started
Fri Jun 28 12:01:07 CEST 2013     DEBUG     datasources found in JNDI: []
Fri Jun 28 12:01:07 CEST 2013     DEBUG     JavaMelody listener init done in 60 ms
Fri Jun 28 12:01:07 CEST 2013     DEBUG     JavaMelody filter init started
Fri Jun 28 12:01:07 CEST 2013     DEBUG     OS: Linux unknown, i386/32
Fri Jun 28 12:01:07 CEST 2013     DEBUG     Java: Java(TM) SE Runtime Environment, 1.7.0_11-b21
Fri Jun 28 12:01:07 CEST 2013     DEBUG     Server: jetty/8.1.3.v20120416
Fri Jun 28 12:01:07 CEST 2013     DEBUG     Webapp context: /api
Fri Jun 28 12:01:07 CEST 2013     DEBUG     JavaMelody version: 1.45.0
Fri Jun 28 12:01:07 CEST 2013     DEBUG     JavaMelody classes loaded from: file:/var/cache/jetty8/data/jetty-0.0.0.0-8445-api.war-_api-any-/webapp/WEB-INF/lib/javamelody.jar
Fri Jun 28 12:01:07 CEST 2013     DEBUG     Host: gepp...@127.0.1.1
Fri Jun 28 12:01:07 CEST 2013     DEBUG     log listeners initialized
Fri Jun 28 12:01:07 CEST 2013     DEBUG     datasources found in JNDI: []
Fri Jun 28 12:01:07 CEST 2013     DEBUG     counters initialized
Fri Jun 28 12:01:07 CEST 2013     DEBUG     counters data read from files in /var/cache/jetty8/data/javamelody/api_geppetto
Fri Jun 28 12:01:07 CEST 2013     DEBUG     collect task scheduled every 60s
Fri Jun 28 12:01:07 CEST 2013     DEBUG     first collect of data done
Fri Jun 28 12:01:07 CEST 2013     DEBUG     JavaMelody filter init done in 435 ms

Any idea?

[Andrea Mariottini]

I tried setting the properties:

hibernate.connection.driver_class -> net.bull.javamelody.JdbcDriver

hibernate.connection.driver -> oracle.jdbc.driver.OracleDriver

I use c3p0 0.9.2.1 as connection provider

Now this is the error occurring (disabling JavaMelody I have no errors):

[2013-07-19 16:44:47,642- ERROR] (SqlExceptionHelper.java:144) -> [An SQLException was provoked by the following failure: java.lang.RuntimeException: Internal inconsistency: A (not new) checking-out statement is not in deathmarch.]

[2013-07-19 16:44:47,645- ERROR] (RisorsaSincronia.java:63) -> [javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: An SQLException was provoked by the following failure: java.lang.RuntimeException: Internal inconsistency: A (not new) checking-out statement is not in deathmarch.

at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1377)

at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1300)

at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1306)

at org.hibernate.ejb.AbstractEntityManagerImpl.merge(AbstractEntityManagerImpl.java:888)

at it.giuffre.sincroniagsl.infrastruttura.repository.hibernate.RepositoryDatiCliensHibernate.scriviElementoDatiCliens(RepositoryDatiCliensHibernate.java:17)

at it.giuffre.sincroniagsl.applicazione.comandi.ComandoElaboraDatiDaCliens.effettuaScrittura(ComandoElaboraDatiDaCliens.java:59)

at it.giuffre.sincroniagsl.applicazione.comandi.ComandoElaboraDatiDaCliens.esegui(ComandoElaboraDatiDaCliens.java:48)

at it.giuffre.sincroniagsl.applicazione.HandlerComandi.eseguiComando(HandlerComandi.java:18)

at it.giuffre.sincroniagsl.applicazione.risorserest.RisorsaSincronia.scriviDatoDaCliens(RisorsaSincronia.java:51)

at it.giuffre.sincroniagsl.applicazione.risorserest.RisorsaSincronia.scriviDatoDaCliens(RisorsaSincronia.java:42)

at sun.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:601)

at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)

at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205)

at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)

at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)

at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)

at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)

at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)

at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)

at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)

at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)

at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)

at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)

at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)

at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1367)

at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:163)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at it.giuffre.sincroniagsl.applicazione.filtri.AutenticazioneSincroniaFilter.doFilter(AutenticazioneSincroniaFilter.java:37)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at it.giuffre.clienscloud.applicazione.filtri.EntityManagerTenantFilter.doFilter(EntityManagerTenantFilter.java:45)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at it.giuffre.sincroniagsl.applicazione.filtri.StudioSincroniaFilter.doFilter(StudioSincroniaFilter.java:37)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at it.giuffre.clienscloud.applicazione.filtri.EntityManagerStudiFilter.doFilter(EntityManagerStudiFilter.java:31)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at it.giuffre.clienscloud.applicazione.filtri.ConfigurationFilter.doFilter(ConfigurationFilter.java:51)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:206)

at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:179)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1338)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:484)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:499)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:233)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)

at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250)

at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111)

at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:312)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111)

at org.eclipse.jetty.server.Server.handle(Server.java:350)

at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454)

at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:900)

at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:954)

at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:943)

at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)

at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77)

at org.eclipse.jetty.io.nio.SslConnection.handle(SslConnection.java:191)

at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606)

at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603)

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538)

at java.lang.Thread.run(Thread.java:722)

Caused by: org.hibernate.exception.GenericJDBCException: An SQLException was provoked by the following failure: java.lang.RuntimeException: Internal inconsistency: A (not new) checking-out statement is not in deathmarch.

at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)

at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)

at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)

at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.continueInvocation(ConnectionProxyHandler.java:146)

at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81)

at $Proxy89.prepareStatement(Unknown Source)

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:147)

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:166)

at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:145)

at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1749)

at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1726)

at org.hibernate.loader.Loader.doQuery(Loader.java:852)

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:293)

at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:263)

at org.hibernate.loader.Loader.loadEntity(Loader.java:2006)

at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:82)

at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:72)

at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3887)

at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:458)

at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:427)

at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:204)

at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:260)

at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:148)

at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1078)

at org.hibernate.internal.SessionImpl.access$2000(SessionImpl.java:175)

at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2424)

at org.hibernate.internal.SessionImpl.get(SessionImpl.java:978)

at org.hibernate.event.internal.DefaultMergeEventListener.entityIsDetached(DefaultMergeEventListener.java:271)

at org.hibernate.event.internal.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:151)

at org.hibernate.event.internal.DefaultMergeEventListener.onMerge(DefaultMergeEventListener.java:76)

at org.hibernate.internal.SessionImpl.fireMerge(SessionImpl.java:903)

at org.hibernate.internal.SessionImpl.merge(SessionImpl.java:887)

at org.hibernate.internal.SessionImpl.merge(SessionImpl.java:891)

at org.hibernate.ejb.AbstractEntityManagerImpl.merge(AbstractEntityManagerImpl.java:879)

... 68 more

Caused by: java.sql.SQLException: An SQLException was provoked by the following failure: java.lang.RuntimeException: Internal inconsistency: A (not new) checking-out statement is not in deathmarch.

at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:118)

at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:77)

at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:74)

at com.mchange.v2.c3p0.impl.NewPooledConnection.handleThrowable(NewPooledConnection.java:492)

at com.mchange.v2.c3p0.impl.NewProxyConnection.prepareStatement(NewProxyConnection.java:179)

at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:601)

at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.continueInvocation(ConnectionProxyHandler.java:138)

... 98 more

Caused by: java.lang.RuntimeException: Internal inconsistency: A (not new) checking-out statement is not in deathmarch.

at com.mchange.v2.c3p0.stmt.GooGooStatementCache$Deathmarch.undeathmarchStatement(GooGooStatementCache.java:710)

at com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache.removeStatementFromDeathmarches(GlobalMaxOnlyStatementCache.java:62)

at com.mchange.v2.c3p0.stmt.GooGooStatementCache.checkoutStatement(GooGooStatementCache.java:224)

at com.mchange.v2.c3p0.impl.NewPooledConnection.checkoutStatement(NewPooledConnection.java:308)

at com.mchange.v2.c3p0.impl.NewProxyConnection.prepareStatement(NewProxyConnection.java:148)

... 102 more

[Vernat Emeric]

Hi Andrea,

c3p0 0.9.2.1 was said to be a problem for us before.
You can try DBCP instead of c3p0.

bye,
Emeric

--
 
---
You received this message because you are subscribed to the Google Groups "javamelody" group.
To unsubscribe from this group and stop receiving emails from it, send an email to javamelody+...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[Andrea Mariottini]

I verified it works if I set max_statements=0, this disable prepared statements.

I don't know if this could have a big impact on performance...

I also verified Hibernate 4 has hibernate.jdbc.factory_class defined but it seems to never use that property.

This is why it doesn't work.

Maybe it is deprecated?

[Andrea Mariottini]

The problem with DBCP is it seems not maintained.

Il giorno venerdì 19 luglio 2013 23:54:01 UTC+2, evernat ha scritto:

[evernat]

> The problem with DBCP is it seems not maintained.

A few Apache guys have just raised straight up from their seats with Tomahawks.

A bit more seriously, DBCP is the default connection pool in Tomcat, which is the most used java server in the world.
So, if there is no release of DBCP, it's probably because there is no serious bug.
But if you prefer, you can look at the other connection pool of Tomcat : tomcat jdbc pool, with a similar configuration as DBCP.
http://tomcat.apache.org/tomcat-7.0-doc/jdbc-pool.html

bye,
Emeric

[Andrea Mariottini]

Thanks, now I know, take a breath Apache guys! :)

Even me, more seriously: to change from c3p0 to another connection pool is  not so trivial. I need to verify all works exactly the same.

I prefer to let this option as the last one and move for application reasons, not monitoring reasons.

As I wrote, I discovered setting max_statements=0 solve the problem.

What is not perfectly clear to me is what are the consequences.

Does it simply means repeated SQL statements are not cached in compiled form?

Why JavaMelody doesn't work with precompiled statements?

Andrea

You received this message because you are subscribed to a topic in the Google Groups "javamelody" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/javamelody/wrUcAzH4MD0/unsubscribe.
To unsubscribe from this group and all its topics, send an email to javamelody+...@googlegroups.com.

[Vernat Emeric]

Hi,

maxStatements is documented at:
http://www.mchange.com/projects/c3p0/#configuring_statement_pooling

c3p0 has seen a lot of changes recently, both before and after 0.9.2.1, which was released in March 2013.
For whatever reason, if you prefer to keep c3p0, I suggest to try some version before 0.9.2.1 or version 0.9.5-pre3.

bye,
Emeric