BodyFilter can affect request body processed by Spring Boot!

[jmeekseon]

When using a BodyFilter on a multipart/form-data request, the request body processed by Spring Boot is affected.

Description

Logging should never affect the request/response of the underlying system. Under particular circumstances, logbook appears to violate this principal. One case where this occurs is when a BodyFilter is applied a multipart/form-data request body where the request body contains a JSON part and an uploaded file (binary) part.

The example StripBinaryBodyFilter, when turned on for multipart/form-data described above, leads to HTTP 400 errors because the request body processed by Spring Boot becomes malformed.

Expected Behavior

It should not affect underlying request body.

Actual Behavior

The underlying HTTP request is affected, which leads to an HTTP 400 error.

Possible Fix

My only guess is that for certain types of streamed or chunked requests, the BodyFilter does not receive an actual copy of the request body.

Steps to Reproduce

Use example below.

Context

Since we are using a multipart with a JSON part and a binary part, we'd like to log the JSON but strip out the binary part.

Your Environment

• Version used: Tested with Spring Boot 2.2.6 & 2.2.10; Logbook 2.1.4, 2.2.0
• Link to your project: (see example Logbook wiring below)

@Configuration
class LogbookWiring {
    @Bean
    fun customLogbook(
        settings: CustomLogbackSettings
    ): Logbook {
        return Logbook.builder()
	    // comment out the line below to enable default RequestFilters. This prevents the StripBinaryBodyFilter
	    // from processing the multipart/form-data request body
            .requestFilter(RequestFilter.none())
            .headerFilter(authorization())
            .bodyFilter(StripBinaryBodyFilter)
            .build()
    }
}

/**
 * This filter truncates a body when it gets "excessively binary".
 */
object StripBinaryBodyFilter : BodyFilter {
    override fun filter(contentType: String?, body: String): String {
        val startBinThreshold = 6
        var unprintableCount = 0
        var curIdx = 0
        var startIdx: Int = 0
        var endIdx: Int

        val charBytes = body.toCharArray()
        val result = StringBuffer(1024)
        charBytes.forEach {
            // The char types below are indicators that it is getting "more binary".
            if (UNASSIGNED.contains(it) || CONTROL.contains(it) || OTHER_SYMBOL.contains(it)) {
                unprintableCount += 1
            } else {
                unprintableCount = 0
            }
            if (unprintableCount == startBinThreshold) {
                endIdx = curIdx - startBinThreshold
                result.append(charBytes.sliceArray(startIdx..endIdx))
                return result.toString()
            }
            curIdx += 1
        }
        return body
    }
}

[whiskeysierra]

What kind of Spring Boot environment do you have? Are you using Spring Web with Servlets? Or Spring WebFlux?

[whiskeysierra]

Can you confirm you read the section after Beware here: https://github.com/zalando/logbook#servlet as well as #94?
Forms and multipart requests on top of the Servlet API are impossible to process without violating the principle that you mentioned.

[jmeekseon]

@whiskeysierra -- I understand the Beware comment in the servlet section. I can confirm that this is not issue in my case since I'm using Spring Boot and I see that in LogbookAutoConfiguration that the SecureLogbookFilter is registered with the REQUEST, ASYNC dispatcher types.

I also understand the #94 , especially with regards to the comment about multipart/form-data.

Also, I am using Servlets (not WebFlux).

[whiskeysierra]

is registered with the REQUEST, ASYNC dispatcher types

Sorry, I was referring to the section directly below:

The LogbookFilter will, by default, treat requests with a application/x-www-form-urlencoded body not different from any other request, i.e you will see the request body in the logs. The downside of this approach is that you won't be able to use any of the HttpServletRequest.getParameter*(..) methods. See issue #94 for some more details.

[whiskeysierra]

Also, I am using Servlets (not WebFlux).

Then, I believe, you subject to this limitation of Servlets, because Spring is built on top of that.

[jmeekseon]

Understood. As this is a known issue, it not a true bug, per se.