[logback-user] JNDI DBAppender with WebLogic pool connection - Cannot call commit when using distributed transactions

Mon Jun 18 06:21:01 CEST 2012

Using Logback classic 1.0.6 (slf4j 1.6.5)
Running on a Weblogic server 10.3.5.

I just added the DBAppender and have some unusual errors that get generated.

My append statement works fine and it does log entries to the database:
       <appender name="DataBase" class="ch.qos.logback.classic.db.DBAppender">
             <connectionSource class="ch.qos.logback.core.db.JNDIConnectionSource">
                    <param name="jndiLocation" value="UCS_DS." />
             </connectionSource>
       </appender>

Weblogic reports the following about the datasource creation (This pool on my local machine starts at 6 and grows by 2 up to 40 connections):

<BEA-001177> <Creating Connection Pool named UCS_DS, URL = jdbc:oracle:thin:@localhost:1521:XE, Properties = user=logback;.>
<BEA-000626> <Free resources in pool "UCS_DS" will be tested every "120" seconds.>
<BEA-001066> <Delaying 6 seconds before making a UCS_DS pool connection.>
<BEA-001516> <Connection Pool "UCS_DS" connected to Database: "Oracle", Version: "Oracle Database 10g Express Edition Release 10.2.0.1.0 - Production".>
<BEA-001517> <Connection Pool "UCS_DS" using Driver: "Oracle JDBC driver", Version: "11.2.0.2.0".>
<BEA-001066> <Delaying 6 seconds before making a UCS_DS pool connection.>
<BEA-001066> <Delaying 6 seconds before making a UCS_DS pool connection.>
<BEA-001066> <Delaying 6 seconds before making a UCS_DS pool connection.>
<BEA-001066> <Delaying 6 seconds before making a UCS_DS pool connection.>
<BEA-001066> <Delaying 6 seconds before making a UCS_DS pool connection.>
<BEA-000628> <Created "6" resources for pool "UCS_DS", out of which "6" are available and "0" are unavailable.>
<BEA-001124> <Created Connection Pool named UCS_DS.>
<BEA-001174> <Creating Data Source named UCS_DS, JNDI Name = UCS_DS.>
<BEA-001512> <Data Source UCS_DS has been successfully created.>

But this error is thrown quite frequently.

20:38:56,700 |-ERROR in ch.qos.logback.classic.db.DBAppender[DataBase] - problem appending event java.sql.SQLException: Cannot call commit when using distributed transactions at java.sql.SQLException: Cannot call commit when using distributed transactions
        at      at weblogic.jdbc.wrapper.JTAConnection.commit(JTAConnection.java:355)
        at      at ch.qos.logback.core.db.DBAppenderBase.append(DBAppenderBase.java:116)
        at      at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
        at      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
        at      at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:282)
        at      at ch.qos.logback.classic.Logger.callAppenders(Logger.java:269)
        at      at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:470)
        at      at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:424)
        at      at ch.qos.logback.classic.Logger.info(Logger.java:628)

And I also see this:

