zalando/logbook

JsonHttpLogFormatter generated invalid json

cantaylancapraz opened this issue · 3 comments

cantaylancapraz commented

Description

We use JsonHttpLogFormatter for Request Response logging. We discovered a case where invalid json was generated.

Expected Behavior

formatter.format(correlation, response) should generate valid json.

Actual Behavior

formatter.format(correlation, response) generates invalid json like that. As you can see, it doesn't put quote to body, so generated json is invalid.

{
    "origin": "local",
    "type": "response",
    "correlation": "b6cf6a602a7df993",
    "duration": 1481,
    "protocol": "HTTP/1.1",
    "status": 503,
    "headers": {
      "cache-control": [
        "no-cache, no-store, max-age=0, must-revalidate"
      ],
      "content-length": [
        "19"
      ],
      "content-type": [
        "application/json"
      ],
      "date": [
        "Mon, 24 Oct 2022 19:19:15 GMT"
      ],
      "expires": [
        "0"
      ],
      "pragma": [
        "no-cache"
      ],
      "referrer-policy": [
        "no-referrer"
      ],
      "server": [
        "envoy"
      ],
      "vary": [
        "Origin,Access-Control-Request-Method,Access-Control-Request-Headers"
      ],
      "x-content-type-options": [
        "nosniff"
      ],
      "x-envoy-upstream-service-time": [
        "1479"
      ],
      "x-frame-options": [
        "DENY"
      ],
      "x-xss-protection": [
        "1 ; mode=block"
      ]
    },
    "body":no healthy upstream
  }

Steps to Reproduce

  1. Configure your machine as it return json like that using wiremock.
{
  "id" : "0520821d-fddf-4155-b391-747f42d7bd8e",
  "name" : "api",
  "request" : {
    "url" : "/api",
    "method" : "GET"
  },
  "response" : {
    "status" : 503,
    "body" : "no healthy upstream",
    "headers" : {
      "date" : "Mon, 24 Oct 2022 20:22:46 GMT",
      "content-type" : "application/json",
      "strict-transport-security" : "max-age=15724800; includeSubDomains",
      "x-frame-options" : "SAMEORIGIN",
      "x-content-type-options" : "nosniff"
    }
  },
  "uuid" : "0520821d-fddf-4155-b391-747f42d7bd8e",
  "persistent" : true,
  "insertionIndex" : 3
}
  1. Clone https://github.com/cantaylancapraz/logbook-bug-demo
  2. Provide url of server that returns response in step 1 as WIREMOCK_URL. Or you can update default https://github.com/cantaylancapraz/logbook-bug-demo/blob/main/build.gradle.kts#L59
  3. Send http request to localhost:8080/api and get response. Check logs.

Notes

I am planning to write unit test. For some reason, sink not working in tests, even though it works well when I run service using bootrun. If I can solve it, I'll update the procedure.

whiskeysierra commented

Logbook checks the Content-Type of the response to determine whether the body is JSON or not. In this case, there is a header, but the content isn't JSON.

I'd argue the problem is on the server side in this case (envoy, I presume?!).

cantaylancapraz commented

Hi @whiskeysierra ,

I think this issue should be reopened. Because the response is a valid json.
You can use any json validator.
https://codebeautify.org/jsonvalidator/y22e3fdc5

Here, the json generated by JsonHttpLogFormatter is invalid.

whiskeysierra commented