getOutputStream() has already been called for this response

[davidjirovec]

When I use Logbook auto configuration with Spring Security with Spring Boot app packaged as war and deployed to Tomcat and try to access non existent url, I get

Whitelabel Error Page

This application has no explicit mapping for /error, so you are seeing this as a fallback.

Tue Mar 07 18:14:22 CET 2017
There was an unexpected error (type=Internal Server Error, status=500).
getOutputStream() has already been called for this response

I have prepared minimal example to reproduce it here

without Logbook it works as expected - basic auth is required
without Spring Security it works as expected - not found error message is shown
when packaged as jar with embedded Tomcat it works perfectly

The problem is not present only when accessing non existent url - if there would be any controllers in my example, you would not be able to access them neither.

[whiskeysierra]

when packaged as jar with embedded Tomcat it works perfectly

I'm not 100% sure how Spring (or Logbook?) behaves differently between embedded and standalone tomcat deployments. We are using the embedded deployment exclusively. @davidjirovec Are you willing to investigate this?

[davidjirovec]

I am very busy sorry :( Anyway the example demonstrates it well I think. I've tried different versions of Tomcat, both standalone and embedded and always same result.

[Infeligo]

I have a similar issue with Logbook and Spring Boot. I noticed that when browser is accessing /favicon.ico, an exception is thrown:

java.lang.IllegalStateException: getOutputStream() has already been called for this response
	at org.apache.catalina.connector.Response.getWriter(Response.java:609) ~[tomcat-embed-core-8.5.11.jar:8.5.11]
	at org.apache.catalina.connector.ResponseFacade.getWriter(ResponseFacade.java:211) ~[tomcat-embed-core-8.5.11.jar:8.5.11]
	at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:109) ~[tomcat-embed-core-8.5.11.jar:8.5.11]
	at org.zalando.logbook.servlet.LocalResponse.withoutBody(LocalResponse.java:88) ~[logbook-servlet-1.1.1.jar:na]
	at org.zalando.logbook.BodyReplacementRawHttpResponse.withBody(BodyReplacementRawHttpResponse.java:24) ~[logbook-core-1.1.1.jar:na]
	at org.zalando.logbook.DefaultLogbook.lambda$write$0(DefaultLogbook.java:48) ~[logbook-core-1.1.1.jar:na]
	at org.zalando.logbook.servlet.NormalStrategy.logResponse(NormalStrategy.java:75) ~[logbook-servlet-1.1.1.jar:na]
	at org.zalando.logbook.servlet.NormalStrategy.doFilter(NormalStrategy.java:40) ~[logbook-servlet-1.1.1.jar:na]
	at org.zalando.logbook.servlet.LogbookFilter.doFilter(LogbookFilter.java:33) ~[logbook-servlet-1.1.1.jar:na]

You can try it for yourself by running the single test in this demo application.

The problem occurs when LocalResponse is marked as without body:

    @Override
    public void withoutBody() throws IOException {
        this.body = null;
        this.bytes = new ByteArrayOutputStream(0);
        this.output = new DataOutputStream(NULL);
        this.stream = super.getOutputStream();
        this.writer = super.getWriter(); // This line causes exception
    }

I would refactor this method, throwing out the last two lines and returning OutputStream and Writer from corresponding getters on demand. Of course, these getters will need to account for two cases: when withoutBody has been called and when it has not been. I don't know if body == null is a good criteria for that or there needs to be a special flag.

[whiskeysierra]

Thanks for the investigation. I guess it would be enough to delay the calls to getOutputStream and getWriter respectively until someone calls either.

[davidjirovec]

Any plans on fix? Thanks.

[whiskeysierra]

@davidjirovec I tried to replicate/fix this locally. I haven't finished it yet.

[whiskeysierra]

@davidjirovec @Infeligo See #153

[whiskeysierra]

@davidjirovec @Infeligo I deployed 1.2.1 just now. Should be in central soon.

[davidjirovec]

Thanks, issue is fixed for the example I've provided originally, but I still run in same problem when I turn on logging messages in logger configuration. Please see #155. I've updated my example to reproduce it again.