<BEA-001153> <Forcibly releasing inactive connection "[weblogic.jdbc.wrapper.JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection-UCS_DS-2, oracle.jdbc.driver.LogicalConnection at 11d5e99]" back into the connection pool "UCS_DS", currently reserved by: java.lang.Exception
               at weblogic.jdbc.common.internal.ConnectionEnv.setup(ConnectionEnv.java:325)
               at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:363)
               at weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:329)
               at weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:417)
               at weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:324)
               at weblogic.jdbc.common.internal.ConnectionPoolManager.reserve(ConnectionPoolManager.java:94)
               at weblogic.jdbc.common.internal.ConnectionPoolManager.reserve(ConnectionPoolManager.java:63)
               at weblogic.jdbc.jta.DataSource.getXAConnectionFromPool(DataSource.java:1677)
               at weblogic.jdbc.jta.DataSource.refreshXAConnAndEnlist(DataSource.java:1475)
               at weblogic.jdbc.jta.DataSource.getConnection(DataSource.java:446)
               at weblogic.jdbc.jta.DataSource.connect(DataSource.java:403)
               at weblogic.jdbc.common.internal.RmiDataSource.getConnection(RmiDataSource.java:364)
               at ch.qos.logback.core.db.JNDIConnectionSource.getConnection(JNDIConnectionSource.java:63)
               at ch.qos.logback.core.db.ConnectionSourceBase.discoverConnectionProperties(ConnectionSourceBase.java:47)
               at ch.qos.logback.core.db.JNDIConnectionSource.start(JNDIConnectionSource.java:50)
               at ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(NestedComplexPropertyIA.java:167)
               at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:318)
               at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:197)
               at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:183)
               at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
               at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:147)
               at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:133)
               at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:96)
               at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:55)
               at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
               at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
               at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
               at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:54)
               at org.slf4j.LoggerFactory.bind(LoggerFactory.java:128)
               at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
               at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:279)
               at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:252)
               at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:156)
               at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:132)
               at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:645)
               at org.displaytag.tags.TableTag.<clinit>(TableTag.java:104)
               at java.lang.Class.forName0(Native Method)
               at java.lang.Class.forName(Class.java:169)
               at org.displaytag.tags.TableTagBeanInfo.class$(TableTagBeanInfo.java:42)
               at org.displaytag.tags.TableTagBeanInfo.getPropertyDescriptors(TableTagBeanInfo.java:41)
               at java.beans.Introspector.getTargetPropertyInfo(Introspector.java:501)
               at java.beans.Introspector.getBeanInfo(Introspector.java:410)
               at java.beans.Introspector.getBeanInfo(Introspector.java:232)
               at java.beans.Introspector.<init>(Introspector.java:389)
               at java.beans.Introspector.getBeanInfo(Introspector.java:232)
               at java.beans.Introspector.getBeanInfo(Introspector.java:218)
               at weblogic.jsp.internal.jsp.tag.TagInfoEx.getPropertyDescriptorSetterTypes(TagInfoEx.java:554)
               at weblogic.jsp.internal.jsp.tag.TagInfoEx.getSetterTypes(TagInfoEx.java:499)
               at weblogic.jsp.internal.jsp.tag.TagInfoEx.initAttributeTypes(TagInfoEx.java:395)
               at weblogic.jsp.internal.jsp.JspActionChecker.checkActionStart(JspActionChecker.java:287)
               at weblogic.jsp.internal.jsp.JspActionChecker.checkActions(JspActionChecker.java:214)
               at weblogic.jsp.internal.jsp.JspActionChecker.checkActions(JspActionChecker.java:228)
               at weblogic.jsp.internal.jsp.JspActionChecker.check(JspActionChecker.java:150)
               at weblogic.jsp.internal.jsp.JspCheckContext.check(JspCheckContext.java:67)
               at weblogic.jsp.internal.jsp.JspAnalyzer.check(JspAnalyzer.java:57)
               at weblogic.jsp.internal.ProxySourceFile._check(ProxySourceFile.java:136)
               at weblogic.jsp.internal.SourceFile.masterCheck(SourceFile.java:762)
               at weblogic.jsp.internal.SourceFile.check(SourceFile.java:314)
               at weblogic.jsp.internal.SourceFile.check(SourceFile.java:335)
               at weblogic.jsp.internal.ProxySourceFile.codeGen(ProxySourceFile.java:224)
               at weblogic.jsp.internal.SourceFile.codeGen(SourceFile.java:327)
               at weblogic.jsp.internal.client.ClientUtilsImpl$CodeGenJob.run(ClientUtilsImpl.java:599)
               at weblogic.jsp.internal.client.Job.performJob(Job.java:83)
               at weblogic.jsp.internal.client.ThreadPool$WorkerThread.run(ThreadPool.java:217)
.>

So my questions are:

1.      Is there a way to not throw the error?

2.      What type of performance impact can this cause?

Larry Smith

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20120618/e222df18/attachment-0001.html>