opentracing-contrib / java-jdbc

OpenTracing Instrumentation for JDBC
Apache License 2.0
82 stars 56 forks source link

DynamicProxy ClassCastException when using JPA #60

Closed rlubke closed 4 years ago

rlubke commented 4 years ago

This appears related to #59 as if I rollback to 0.2.4, the error does not occur.

Error (sorry, it's a long one):

    at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:857)
    at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getAbstractSession(EntityManagerFactoryDelegate.java:222)
    at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:330)
    at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.createEntityManagerImpl(EntityManagerFactoryImpl.java:350)
    at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.createEntityManager(EntityManagerFactoryImpl.java:313)
    at com.oracle.coherence.demo.application.Utilities.<clinit>(Utilities.java:126)
    at com.oracle.coherence.demo.application.BootstrapInterceptor.onEvent(BootstrapInterceptor.java:50)
    at com.oracle.coherence.demo.application.BootstrapInterceptor.onEvent(BootstrapInterceptor.java:36)
    at com.tangosol.net.events.internal.NamedEventInterceptor.onEvent(NamedEventInterceptor.java:261)
    at com.tangosol.net.events.internal.AbstractEvent.nextInterceptor(AbstractEvent.java:122)
    at com.tangosol.net.events.internal.AbstractEvent.dispatch(AbstractEvent.java:167)
    at com.tangosol.net.events.internal.ConfigurableCacheFactoryDispatcher.dispatchEvent(ConfigurableCacheFactoryDispatcher.java:78)
    at com.tangosol.net.events.internal.ConfigurableCacheFactoryDispatcher.dispatchActivated(ConfigurableCacheFactoryDispatcher.java:54)
    at com.tangosol.net.ExtensibleConfigurableCacheFactory.activate(ExtensibleConfigurableCacheFactory.java:630)
    at com.tangosol.net.DefaultCacheServer.startServicesInternal(DefaultCacheServer.java:565)
    at com.tangosol.net.DefaultCacheServer.initialStartServices(DefaultCacheServer.java:503)
    at com.tangosol.net.DefaultCacheServer.lambda$startAndMonitor$0(DefaultCacheServer.java:87)
    at java.security.AccessController.doPrivileged(Native Method)
    at com.tangosol.net.DefaultCacheServer.startAndMonitor(DefaultCacheServer.java:84)
    at com.tangosol.net.DefaultCacheServer.main(DefaultCacheServer.java:430)
    at com.oracle.coherence.demo.application.Launcher.main(Launcher.java:190)
Caused by: java.lang.reflect.UndeclaredThrowableException
    at com.sun.proxy.$Proxy48.prepareStatement(Unknown Source)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.prepareStatement(DatabaseAccessor.java:1595)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.prepareStatement(DatabaseAccessor.java:1544)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseCall.prepareStatement(DatabaseCall.java:807)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:628)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:567)
    at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2099)
    at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:603)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:275)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:261)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeNoSelectCall(DatasourceCallQueryMechanism.java:304)
    at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeNoSelect(DatasourceCallQueryMechanism.java:284)
    at org.eclipse.persistence.queries.DataModifyQuery.executeDatabaseQuery(DataModifyQuery.java:87)
    at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:911)
    at org.eclipse.persistence.internal.sessions.AbstractSession.internalExecuteQuery(AbstractSession.java:3356)
    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1898)
    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1880)
    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1830)
    at org.eclipse.persistence.internal.sessions.AbstractSession.priviledgedExecuteNonSelectingCall(AbstractSession.java:5223)
    at org.eclipse.persistence.tools.schemaframework.DatabaseObjectDefinition.createOnDatabase(DatabaseObjectDefinition.java:204)
    at org.eclipse.persistence.tools.schemaframework.SchemaManager.createObject(SchemaManager.java:223)
    at org.eclipse.persistence.tools.schemaframework.TableCreator.createTables(TableCreator.java:173)
    at org.eclipse.persistence.tools.schemaframework.TableCreator.createTables(TableCreator.java:150)
    at org.eclipse.persistence.tools.schemaframework.TableCreator.createTables(TableCreator.java:142)
    at org.eclipse.persistence.tools.schemaframework.SchemaManager.createDefaultTables(SchemaManager.java:1030)
    at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.generateDefaultTables(EntityManagerFactoryProvider.java:110)
    at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.writeDDLToDatabase(EntityManagerSetupImpl.java:4436)
    at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.writeDDL(EntityManagerSetupImpl.java:4364)
    at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.writeDDL(EntityManagerSetupImpl.java:4264)
    at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:819)
    ... 20 more
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at io.opentracing.contrib.jdbc.DynamicProxy$1.invoke(DynamicProxy.java:32)
    ... 50 more
Caused by: java.lang.ClassCastException: com.sun.proxy.$Proxy49 cannot be cast to java.sql.PreparedStatement
    at io.opentracing.contrib.jdbc.TracingConnection.prepareStatement(TracingConnection.java:65)
    ... 55 more

My persistence.xml is defined as:

<persistence xmlns="http://java.sun.com/xml/ns/persistence"
             xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_1_0.xsd"
             version="1.0">
  <persistence-unit name="demo" transaction-type="RESOURCE_LOCAL">
    <provider>org.eclipse.persistence.jpa.PersistenceProvider</provider>
    <class>model.Price</class>
    <class>model.Trade</class>
    <properties>
      <property name="javax.persistence.jdbc.driver" value="io.opentracing.contrib.jdbc.TracingDriver"/>
      <property name="javax.persistence.jdbc.url"
                value="jdbc:tracing:derby:memory;create=true;traceWithActiveSpanOnly=true"/>
      <property name="eclipselink.ddl-generation" value="create-tables"/>
      <property name="eclipselink.ddl-generation.output-mode" value="database"/>
      <property name="eclipselink.weaving" value="false"/>
      <property name="eclipselink.logging.level.sql" value="FINE"/>
    </properties>
  </persistence-unit>
