Fix when request body is empty string

[ismail2ov]

In Spring Framework, for GET requests the RequestBody is an empty string and throws an error when we want to apply the filter.

Types of changes

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Breaking change (fix or feature that would cause existing functionality to change)

Checklist:

• My change requires a change to the documentation.
• I have updated the documentation accordingly.
• I have added tests to cover my changes.

[whiskeysierra]

In Spring Framework, for GET requests the RequestBody is an empty string

Under which circumstances?

We do check on the Content-Type being application/json (or derivatives). If you have a request that claims to be JSON (Content-Type is set) but the body is empty, then that's not a valid JSON request.

[ismail2ov]

GET requests have Content-Type: application/json and not have a body and Spring returns an empty string that throws enception when trying to parse

[whiskeysierra]

GET requests have Content-Type: application/json and not have a body

But that's an illegal statement in HTTP.
Your content type claims that the request body is a valid JSON document, but an empty string is not valid JSON.
I'd argue that Logbook is not at fault here.
Why do you have that content type on a GET request in the first place?
What's the purpose of that?

[ismail2ov]

I totally agree that the problem is not in the Logbook, but IMHO it must be protected from IllegalArgumentException.

The call workflow is as follows:
Mobile App -> Akamai -> F5 -> WSO2 -> Openshift

I don't know where this content type header is added, but it causes us problems

[whiskeysierra]

IMHO it must be protected from IllegalArgumentException

Agreed. Instead of checking for this particular issue (empty body), why not catch any exception from the JSON parser and handle that (by not doing something). That way we also covered syntactically incorrect JSON bodies, etc.

[ChristianHersevoort]

This exception also happens when the WithoutBodyStrategy is active. It's not limited to GET requests, PUT and POST requests are also broken.

This results in the following exception

java.lang.IllegalArgumentException: json string can not be null or empty
	at com.jayway.jsonpath.internal.Utils.notEmpty(Utils.java:383)
	at com.jayway.jsonpath.internal.ParseContextImpl.parse(ParseContextImpl.java:36)
	at org.zalando.logbook.json.JsonPathBodyFilters$JsonPathBodyFilter.filter(JsonPathBodyFilters.java:99)
	at org.zalando.logbook.NonMergeableBodyFilterPair.filter(NonMergeableBodyFilterPair.java:21)
	at org.zalando.logbook.FilteredHttpResponse.getBodyAsString(FilteredHttpResponse.java:50)
	at org.zalando.logbook.json.JsonHttpLogFormatter.prepareBody(JsonHttpLogFormatter.java:64)
	at org.zalando.logbook.StructuredHttpLogFormatter.prepare(StructuredHttpLogFormatter.java:95)
	at org.zalando.logbook.StructuredHttpLogFormatter.format(StructuredHttpLogFormatter.java:26)
	at org.zalando.logbook.logstash.LogstashLogbackSink.write(LogstashLogbackSink.java:52)
	at org.zalando.logbook.Strategy.write(Strategy.java:119)
	at org.zalando.logbook.DefaultLogbook$1.lambda$process$0(DefaultLogbook.java:55)
	at org.zalando.logbook.servlet.LogbookFilter.write(LogbookFilter.java:87)
	at org.zalando.logbook.servlet.LogbookFilter.doFilter(LogbookFilter.java:80)
	at org.zalando.logbook.servlet.HttpFilter.doFilter(HttpFilter.java:31)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327)
	at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
	at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
	at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:121)
	at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:115)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
	at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:105)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)

[ismail2ov]

Agreed. Instead of checking for this particular issue (empty body), why not catch any exception from the JSON parser and handle that (by not doing something). That way we also covered syntactically incorrect JSON bodies, etc.

If the body is incorrect JSON, we never execute this code. The corner case is when the body does not exist and Spring treats it as an empty string.
This PR solve this problem. I do not believe that we should give solutions to cases that will not occur. This is YAGNI

[whiskeysierra]

@ChristianHersevoort Spot-on observation!

@ismail2ov What about this then:

• Check for empty body and skip the filter
  • Maybe we should skip all body filters altogether in this case? I mean what is there to filter if there is no body, right?
• Catch exceptions from the context.parse(..) call and default to return body as-is

[ismail2ov]

* Check for empty body and skip the filter
  
  * Maybe we should skip all body filters altogether in this case? I mean what is there to filter if there is no body, right?

This solves our problem

* Catch exceptions from the `context.parse(..)` call and default to return body _as-is_

This case will never occur because we already know that it is a valid JSON

[whiskeysierra]

This case will never occur because we already know that it is a valid JSON

Not really. A faulty client could set Content-Type: application/json but send you an XML body.

[ChristianHersevoort]

Also application/json isn't the only content-type that is valid json!
You also have;

