JNDI DBAppender with WebLogic pool connection - Cannot call commit when using distributed transactions
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@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
Hi Larry, The SQLException is rather explicit. DBAppedner "cannot call commit when using distributed transactions". The commit occurs on line 116 of DBAppenderBase. Ideally, DBAppender should be able to automatically determine whether it participates in a distributed transactions and skip committing. If that is not feasible, there should be an explicit property telling DBAppedner not to commit. Please create a jira issue to request this feature/fix. Does error BEA-001153 occur independently of DBAppender? If so, I suspect DBAppender is not at cause here. Cheers, -- Ceki http://twitter.com/#!/ceki On 18.06.2012 06:21, Smith, Larry (ECS - Enterprise Cloud Service) wrote:
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:
<appendername=/"DataBase"/ class=/"ch.qos.logback.classic.db.DBAppender"/>
<connectionSourceclass=/"ch.qos.logback.core.db.JNDIConnectionSource"/>
<paramname=/"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@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
participants (2)
-
ceki -
Smith, Larry (ECS - Enterprise Cloud Service)