Mikhail Chinkov created LOGBACK-1262: ---------------------------------------- Summary: java.io.IOException: Stream closed in EvaluatorFilter Key: LOGBACK-1262 URL: https://jira.qos.ch/browse/LOGBACK-1262 Project: logback Issue Type: Bug Components: logback-access Affects Versions: 1.2.1, 1.1.6 Environment: OS: Alpine Linux v3.4 (application under Docker) Kernel: 3.10.0-327.10.1.el7.x86_64 (CentOS 7 host) Tomcat version: 7.0.73 Logback-access/core/classic version: 1.1.6 (tried to upgrade to 1.2.1, but it didn't work out)   Reporter: Mikhail Chinkov Assignee: Logback dev list I changed my filter configuration in logback-access to log HTTP requests with full response/request to console instead of file. Configuration that works properly in file: {{<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />}}{{<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">}} {{ <filter class="ch.qos.logback.core.filter.EvaluatorFilter">}} {{ <evaluator>}} {{ <expression>(event.getStatusCode() == 500 || event.getStatusCode() == 400) && (event.getLocalPort() == 8080)</expression>}} {{ </evaluator>}} {{ <onMismatch>DENY</onMismatch>}} {{ <onMatch>NEUTRAL</onMatch>}} {{ </filter>}} {{ <file>$\{catalina.base}/logs/data-api-requests.log</file>}} {{ <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">}} {{ <fileNamePattern>$\{catalina.base}/logs/data-api-requests-%d\{yyyy-MM-dd}.log.%i</fileNamePattern>}} {{ <maxHistory>10</maxHistory>}} {{ <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">}} {{ <maxFileSize>500mb</maxFileSize>}} {{ </timeBasedFileNamingAndTriggeringPolicy>}} {{ </rollingPolicy>}} {{ <encoder>}} {{ <pattern>%a %t\{dd MMM yyyy ;HH:mm:ss,SSS} %fullRequest%n%n%fullResponse</pattern>}} {{ </encoder>}} {{ </appender>}}   New configuration which breaks: {{<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />}}{{<appender name="HTTP" class="ch.qos.logback.core.ConsoleAppender">}} {{ <filter class="ch.qos.logback.core.filter.EvaluatorFilter">}} {{ <evaluator>}} {{ <expression>(event.getStatusCode() == 500 || event.getStatusCode() == 400)</expression>}} {{ </evaluator>}} {{ <onMismatch>DENY</onMismatch>}} {{ <onMatch>NEUTRAL</onMatch>}} {{ </filter>}} {{ <encoder>}} {{ <pattern>%h %l %u %user %date "%r" %s %b%n%n%fullRequest%n%n%fullResponse</pattern>}} {{ </encoder>}} {{ </appender>}}   How breaks? When trying to log event by filter it throws IOException. {{java.io.IOException: Stream closed}} {{ at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:312)}} {{ at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:200)}} {{ at ch.qos.logback.access.servlet.TeeServletInputStream.consumeBufferAndReturnAsByteArray(TeeServletInputStream.java:56)}} {{ at ch.qos.logback.access.servlet.TeeServletInputStream.duplicateInputStream(TeeServletInputStream.java:42)}} {{ at ch.qos.logback.access.servlet.TeeServletInputStream.<init>(TeeServletInputStream.java:30)}} {{ at ch.qos.logback.access.servlet.TeeHttpServletRequest.<init>(TeeHttpServletRequest.java:44)}} {{ at ch.qos.logback.access.servlet.TeeFilter.doFilter(TeeFilter.java:49)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at com.skybonds.data.filter.CORSFilter.doFilter(CORSFilter.java:30)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)}} {{ at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:113)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:748)}} {{ at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:486)}} {{ at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:411)}} {{ at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:338)}} {{ at org.springframework.boot.context.web.ErrorPageFilter.handleErrorStatus(ErrorPageFilter.java:154)}} {{ at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:122)}} {{ at org.springframework.boot.context.web.ErrorPageFilter.access$000(ErrorPageFilter.java:61)}} {{ at org.springframework.boot.context.web.ErrorPageFilter$1.doFilterInternal(ErrorPageFilter.java:95)}} {{ at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)}} {{ at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:113)}} {{ at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)}} {{ at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)}} {{ at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)}} {{ at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)}} {{ at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)}} {{ at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)}} {{ at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)}} {{ at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:254)}} {{ at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)}} {{ at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)}} {{ at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)}} {{ at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1074)}} {{ at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)}} {{ at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314)}} {{ 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)}} When I removed filter, the problem was gone. Also I tried to reconfigure filter. {{<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />}}{{<appender name="HTTP" class="ch.qos.logback.core.ConsoleAppender">}} {{ <filter class="ch.qos.logback.core.filter.EvaluatorFilter">}} {{ <evaluator>}} {{ <expression>(event.getStatusCode() != 200) && (event.getStatusCode() != 303)</expression>}} {{ </evaluator>}} {{ <onMismatch>DENY</onMismatch>}} {{ </filter>}} {{ <encoder>}} {{ <pattern>%h %l %u %user %date "%r" %s %b%n%n%fullRequest%n%n%fullResponse</pattern>}} {{ </encoder>}} {{ </appender>}} This one started to throw events and IOExceptions simultaneously. So, looking for your docs, I configured logback-access to console as mentioned there, but I still get the same exception. Probably, there must be my mistake, but after few-hours debugging still can't get where. So, please, help me to find the problem at this filter. -- This message was sent by Atlassian JIRA (v7.3.1#73012)