Return-Path: X-Original-To: apmail-logging-log4j-dev-archive@www.apache.org Delivered-To: apmail-logging-log4j-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id EBFA2112EF for ; Wed, 23 Jul 2014 01:57:38 +0000 (UTC) Received: (qmail 1601 invoked by uid 500); 23 Jul 2014 01:57:38 -0000 Delivered-To: apmail-logging-log4j-dev-archive@logging.apache.org Received: (qmail 1545 invoked by uid 500); 23 Jul 2014 01:57:38 -0000 Mailing-List: contact log4j-dev-help@logging.apache.org; run by ezmlm Precedence: bulk List-Unsubscribe: List-Help: List-Post: List-Id: "Log4J Developers List" Reply-To: "Log4J Developers List" Delivered-To: mailing list log4j-dev@logging.apache.org Received: (qmail 1534 invoked by uid 99); 23 Jul 2014 01:57:38 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 23 Jul 2014 01:57:38 +0000 Date: Wed, 23 Jul 2014 01:57:38 +0000 (UTC) From: "Matt Sicker (JIRA)" To: log4j-dev@logging.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (LOG4J2-449) JDBCDatabaseManager not closing timed-out connection MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/LOG4J2-449?page=3Dcom.atlassian= .jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=3D1407= 1256#comment-14071256 ]=20 Matt Sicker commented on LOG4J2-449: ------------------------------------ I don't think this is an issue anymore. For every write() or flush(), a new= connection is obtained, records are written, then committed, then the conn= ection is closed. It would be hard to time out a connection this way. > JDBCDatabaseManager not closing timed-out connection > ---------------------------------------------------- > > Key: LOG4J2-449 > URL: https://issues.apache.org/jira/browse/LOG4J2-449 > Project: Log4j 2 > Issue Type: Bug > Components: Appenders > Affects Versions: 2.0-beta9 > Environment: Jetty 9.0.6 with JNDI (jdbc/logging) through BoneCP = 0.8.0-RELEASE with MySQL Connector/J 5.1.26 > Reporter: Dimitry Declercq > Fix For: 2.0 > > > Using the config below we receive following error when writing to DB afte= r a few days of inactivity.=20 > Assume 2 Applications and a configured connection pool (BoneCP 30m idle t= imeout, mysql wait_timeout=3D8h) accessed by 'jdbc/logging' > - App 1 logs frequently (every 5 minutes) > - App 2 logs only errors (1-2 a week) > App 1 works fine, no errors, logs are written to database > App 2 shows trouble when logging errors more than 1 day after deploy > Error: > {code} > ERROR Unable to write to database [jdbcManager{ description=3DdatabaseApp= ender, bufferSize=3D0, connectionSource=3DdataSource{ name=3Djava:/comp/env= /jdbc/logging, value=3DJDBC URL =3D jdbc:mysql://host1,host2/logging?failOv= erReadOnly=3Dfalse&secondsBeforeRetryMaster=3D60, Username =3D <>, partitions =3D 1, max (per partition) =3D 10, min (per partition) =3D = 2, idle max age =3D 30 min, idle test period =3D 5 min, strategy =3D DEFAUL= T }, tableName=3Dapplication_log, columns=3D[ { name=3Dhost, layout=3Dacc-a= ppserver-1, literal=3Dnull, timestamp=3Dfalse }, { name=3Dcontext, layout= =3D/websocket, literal=3Dnull, timestamp=3Dfalse }, { name=3DeventDate, lay= out=3Dnull, literal=3Dnull, timestamp=3Dtrue }, { name=3Dlevel, layout=3D%l= evel, literal=3Dnull, timestamp=3Dfalse }, { name=3Dclass, layout=3D%c, lit= eral=3Dnull, timestamp=3Dfalse }, { name=3Dmessage, layout=3D%message, lite= ral=3Dnull, timestamp=3Dfalse }, { name=3Dexception, layout=3D%ex{full}, li= teral=3Dnull, timestamp=3Dfalse } ] }] for appender [databaseAppender]. jav= a.lang.reflect.UndeclaredThrowableException > at com.sun.proxy.$Proxy33.setNString(Unknown Source) > at com.jolbox.bonecp.PreparedStatementHandle.setNString(PreparedS= tatementHandle.java:472) > at org.apache.logging.log4j.core.appender.db.jdbc.JDBCDatabaseMan= ager.writeInternal(JDBCDatabaseManager.java:93) > at org.apache.logging.log4j.core.appender.db.AbstractDatabaseMana= ger.write(AbstractDatabaseManager.java:136) > at org.apache.logging.log4j.core.appender.db.AbstractDatabaseAppe= nder.append(AbstractDatabaseAppender.java:103) > at org.apache.logging.log4j.core.config.AppenderControl.callAppen= der(AppenderControl.java:99) > at org.apache.logging.log4j.core.config.LoggerConfig.callAppender= s(LoggerConfig.java:425) > at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerCo= nfig.java:406) > at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerCo= nfig.java:409) > at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerCo= nfig.java:367) > at org.apache.logging.log4j.core.Logger.log(Logger.java:110) > at org.apache.logging.log4j.spi.AbstractLoggerWrapper.log(Abstrac= tLoggerWrapper.java:55) > at org.slf4j.impl.SLF4JLogger.warn(SLF4JLogger.java:333) > at com.lynx.websocket.gateway.GatewayMessageProcessor.handleMessa= ge(GatewayMessageProcessor.java:34) > at com.lynx.websocket.queue.WebSocketConsumer.handleMessage(WebSo= cketConsumer.java:47) > at com.lynx.queue.consumer.QueueConsumer.handleDelivery(QueueCons= umer.java:75) > at com.rabbitmq.client.impl.ConsumerDispatcher$4.run(ConsumerDisp= atcher.java:121) > at com.rabbitmq.client.impl.ConsumerWorkService$WorkPoolRunnable.= run(ConsumerWorkService.java:76) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1145) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:615) > at java.lang.Thread.run(Thread.java:724) > Caused by: java.lang.reflect.InvocationTargetException > at sun.reflect.GeneratedMethodAccessor21.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at com.jolbox.bonecp.MemorizeTransactionProxy.invoke(MemorizeTran= sactionProxy.java:233) > ... 21 more > Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionExc= eption: No operations allowed after statement closed. > at sun.reflect.GeneratedConstructorAccessor292.newInstance(Unknow= n Source) > at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Dele= gatingConstructorAccessorImpl.java:45) > at java.lang.reflect.Constructor.newInstance(Constructor.java:526= ) > at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) > at com.mysql.jdbc.Util.getInstance(Util.java:386) > at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) > at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) > at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975) > at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:920) > at com.mysql.jdbc.StatementImpl.checkClosed(StatementImpl.java:46= 1) > at com.mysql.jdbc.PreparedStatement.setNString(PreparedStatement.= java:5316) > ... 25 more > {code} > Config: > {code} > > > > ${web:contextPath} > ${web:hostName} > > > > > > > > > > > > > > > > > > > > > > > {code} > After a quick look at the code I think the connection is retrieved and op= ened upon application start. Would there be a possibility to either retriev= es connections from the pool when the actual on log event occurs or to reco= nnect in case of connection problems? -- This message was sent by Atlassian JIRA (v6.2#6252) --------------------------------------------------------------------- To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org For additional commands, e-mail: log4j-dev-help@logging.apache.org