Filebeat strips last characters of JSON


(Sander Mathijssen) #1

Hi all,

I have a strange problem parsing a JSON-ish file.
We log in a JSON format where a multiline string can be added in a Message field.

TLDR;

Filebeat doesn't send the last two }} of the file for some reason.

Sourcefile:

{ "@timestamp":"2018-07-06T18:32:59.0864644+02:00", "Level":"Error", "Event": { "Context": "Default", "Message":"Error while executing the Task: Unable to connect to the remote server, StackTrace:    at blabablablablablabablablablablabablablablablabablablabla
   at blabablablabla()
   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla
   at blabablablablablabablablablablabablablablablabablablablablabablablabla
   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla
   at blabablablablablabablablablablabablablablablabablablablablabablablabla"}}
{ "@timestamp":"2018-07-06T19:32:59.0864644+02:00", "Level":"Error", "Event": { "Context": "Default", "Message":"Error while executing the Task: Unable to connect to the remote server, StackTrace:    at blabablablablablabablablablablabablablablablabablablabla
   at blabablablabla()
   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla
   at blabablablablablabablablablablabablablablablabablablablablabablablabla
   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla
   at blabablablablablabablablablablabablablablablabablablablablabablablabla"}}

When I parse this with Filebeat with the following config:

filebeat.inputs:
- type: log
  paths:
  - C:\Logs\*.jlog
  #exclude_files: ['.*SbrRequestServerService.*'] #This should not exist in the log dir.
  fields_under_root: true
  multiline.pattern: '^{'
  multiline.negate: true
  multiline.match: after
output:
  logstash:
    hosts: ["localhost:3542"]

And parse it in Logstash like so:

filter { 
   if [type] == "jlog" {
        mutate { 
            gsub => ["message", "\n", ""] 
        }
        json {
            source => "message"
        }          
    }
}

I see that the last logline is missing it's }} in the message field.
The parsing fails for that one.

[2018-07-13T06:34:38,086][WARN ][logstash.filters.json    ] Error parsing json {:source=>"message", :raw=>"{ \"@timestamp\":\"2018-07-06T19:32:59.0864644+02:00\", \"Level\":\"Error\", \"Event\": { \"Context\": \"Default\", \"Message\":\"Error while executing the Task: Unable to connect to the remote server, StackTrace:    at blabablablablablabablablablablabablablablablabablablabla   at blabablablabla()   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla", :exception=>#<LogStash::Json::ParserError: Unexpected end-of-input in VALUE_STRING
 at [Source: (byte[])"{ "@timestamp":"2018-07-06T19:32:59.0864644+02:00", "Level":"Error", "Event": { "Context": "Default", "Message":"Error while executing the Task: Unable to connect to the remote server, StackTrace:
at blabablablablablabablablablablabablablablablabablablabla   at blabablablabla()   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablaba"[truncated 79 bytes]; line: 1, column: 1159]>}
{
  "@version" => "1",
      "type" => "jlog",
   "message" => "{ \"@timestamp\":\"2018-07-06T18:32:59.0864644+02:00\", \"Level\":\"Error\", \"Event\": { \"Context\": \"Default\", \"Message\":\"Error while executing the Task: Unable to connect to the remote server, StackTrace:    at blabablablablablabablablablablabablablablablabablablabla   at blabablablabla()   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablabla**bla\"}}**",
"prospector" => {
    "type" => "log"
},
      "host" => {
    "name" => "LT-3T2S1G2"
},
     "Event" => {
    "Context" => "Default",
    "Message" => "Error while executing the Task: Unable to connect to the remote server, StackTrace:    at blabablablablablabablablablablabablablablablabablablabla   at blabablablabla()   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablabla"
},
    "source" => "C:\\Logs\\0e44c70a-1740-49d7-ab12-6492bbe78251_2018-07-06_1864_Default.jlog",
     "input" => {
    "type" => "log"
},
      "beat" => {},
     "Level" => "Error",
"@timestamp" => 2018-07-06T16:32:59.086Z,
      "tags" => []
}
{
  "@version" => "1",
      "type" => "jlog",
   "message" => "{ \"@timestamp\":\"2018-07-06T19:32:59.0864644+02:00\", \"Level\":\"Error\", \"Event\": { \"Context\": \"Default\", \"Message\":\"Error while executing the Task: Unable to connect to the remote server, StackTrace:    at blabablablablablabablablablablabablablablablabablablabla   at blabablablabla()   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablabla   at blabablablablablabablablablablabablablablablabablablablablabablablablablabablablablablababla**blabla"**,
"prospector" => {
    "type" => "log"
},
      "host" => {
    "name" => "LT-3T2S1G2"
},
     "input" => {
    "type" => "log"
},
    "source" => "C:\\Logs\\0e44c70a-1740-49d7-ab12-6492bbe78251_2018-07-06_1864_Default.jlog",
      "beat" => {},
"@timestamp" => 2018-07-13T06:34:26.280Z,
      "tags" => [
    [0] "_jsonparsefailure"
]
}

When I add a newline after the last line, the parsing succeeds.

filebeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:09:04 +0000 UTC]

BTW:

Th reason we do this is so that we are able to read Message field with newline chars. Is there a better way to parse this?

Best regards,
Sander


(Jaime Soriano) #2

Hi @Sander_Ma and welcome! :slight_smile:

You can use filebeat directly to parse JSON when the log file includes an object per line, as seems to be in your case. This will help you to avoid tricky multiline configurations for this case.

You have to enable one of the json options to make it work. And then you won't need the multiline configuration in filebeat, or the json parsing in logstash.


(Sander Mathijssen) #3

Hi Jaime,

Thnx for the welcome!

Unfortunately, the log isn't one line, so that isn't going to work.
To make things more complicated:

The JSON message field contains newline chars, and that isn't valid JSON to begin with. So some voodoo is needed to make this work.

Normally you would have something like this:

{ID: 8181,Event:{Message:"This is a message"}}

That will work with the default JSON parser of filebeat.

We have this:

{ID: 8181,Event:{Message:"This is a message
and it continues on this line
And so on."}}

As you can see, this isn't valid.
So I read it like:

multiline.pattern: '^{'
multiline.negate: true
multiline.match: after

When I do that, the last entry will be missing it's }} characters, and Logstash cannot parse the JSON.
The line above it does.


(Sander Mathijssen) #4

How does the multiline filtering work using the json message field?
Given that the json I try to read isn't valid json (it contains a multiline string as value) can I still read it as json? What would you guys advise?


(system) #5

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.