[LOG4J2-676] Failed to write log event to CouchDB due to error: Connection pool shut down

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.0-rc1
• Component/s: Appenders
• Labels: appender couchdb nosql

Environment

Apache CouchDB 1.2.0
org.lightcouch.lightcouch-1.3.0
log4j-core-2.0-RC1
--------------------------------------------------------------------------------
java version "1.7.0_09"
Java(TM) SE Runtime Environment (build 1.7.0_09-b05)
Java HotSpot(TM) Server VM (build 23.5-b02, mixed mode)
--------------------------------------------------------------------------------
GlassFish 4.0-89

• Assignee: Unassigned
• Reporter: Phillip
• Created: 22/Jun/14 08:36
• Updated: 26/Jun/14 19:33
• Resolved: 22/Jun/14 18:37

Description

I'm trying to setup a NoSQL logger using Apache CouchDB. After logging a single message, the logger fails with the following exception:

2014-06-22 10:22:18,590 ERROR An exception occurred processing Appender databaseAppender org.apache.logging.log4j.core.appender.AppenderLoggingException: Failed to write log event to CouchDB due to error: Connection pool shut down
at org.apache.logging.log4j.core.appender.db.nosql.couchdb.CouchDBConnection.insertObject(CouchDBConnection.java:57)
at org.apache.logging.log4j.core.appender.db.nosql.NoSQLDatabaseManager.writeInternal(NoSQLDatabaseManager.java:148)
at org.apache.logging.log4j.core.appender.db.AbstractDatabaseManager.write(AbstractDatabaseManager.java:159)
at org.apache.logging.log4j.core.appender.db.AbstractDatabaseAppender.append(AbstractDatabaseAppender.java:103)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:425)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:406)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:367)
at org.apache.logging.log4j.core.Logger.log(Logger.java:112)
at org.apache.logging.log4j.spi.AbstractLogger.error(AbstractLogger.java:577)
at be.pw999.kbomap.controller.KboMapController.getJson(KboMapController.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:125)
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:195)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:91)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:346)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:341)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:101)
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:224)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:198)
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:946)
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:323)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:372)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:335)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:218)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:344)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.apache.logging.log4j.core.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:66)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:316)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:357)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
at java.lang.Thread.run(Thread.java:722)
Caused by: java.lang.IllegalStateException: Connection pool shut down
at org.apache.http.util.Asserts.check(Asserts.java:34)
at org.apache.http.pool.AbstractConnPool.lease(AbstractConnPool.java:169)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:217)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:158)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:186)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
at org.lightcouch.CouchDbClientBase.executeRequest(CouchDbClientBase.java:409)
at org.lightcouch.CouchDbClientBase.put(CouchDbClientBase.java:517)
at org.lightcouch.CouchDbClientBase.save(CouchDbClientBase.java:273)
at org.apache.logging.log4j.core.appender.db.nosql.couchdb.CouchDBConnection.insertObject(CouchDBConnection.java:51)
... 66 more]]

The log4j2.xml file is:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="info">
  <Appenders>
    <NoSql name="databaseAppender">
      <CouchDb databaseName="kbomaplog" protocol="http" server="127.0.0.1" port="5984"
               username="loguser" password="meh" />
    </NoSql>
  </Appenders>
  <Loggers>
    <Root level="info">
      <AppenderRef ref="databaseAppender"/>
    </Root>
  </Loggers>
</Configuration>

And the piece of code I'm using to test is:

	private Logger logger = LogManager.getLogger(KboMapController.class);
	
	/**
	 * Does nothing special. Returns a simple JSON object with a count of the code table for testing purposes.
	 * 
	 * @param id unused
	 * @param test unused
	 * @return a JSON representation of the filled in {@link Enterprise} object.
	 */
	@GET
	@Produces(MediaType.APPLICATION_JSON)
	@Path("{id}/{test}")
	public Enterprise getJson(@PathParam("id") String id, @PathParam("test") String test) {
		try {
			logger.error("whoaaaaaah");
			return new Enterprise("SUCCESS", "COUNT=" + dao.count());
		} catch (SQLException e) {
			return new Enterprise("ERROR", e.getMessage());
		}

	}

The same issue occurs when the logger is static final