We run a periodic health check against our Camunda engine to ensure that it is healthy. This health check simply issues the REST API request: GET /engine.
We noticed this morning that this request was failing. The Catalina log for this time period has numerous log entries consisting of two types of errors:
- a failure executing GET /engine due to java.io.IOException: Broken pipe
- a database error due to an empty connection pool.
It seems that these errors are related, as they are interspersed in the log. But I am not sure if they are related or not.
The log entries are shown below at the end of this post.
We are running Camunda 7.5, stand-alone, using an AWS Aurora DB.
Here is our DB configuration:
<Resource name="jdbc/ProcessEngine" auth="Container" type="javax.sql.DataSource" factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" uniqueResourceName="process-engine" driverClassName="com.mysql.jdbc.Driver" url="jdbc:mysql://<redacted>?autoReconnect=true" username="<redacted" password="<redacted>" maxActive="20" minIdle="5"/>
Do you have any ideas of the cause of either of these errors?
Do you believe that the 2 errors are related?
Perhaps we need some additional DB configuration options?
Here are some of the log entries:
03-Feb-2017 10:08:45.628 SEVERE [http-nio-8080-exec-6076] org.jboss.resteasy.logging.impl.Slf4jLogger.error Failed executing GET /engine
org.jboss.resteasy.spi.WriterException: org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
at org.jboss.resteasy.core.ServerResponse.writeTo(ServerResponse.java:262)
at org.jboss.resteasy.core.SynchronousDispatcher.writeJaxrsResponse(SynchronousDispatcher.java:602)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:528)
at org.jboss.resteasy.core.SynchronousDispatcher.invokePropagateNotFound(SynchronousDispatcher.java:169)
at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:212)
at org.jboss.resteasy.plugins.server.servlet.FilterDispatcher.doFilter(FilterDispatcher.java:59)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.camunda.bpm.engine.rest.filter.CacheControlFilter.doFilter(CacheControlFilter.java:41)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:617)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1527)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1484)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:393)
at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:426)
at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:342)
at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:317)
at org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:110)
at org.jboss.resteasy.plugins.server.servlet.HttpServletResponseWrapper$DeferredOutputStream.flush(HttpServletResponseWrapper.java:52)
at org.jboss.resteasy.util.CommitHeaderOutputStream.flush(CommitHeaderOutputStream.java:59)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1022)
at com.fasterxml.jackson.databind.ObjectWriter.writeValue(ObjectWriter.java:891)
at com.fasterxml.jackson.jaxrs.base.ProviderBase.writeTo(ProviderBase.java:635)
at org.jboss.resteasy.core.interception.MessageBodyWriterContextImpl.proceed(MessageBodyWriterContextImpl.java:117)
at org.jboss.resteasy.plugins.interceptors.encoding.GZIPEncodingInterceptor.write(GZIPEncodingInterceptor.java:104)
at org.jboss.resteasy.core.interception.MessageBodyWriterContextImpl.proceed(MessageBodyWriterContextImpl.java:123)
at org.jboss.resteasy.core.ServerResponse.writeTo(ServerResponse.java:250)
... 26 more
Caused by: java.io.IOException: Broken pipe
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471)
at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:127)
at org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:101)
at org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:173)
at org.apache.coyote.http11.InternalNioOutputBuffer.writeToSocket(InternalNioOutputBuffer.java:139)
at org.apache.coyote.http11.InternalNioOutputBuffer.addToBB(InternalNioOutputBuffer.java:197)
at org.apache.coyote.http11.InternalNioOutputBuffer.access$000(InternalNioOutputBuffer.java:41)
at org.apache.coyote.http11.InternalNioOutputBuffer$SocketOutputBuffer.doWrite(InternalNioOutputBuffer.java:320)
at org.apache.coyote.http11.filters.IdentityOutputFilter.doWrite(IdentityOutputFilter.java:93)
at org.apache.coyote.http11.AbstractOutputBuffer.doWrite(AbstractOutputBuffer.java:256)
at org.apache.coyote.Response.doWrite(Response.java:503)
at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:388)
... 39 more
03-Feb-2017 10:08:45.629 WARNING [http-nio-8080-exec-6047] org.camunda.bpm.engine.rest.exception.ProcessEngineExceptionHandler.toResponse org.camunda.bpm.engine.ProcessEngineException: Process engine persistence exception
at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.rethrow(CommandInvocationContext.java:60)
at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:291)
at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:113)
at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:66)
at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
at org.camunda.bpm.engine.impl.TaskServiceImpl.getVariablesTyped(TaskServiceImpl.java:205)
at org.camunda.bpm.engine.rest.sub.task.impl.TaskVariablesResource.getVariableEntities(TaskVariablesResource.java:45)
at org.camunda.bpm.engine.rest.sub.impl.AbstractVariablesResource.getVariables(AbstractVariablesResource.java:64)
at sun.reflect.GeneratedMethodAccessor245.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167)
at org.jboss.resteasy.core.ResourceMethod.invokeOnTarget(ResourceMethod.java:257)
at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:222)
at org.jboss.resteasy.core.ResourceLocator.invokeOnTargetObject(ResourceLocator.java:159)
at org.jboss.resteasy.core.ResourceLocator.invoke(ResourceLocator.java:107)
at org.jboss.resteasy.core.ResourceLocator.invokeOnTargetObject(ResourceLocator.java:154)
at org.jboss.resteasy.core.ResourceLocator.invoke(ResourceLocator.java:107)
at org.jboss.resteasy.core.ResourceLocator.invokeOnTargetObject(ResourceLocator.java:154)
at org.jboss.resteasy.core.ResourceLocator.invoke(ResourceLocator.java:92)
at org.jboss.resteasy.core.SynchronousDispatcher.getResponse(SynchronousDispatcher.java:542)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:524)
at org.jboss.resteasy.core.SynchronousDispatcher.invokePropagateNotFound(SynchronousDispatcher.java:169)
at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:212)
at org.jboss.resteasy.plugins.server.servlet.FilterDispatcher.doFilter(FilterDispatcher.java:59)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.camunda.bpm.engine.rest.filter.CacheControlFilter.doFilter(CacheControlFilter.java:41)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:617)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1527)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1484)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.apache.tomcat.jdbc.pool.PoolExhaustedException: [http-nio-8080-exec-6047] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:20; busy:17; idle:3; lastwait:30000].
### The error may exist in org/camunda/bpm/engine/impl/mapping/entity/Task.xml
### The error may involve org.camunda.bpm.engine.impl.persistence.entity.TaskEntity.selectTask
### The error occurred while executing a query
### Cause: org.apache.tomcat.jdbc.pool.PoolExhaustedException: [http-nio-8080-exec-6047] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:20; busy:17; idle:3; lastwait:30000].
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:26)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:111)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:102)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:66)
at org.camunda.bpm.engine.impl.db.sql.DbSqlSession.selectById(DbSqlSession.java:100)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.selectById(DbEntityManager.java:199)
at org.camunda.bpm.engine.impl.persistence.entity.TaskManager.findTaskById(TaskManager.java:115)
at org.camunda.bpm.engine.impl.cmd.GetTaskVariablesCmd.execute(GetTaskVariablesCmd.java:51)
at org.camunda.bpm.engine.impl.cmd.GetTaskVariablesCmd.execute(GetTaskVariablesCmd.java:33)
at org.camunda.bpm.engine.impl.interceptor.CommandExecutorImpl.execute(CommandExecutorImpl.java:24)
at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:104)
... 43 more
Caused by: org.apache.tomcat.jdbc.pool.PoolExhaustedException: [http-nio-8080-exec-6047] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:20; busy:17; idle:3; lastwait:30000].
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:672)
at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:186)
at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:127)
at org.apache.ibatis.transaction.jdbc.JdbcTransaction.openConnection(JdbcTransaction.java:134)
at org.apache.ibatis.transaction.jdbc.JdbcTransaction.getConnection(JdbcTransaction.java:61)
at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:279)
at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:72)
at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:59)
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:267)
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:137)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:96)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:77)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:108)
... 52 more