application/fhir+json (https://en.wikipedia.org/wiki/Fast_Healthcare_Interoperability_Resources) 
application/geo+json (https://en.wikipedia.org/wiki/GeoJSON)

[whiskeysierra]

Also application/json isn't the only content-type that is valid json!

@ChristianHersevoort You're right, that's also what's implemented in Logbook:

logbook/logbook-json/src/main/java/org/zalando/logbook/json/JsonMediaType.java

Lines 10 to 35 in 1a3fe4e

	static final Predicate<String> JSON = contentType -> {
	if (contentType == null) {
	return false;
	}
	// implementation note: manually coded for improved performance
	if (contentType.startsWith("application/")) {
	int index = contentType.indexOf(';', 12);
	if (index != -1) {
	if (index > 16) {
	// application/some+json;charset=utf-8
	return contentType.regionMatches(index - 5, "+json", 0, 5);
	}
	// application/json;charset=utf-8
	return contentType.regionMatches(index - 4, "json", 0, 4);
	} else {
	// application/json
	if (contentType.length() == 16) {
	return contentType.endsWith("json");
	}
	// application/some+json
	return contentType.endsWith("+json");
	}
	}
	return false;
	};

Since my comment wasn't specifically about this, hence I simplified things a bit.

[ismail2ov]

@ChristianHersevoort In this case, the Content Type is not important, it is important that if the body is an empty string, the code in the IF should not be executed

[ismail2ov]

@whiskeysierra Can we merge this as a temporary solution? This is a blocker for us.

Catch exceptions from the context.parse(..) call and default to return body as-is

IMHO this is very expensive and does not make sense

[whiskeysierra]

IMHO this is very expensive and does not make sense

How is that expensive? The exception would be thrown anyway. It's a question about invasiveness of Logbook. We try to not change the behavior of the application that is instrumented with Logbook. Catching exceptions there would be very much in line with that.

[ismail2ov]

How is that expensive? The exception would be thrown anyway.

The question is more about the design.
IMHO we shouldn't execute parser if we know it won't work.

It's a question about invasiveness of Logbook. We try to not change the behavior of the application that is instrumented with Logbook. Catching exceptions there would be very much in line with that.

Right now Logbook is breaking requests.

[ChristianHersevoort]

In this case, the Content Type is not important, it is important that if the body is an empty string, the code in the IF should not be executed
@ismail2ov Yeah I agree, I wasn't suggesting otherwise.

I don't understand how catching the exception is the ideal solution, but maybe it can be used as temporary fix.

How is that expensive? The exception would be thrown anyway.
@whiskeysierra
It's about preventing an exception to be thrown, and yes exceptions CAN be really expensive and should be avoided see; https://shipilev.net/blog/2014/exceptional-performance/

It's a question about invasiveness of Logbook. We try to not change the behavior of the application that is instrumented with Logbook. Catching exceptions there would be very much in line with that.
@whiskeysierra
I agree that invasive changes should be avoided as much as possible. But in this case it's not changing anything to the the behavior, it's only fixing a broken case in the "JsonPathBodyFilters" and making it more lenient / forgiving.

[ismail2ov]

I totally agree with @ChristianHersevoort

[whiskeysierra]

IMHO we shouldn't execute parser if we know it won't work.

Ideally yes, but in order to catch every single invalid input that would make the parser fail you'd need to implement the same parser again... Empty inputs are just one of endless possibilities of invalid inputs.

Right now Logbook is breaking requests.

Exactly, and it very much should not.
That's why I'm proposing to:

1. Handle empty bodies and
2. Exceptions during body parsing
   in the very same way, by ignoring them and leaving the body as-is.

It's about preventing an exception to be thrown

I'm fine with handling empty bodies separately.
But as stated above, empty bodies are just one possible cause of the parser failing.

yes exceptions CAN be really expensive and should be avoided see;

We're not using exceptions for control flows in tight loops and we don't throw exceptions where there wasn't one being thrown to begin with. So I don't see how the performance argument can be made here.

But in this case it's not changing anything to the the behavior, it's only fixing a broken case in the "JsonPathBodyFilters" and making it more lenient / forgiving.

You really gotta see the empty body in the bigger picture here.
Logbook, as of today, is very much breaking the behavior of the instrumented application here.

An application should react to requests in the very same way, regardless of whether it's instrumented with Logbook or not.
Today: That principle is violated in the following cases:

• Empty body
• Syntactically incorrect JSON
• YAML instead of JSON
• XML instead of JSON
• endless more possibilities...

(Hopefully in the) Future: The principle is not violated.
As you can see from the list above, by fixing empty bodies, you just eliminated one of infinite possible errors instead of all of them.
For performance reasons, we should be checking for empty bodies, because:

1. They happen right now in real-world applications and they hurt
2. It's easy to do
3. It's faster than throwing and catching useless exceptions

However, that does not mean we should not also do catch exceptions, because:

1. It's easy to do
2. It's preserves the application's original behavior
3. It's economically cheaper than re-implementing a full JSON parser to check for correctness
   (Granted, nobody complain about this until now, but why wait for somebody to stumble over this before we fix it?)

[ChristianHersevoort]

@whiskeysierra
I agree with everything what you are saying, but maybe it can be split the fix in 2 parts;

Part 1: (this) hotfix , only fixing this specific issue in the JsonPathBodyFilters. Ignoring (semi) unrelated content issues

Part 2. Refactor of how BodyFiltering works; This will probably be a major (breaking) change.

[ismail2ov]

@whiskeysierra I totally agree with you.

What do you think of this approach? I'm logging only the class name of the exception to avoid problems if the exception is NPE

[whiskeysierra]

👍

[whiskeysierra]

@ismail2ov Great, let's go with that for now and we'll re-visit BodyFilters in general and whether we should skip or augment them with exception handling in general (not just the JSON ones).