Kevin, I'm not having any luck getting any of that to work. The rest of the code in my project is using slf4j with a log4j backend, so I added:
<property name="openjpa.Log" value="slf4j"/> ...to my persistence.xml, and... log4j.category.openjpa.Tool=INFO log4j.category.openjpa.Runtime=INFO log4j.category.openjpa.Remote=WARN log4j.category.openjpa.DataCache=WARN log4j.category.openjpa.MetaData=WARN log4j.category.openjpa.Enhance=WARN log4j.category.openjpa.Query=WARN log4j.category.openjpa.jdbc.SQL=WARN log4j.category.openjpa.jdbc.SQLDiag=WARN log4j.category.openjpa.jdbc.JDBC=TRACE log4j.category.openjpa.jdbc.Schema=WARN ...to my already existing log4j.properties, which is on the classpath. These jars are on the classpath: slf4j-api-1.6.6.jar slf4j-log4j12-1.6.6.jar log4j-1.2.17.jar The only output I see is the usual: [main] openjpa.Runtime INFO OpenJPA dynamically loaded the class enhancer. Any classes that were not enhanced at build time will be enhanced when they are loaded by the JVM. [main] openjpa.Runtime INFO Starting OpenJPA 2.2.1 [main] openjpa.jdbc.JDBC INFO Using dictionary class "org.apache.openjpa.jdbc.sql.OracleDictionary". Any ideas? Thanks, -Chris On Thu, Jan 31, 2013 at 1:56 PM, Kevin Sutter <kwsut...@gmail.com> wrote: > Hi Chris, > Good to know your plans. Thanks. > > You can get almost all of the JDBC connection access via the JDBC channel > in our logging framework [1]. Unfortunately, I looked at the code and the > constructors don't seem to have a log entry... :-( But, you do get all of > the closes, commits, rollbacks, etc -- all of the normal operations through > a Connection object. So, I'd start with that. > > Updating the Ctor for additional logging would be very easy to do. I would > probably do it in the LoggingConnectionDecorator, like you thought. If you > have issues with building a version of OpenJPA for your testing, ping me > back with the version of OpenJPA that you are using and maybe I can find > time to do a quick update. But, try the JDBC log channel first and see if > that gives you enough information for your specific scenario. > > Thanks, > Kevin > > [1] > http://people.apache.org/~mikedd/nightly.builds/apache-openjpa-2.3.0-SNAPSHOT/docs/docbook/manual.html#ref_guide_logging_channels > > On Thu, Jan 31, 2013 at 12:02 PM, Chris Wolf <cwolf.a...@gmail.com> wrote: > >> I am fully aware that pooling is the way to go, but I want to just >> prove out the simple case first. Also the final deployment will be in >> a JEE container, so it will be doing the pooling. >> >> I really wish there was a logging setting to trace acquire/release of >> JDBC Connections - I looked at the source for (I forget now, something >> like JDBCDatStore) it had logging but not of acquire/release of >> Connections. >> >> What is this LoggingConnectionDecorator? would that help me log >> connection activity? If so, how is it configured? >> >> Thanks, >> >> -Chris >> >> On Thu, Jan 31, 2013 at 12:19 PM, Kevin Sutter <kwsut...@gmail.com> wrote: >> > Hi Chris, >> > Normally, OpenJPA will only request a connection "on demand" [1]. As >> each >> > database access is requested, a connection is obtained, but then it's >> > released when we're done with it. Unless there is some processing or >> > configuration that is telling OpenJPA to hang onto the connection... If >> > nothing jumps out at you, I would suggest tracing (maybe both OpenJPA and >> > database) to see why all of the connections are getting requested and >> > nothing is getting closed. >> > >> > As an aside, I would highly recommend the use of some type of connection >> > pooling. Overall, you will get much better performance if connections >> can >> > be re-used instead of constantly dropping and re-creating connections. >> > Whether you use DBCP or Oracle pooling or some application server's >> > connection pooling mechanism, it doesn't really matter. But, I would >> > suggest using some connection pooling. >> > >> > Good luck, >> > Kevin >> > >> > [1] >> > >> http://people.apache.org/~mikedd/nightly.builds/apache-openjpa-2.3.0-SNAPSHOT/docs/docbook/manual.html#ref_guide_dbsetup_retain >> > >> > On Thu, Jan 31, 2013 at 10:51 AM, Chris Wolf <cwolf.a...@gmail.com> >> wrote: >> > >> >> If I process a small number of records, everything works, however when >> >> I try to process a "real-world" number of records, I get an >> >> "ORA-12519". At first, I thought it was an Oracle issue and after >> >> searching around and getting hits on "solutions" involving increasing >> >> Oracle sessions and processes (there are at least 125 configured), I >> >> was still getting "ORA-12519". I then tailed the TNS listener log and >> >> saw that everytime my OpenJPA process ran, it would consume all the >> >> JDBC connections as if it was using connection pooling with some high >> >> min-connections setting. >> >> >> >> In fact, as the stack trace shows, it's only using >> >> "SimpleDriveDataSource", which I thought didn't pool connections and I >> >> don't have the DBCP jar on my classpath, so why is OpenJPA opening all >> >> these JDBC connections? >> >> >> >> >> >> Thanks, >> >> >> >> >> >> Chris >> >> >> >> >> >> 183 marketdata INFO [main] openjpa.Runtime - Starting OpenJPA 2.2.1 >> >> 214 marketdata INFO [main] openjpa.jdbc.JDBC - Using dictionary >> >> class "org.apache.openjpa.jdbc.sql.OracleDictionary". >> >> Exception in thread "main" <openjpa-2.2.1-r422266:1396819 fatal store >> >> error> org.apache.openjpa.persistence.RollbackException: Listener >> >> refused the connection with the following error: >> >> ORA-12519, TNS:no appropriate service handler found >> >> >> >> at >> >> >> org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:594) >> >> at ms.algo.adapt.test.BeanIODemo.saveToDB(BeanIODemo.java:153) >> >> at ms.algo.adapt.test.BeanIODemo.beanIOTest(BeanIODemo.java:127) >> >> at ms.algo.adapt.test.BeanIODemo.main(BeanIODemo.java:50) >> >> Caused by: <openjpa-2.2.1-r422266:1396819 fatal general error> >> >> org.apache.openjpa.persistence.PersistenceException: Listener refused >> >> the connection with the following error: >> >> ORA-12519, TNS:no appropriate service handler found >> >> >> >> at >> >> org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4958) >> >> at >> >> >> org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4918) >> >> at >> >> >> org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:136) >> >> at >> >> >> org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:110) >> >> at >> >> >> org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:62) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.JDBCStoreManager.connect(JDBCStoreManager.java:971) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.JDBCStoreManager.getConnection(JDBCStoreManager.java:240) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.AbstractJDBCSeq.getConnection(AbstractJDBCSeq.java:163) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.NativeJDBCSeq.allocateInternal(NativeJDBCSeq.java:217) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.NativeJDBCSeq.nextInternal(NativeJDBCSeq.java:201) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.AbstractJDBCSeq.next(AbstractJDBCSeq.java:60) >> >> at >> >> org.apache.openjpa.util.ImplHelper.generateValue(ImplHelper.java:160) >> >> at >> >> >> org.apache.openjpa.util.ImplHelper.generateFieldValue(ImplHelper.java:144) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.JDBCStoreManager.assignField(JDBCStoreManager.java:778) >> >> at >> >> org.apache.openjpa.util.ApplicationIds.assign(ApplicationIds.java:493) >> >> at >> >> org.apache.openjpa.util.ApplicationIds.assign(ApplicationIds.java:469) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.JDBCStoreManager.assignObjectId(JDBCStoreManager.java:762) >> >> at >> >> >> org.apache.openjpa.kernel.DelegatingStoreManager.assignObjectId(DelegatingStoreManager.java:135) >> >> at >> >> >> org.apache.openjpa.kernel.StateManagerImpl.assignObjectId(StateManagerImpl.java:600) >> >> at >> >> >> org.apache.openjpa.kernel.SingleFieldManager.preFlushPC(SingleFieldManager.java:803) >> >> at >> >> >> org.apache.openjpa.kernel.SingleFieldManager.preFlushPCs(SingleFieldManager.java:762) >> >> at >> >> >> org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:664) >> >> at >> >> >> org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:589) >> >> at >> >> >> org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:505) >> >> at >> >> >> org.apache.openjpa.kernel.StateManagerImpl.preFlush(StateManagerImpl.java:3028) >> >> at >> >> org.apache.openjpa.kernel.PNewState.beforeFlush(PNewState.java:44) >> >> at >> >> >> org.apache.openjpa.kernel.StateManagerImpl.beforeFlush(StateManagerImpl.java:1042) >> >> at >> org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2114) >> >> at >> >> org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:2074) >> >> at >> >> >> org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:1992) >> >> at >> >> >> org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81) >> >> at >> >> org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1516) >> >> at >> >> >> org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:933) >> >> at >> >> >> org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:570) >> >> ... 3 more >> >> Caused by: java.sql.SQLException: Listener refused the connection with >> >> the following error: >> >> ORA-12519, TNS:no appropriate service handler found >> >> >> >> at >> oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:517) >> >> at >> >> >> oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:557) >> >> at >> oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:233) >> >> at >> >> >> oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:29) >> >> at >> oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:556) >> >> at >> >> >> org.apache.openjpa.jdbc.schema.SimpleDriverDataSource.getSimpleConnection(SimpleDriverDataSource.java:84) >> >> at >> >> >> org.apache.openjpa.jdbc.schema.AutoDriverDataSource.getConnection(AutoDriverDataSource.java:39) >> >> at >> >> >> org.apache.openjpa.jdbc.schema.SimpleDriverDataSource.getConnection(SimpleDriverDataSource.java:76) >> >> at >> >> >> org.apache.openjpa.lib.jdbc.DelegatingDataSource.getConnection(DelegatingDataSource.java:118) >> >> at >> >> >> org.apache.openjpa.lib.jdbc.DecoratingDataSource.getConnection(DecoratingDataSource.java:93) >> >> at >> >> >> org.apache.openjpa.lib.jdbc.DelegatingDataSource.getConnection(DelegatingDataSource.java:118) >> >> at >> >> >> org.apache.openjpa.jdbc.schema.DataSourceFactory$DefaultsDataSource.getConnection(DataSourceFactory.java:304) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.JDBCStoreManager.connectInternal(JDBCStoreManager.java:982) >> >> at >> >> >> org.apache.openjpa.jdbc.kernel.JDBCStoreManager.connect(JDBCStoreManager.java:967) >> >> ... 31 more >> >> Caused by: oracle.net.ns.NetException: Listener refused the connection >> >> with the following error: >> >> ORA-12519, TNS:no appropriate service handler found >> >> >> >> at oracle.net.ns.NSProtocol.connect(NSProtocol.java:457) >> >> at >> >> oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1625) >> >> at >> oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:365) >> >> ... 44 more >> >> >>