</persistence>
malafeev commented 4 years ago

@rlubke fix is released in version 0.2.6, please verify.

rlubke commented 4 years ago

Still failing, but differently - and in a way I can't quite explain.

Caused by: java.sql.SQLSyntaxErrorException: 'DROP TABLE' cannot be performed on 'PRICE' because it does not exist.
    at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
    at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
    at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
    at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
    at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
    at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
    at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(Unknown Source)
    at org.apache.derby.impl.jdbc.EmbedPreparedStatement42.<init>(Unknown Source)
    at org.apache.derby.jdbc.Driver42.newEmbedPreparedStatement(Unknown Source)
    at org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(Unknown Source)
    at org.apache.derby.impl.jdbc.EmbedConnection.prepareStatement(Unknown Source)
    at io.opentracing.contrib.jdbc.TracingConnection.prepareStatement(TracingConnection.java:64)
    ... 46 more
Caused by: ERROR 42Y55: 'DROP TABLE' cannot be performed on 'PRICE' because it does not exist.
    at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
    at org.apache.derby.impl.sql.compile.DDLStatementNode.justGetDescriptor(Unknown Source)
    at org.apache.derby.impl.sql.compile.DDLStatementNode.getTableDescriptor(Unknown Source)
    at org.apache.derby.impl.sql.compile.DDLStatementNode.getTableDescriptor(Unknown Source)
    at org.apache.derby.impl.sql.compile.DropTableNode.bindStatement(Unknown Source)
    at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
    at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
    at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepareInternalStatement(Unknown Source)

Since I last posted, I had changed my persistence settings to drop and create the tables:

<property name="eclipselink.ddl-generation" value="drop-and-create-tables"/>

Version 0.2.4 continues to work, however. I will keep digging on this side, but if you can think of anything I could or should look at, please let me know.

malafeev commented 4 years ago

@rlubke could you provide sample application to reproduce this issue or could you create a unit test like there is one for Hibernate (https://github.com/opentracing-contrib/java-jdbc/blob/master/src/test/java/io/opentracing/contrib/jdbc/HibernateTest.java) ?

Issue is really strange. cc @safris

safris commented 4 years ago

@rlubke, are you receiving this error with v0.2.6? What about with v0.2.7-SNAPSHOT?

rlubke commented 4 years ago

@safris Yes, 0.2.6. I just tried with the head of the master branch and I see the same error.

I haven't quite had a chance to dig further.

malafeev commented 4 years ago

fyi 0.2.7 version is released, although looks like it doesn't fix this problem

cyrille-leclerc commented 4 years ago

I faced a very similar problem and had to revert from opentracing-jdbc 0.2.7 to 0.2.4

Caused by: java.lang.reflect.UndeclaredThrowableException: null
    at com.sun.proxy.$Proxy102.executeQuery(Unknown Source) ~[na:na]
    at com.zaxxer.hikari.pool.ProxyStatement.executeQuery(ProxyStatement.java:111) ~[HikariCP-3.4.1.jar:na]
    at com.zaxxer.hikari.pool.HikariProxyStatement.executeQuery(HikariProxyStatement.java) ~[HikariCP-3.4.1.jar:na]
    at com.wordsmith.words.DatabaseInitializer.postContruct(DatabaseInitializer.java:32) ~[classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_232]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_232]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_232]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_232]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389) ~[spring-beans-5.2.2.RELEASE.jar:5.2.2.RELEASE]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333) ~[spring-beans-5.2.2.RELEASE.jar:5.2.2.RELEASE]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157) ~[spring-beans-5.2.2.RELEASE.jar:5.2.2.RELEASE]
    ... 23 common frames omitted
Caused by: java.lang.reflect.InvocationTargetException: null
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_232]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_232]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_232]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_232]
    at io.opentracing.contrib.jdbc.DynamicProxy$1.invoke(DynamicProxy.java:61) ~[opentracing-jdbc-0.2.7.jar:na]
    ... 34 common frames omitted
Caused by: org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "NOUNS" not found; SQL statement:
select count(*) from nouns [42102-200]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:453) ~[h2-1.4.200.jar:1.4.200]
    ...
    at org.h2.jdbc.JdbcStatement.executeQuery(JdbcStatement.java:78) ~[h2-1.4.200.jar:1.4.200]
    at io.opentracing.contrib.jdbc.TracingStatement.executeQuery(TracingStatement.java:60) ~[opentracing-jdbc-0.2.7.jar:na]
    ... 39 common frames omitted
safris commented 4 years ago

Hi @cyrille-leclerc, this is an error I've not encountered before, but I believe I know how to resolve it. I've submitted PR #65.

safris commented 4 years ago

Hi @rlubke and @cyrille-leclerc, can you advise whether you are still experiencing your last-mentioned issues?

cyrille-leclerc commented 4 years ago

@safris I NO longer face the issue as reported on https://github.com/opentracing-contrib/java-jdbc/pull/65#issuecomment-578163518 .

rlubke commented 4 years ago

Sorry, I was just able to get back to this. I can confirm the issue is resolved in 2.10.