Could not open connection after migration from Oracle 10g to 11g driver

0
votes

I have an application with Oracle DB usage, which uses c3p0 and hibernate. After upgrade to Hibernate 4 I'm getting an exception

java.lang.AbstractMethodError: Method oracle/jdbc/driver/T4CPreparedStatement.setBinaryStream(ILjava/io/InputStream;J)V is abstract         at oracle.jdbc.driver.T4CPreparedStatement.setBinaryStream(T4CPreparedStatement.java)
    at oracle.jdbc.driver.T4CPreparedStatement.setBinaryStream(T4CPreparedStatement.java) ~[ojdbc14.jar:Oracle JDBC Driver version - "10.2.0.5.0"]
    at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source) ~[na:na]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_40]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_40]
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.setBinaryStream(NewProxyPreparedStatement.java:2133) ~[c3p0-0.9.2.jar:0.9.2]
    at org.hibernate.type.descriptor.sql.BlobTypeDescriptor$5$1.doBind(BlobTypeDescriptor.java:147) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.type.descriptor.sql.BlobTypeDescriptor$2$1.doBind(BlobTypeDescriptor.java:103) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.type.descriptor.sql.BasicBinder.bind(BasicBinder.java:90) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.type.AbstractStandardBasicType.nullSafeSet(AbstractStandardBasicType.java:286) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.type.AbstractStandardBasicType.nullSafeSet(AbstractStandardBasicType.java:281) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.type.AbstractSingleColumnStandardBasicType.nullSafeSet(AbstractSingleColumnStandardBasicType.java:56) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.dehydrate(AbstractEntityPersister.java:2843) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3121) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3581) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:104) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:465) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:351) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:350) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1258) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]

The proposed solution is to upgrade Oracle driver from 10g to 11g. For that purpose I replaced ojdbc14.jar with ojdbc6.jar (actually to ojdbc6_g.jar for debug symbols). After that application doesn't start any more with exception

org.hibernate.exception.GenericJDBCException: Could not open connection
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:112) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:235) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1471) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
Caused by: java.sql.SQLException: Connections could not be acquired from the underlying database!
    at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106) ~[mchange-commons-java-0.2.3.3.jar:na]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:677) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:134) ~[c3p0-0.9.2.jar:0.9.2]
    at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:139) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    ... 27 common frames omitted
Caused by: com.mchange.v2.resourcepool.CannotAcquireResourceException: A ResourcePool could not acquire a resource from its primary factory or source.
    at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1406) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:594) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:514) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:743) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:670) ~[c3p0-0.9.2.jar:0.9.2]
    ... 31 common frames omitted

I could not see anything neither from c3p0 not from Oracle 11g driver. It appeared it was due to c3p0 0.9.2 is using log4j instead of slf4j, so after adding log4j-over-slf4j I can see Oracle driver throwing an exception, which c3p0 is logging as warning (sic!)

WARN  com.mchange.v2.resourcepool.BasicResourcePool - com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@412960b2 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
java.sql.SQLException: ORA-00604: error occurred at recursive SQL level 1
ORA-01882: timezone region  not found
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:459) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:392) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:384) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIfun.processError(T4CTTIfun.java:767) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIoauthenticate.processError(T4CTTIoauthenticate.java:450) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:539) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:235) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:382) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:822) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:477) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:564) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:251) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:29) ~[ojdbc6_g.jar:11.2.0.4.0]
    at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:563) ~[ojdbc6_g.jar:11.2.0.4.0]
    at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:183) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:172) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:188) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1074) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1061) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1798) ~[c3p0-0.9.2.jar:0.9.2]
    at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:636) [mchange-commons-java-0.2.3.3.jar:na]

This problem can be cured by providing parameter -Duser.timezone=GMT to a command starting JRE. But the question is why I'm running Java 8 on Linux have to do that? My time zone is properly set:

$ date +'%:z %Z'
+03:00 EEST

Why do I have to set additionally a variable?

2
hibernatejdbcoracle11goracle10gc3p0
Are you running with JRE 6 or above? – Mick Mnemonic
And you have double-checked that you have the correct ojdbc6_g.jar for the 11g version (11gR1/2 + minor version) you're connecting to? – Mick Mnemonic
Last thing I can suggest is to check that ojdbc6_g.jar is definitely in the class path of the application. – Mick Mnemonic
if you upgrade c3p0 to 0.9.5.1 (the latest production version), it will log directly to slf4j, no need for the extra log4j bridge. oracle offers FAQs for debugging failure to pick up the default timezone: docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/… || oracle.com/technetwork/java/javase/dst-faq-138158.html (note they recommend a different timezone format than the date command emits). the timezone your JDK picks up might not be known to the database communities.bmc.com/thread/89972 – Steve Waldman
(Obviously it'd be better if setting the server's timezone correctly were always sufficient. But given there seems to be some degree of fragility between server timezone, JVM timezone, and dbms recognition of timezone, using -Duser.timezone= or writing code that explicitly calls TimeZone.setDefault(...) might not be terrible options. You could of course externalize the values that you set into a config file. But probably the first things to try are Oracle's suggestions and perhaps the TZUpdater tool.) – Steve Waldman

2 Answers

1
votes

JDBC 11.2 onwards uses the timezone name (usually obtained from the OS) when connecting to the server. There are numerous reasons to do this, mostly based around obviating numerous DST related issues which occur if you connect using a fixed offset from UTC.

However, if the database doesn't understand the timezone id, then this error will be thrown.

There are various ways of dealing with this, the most preferable being to update the server to a version that does understand the timezone or patch the existing server with the latest timezone patch available.

Alternatively, change the timezone that the client uses either by setting TZ in the environment before execution or using -Duser.timezone=XXXX to change it in the JVM.

Finally, you can also use -Doracle.jdbc.timezoneAsRegion=false to revert to sending a fixed offset on the connection. This is not recommended as it can reintroduce incorrect DST related behaviour.

0
votes

Everything seems to be right on client side. TimeZone.getDefault().getID() returns me Europe/Helsinki. But Oracle DB table V$TIMEZONE_NAMES doesn't contain Europe/Helsinki, resulting in ORA-01882: timezone region not found exception.

One needs to apply DSTv15 Timezone Patches to DB to get Europe/Helsinki there. Otherwise -Duser.timezone=EET must be set explicitly on client side to avoid this resolution and following exception.