Configure kv plugin to handle multi line messages

[yasko (Yasen Terziivanov)]

I'm collecting logs using filebeat and sending them to logstash for processing.
The log format is:

timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: something happened

In logstash I've setup the kv plugin to create the fields and values.
All works well until a multi line message is received.
In filebeat I've configured the input to handle multi line messages - here's the config:

- type: log
  multiline:
    pattern: '^timestamp'
    negate: true
    match: after
  paths:
    - /mnt/logs/*.log

Filebeat sends the entire message and also logstash, but the kv plugin seems to handle it only until a new line is reached:

input {
  beats {...}
}

filter {
  kv {
    field_split_pattern => "\s*,\s"
    value_split => ":"
  }
}

output {...}

When I put the message value in square brackets all lines of the message are included, the problem is that the message can have all kinds of brackets (SPARQL queries) and that breaks the message again to only a single line.

So, is there a way I can configure the kv plugin to handle multiline messages?

[shrikantgulia (Shrikant)]

Hello @yasko,
Can you please post some logs

Best Regards
Shrikant

[yasko (Yasen Terziivanov)]

@shrikantgulia Sure

Filebeat:

{
"level": "debug",
"timestamp": "2019-01-24T07:23:15.429Z",
"logger": "publish",
"caller": "pipeline/processor.go:308",
"message": "Publish event: {\n  \"@timestamp\": \"2019-01-24T07:23:15.429Z\",\n  \"@metadata\": {\n    \"beat\": \"filebeat\",\n    \"type\": \"doc\",\n    \"version\": \"6.5.4\"\n  },\n  \"log\": {\n    \"flags\": [\n      \"multiline\"\n    ]\n  },\n  \"message\": \"timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: just this line\\nof the\\nmessage is stored\",\n  \"prospector\": {\n    \"type\": \"log\"\n  },\n  \"input\": {\n    \"type\": \"log\"\n  },\n  \"beat\": {\n    \"name\": \"cujo\",\n    \"hostname\": \"af02ce3109dd\",\n    \"version\": \"6.5.4\"\n  },\n  \"host\": {\n    \"name\": \"cujo\"\n  },\n  \"source\": \"/mnt/logs/sample.log\",\n  \"offset\": 0\n}"
}
{
"level": "debug",
"timestamp": "2019-01-24T07:23:15.429Z",
"logger": "publish",
"caller": "pipeline/processor.go:308",
"message": "Publish event: {\n  \"@timestamp\": \"2019-01-24T07:23:15.429Z\",\n  \"@metadata\": {\n    \"beat\": \"filebeat\",\n    \"type\": \"doc\",\n    \"version\": \"6.5.4\"\n  },\n  \"prospector\": {\n    \"type\": \"log\"\n  },\n  \"input\": {\n    \"type\": \"log\"\n  },\n  \"beat\": {\n    \"name\": \"cujo\",\n    \"hostname\": \"af02ce3109dd\",\n    \"version\": \"6.5.4\"\n  },\n  \"host\": {\n    \"name\": \"cujo\"\n  },\n  \"offset\": 99,\n  \"log\": {\n    \"flags\": [\n      \"multiline\"\n    ]\n  },\n  \"message\": \"timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: [proper multi\\nline\\nmessage because of the brackets]\",\n  \"source\": \"/mnt/logs/sample.log\"\n}"
}
{
"level": "debug",
"timestamp": "2019-01-24T07:23:20.430Z",
"logger": "publish",
"caller": "pipeline/processor.go:308",
"message": "Publish event: {\n  \"@timestamp\": \"2019-01-24T07:23:15.429Z\",\n  \"@metadata\": {\n    \"beat\": \"filebeat\",\n    \"type\": \"doc\",\n    \"version\": \"6.5.4\"\n  },\n  \"source\": \"/mnt/logs/sample.log\",\n  \"offset\": 210,\n  \"log\": {\n    \"flags\": [\n      \"multiline\"\n    ]\n  },\n  \"message\": \"timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: [but if I have brackets in\\nthe [message] it doesnt work again]\",\n  \"prospector\": {\n    \"type\": \"log\"\n  },\n  \"input\": {\n    \"type\": \"log\"\n  },\n  \"beat\": {\n    \"hostname\": \"af02ce3109dd\",\n    \"version\": \"6.5.4\",\n    \"name\": \"cujo\"\n  },\n  \"host\": {\n    \"name\": \"cujo\"\n  }\n}"
}

Logstash:

[2019-01-24T10:08:15,300][DEBUG][logstash.pipeline        ] filter received {"event"=>{"input"=>{"type"=>"log"}, "prospector"=>{"type"=>"log"}, "message"=>"timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: just this line\nof the \nmessage is stored", "@timestamp"=>2019-01-24T10:07:10.976Z, "beat"=>{"hostname"=>"0b3b67f06ae8", "name"=>"cujo", "version"=>"6.5.4"}, "source"=>"/mnt/logs/sample.log", "log"=>{"flags"=>["multiline"]}, "tags"=>["kv", "beats_input_codec_plain_applied"], "@version"=>"1", "host"=>{"name"=>"cujo"}, "offset"=>0}}
[2019-01-24T10:08:15,301][DEBUG][logstash.pipeline        ] filter received {"event"=>{"input"=>{"type"=>"log"}, "prospector"=>{"type"=>"log"}, "message"=>"timestamp: 2019-01-24T07:23:15.429Z, level: INFO, message: [proper multi\nline\nmessage because of the brackets]", "@timestamp"=>2019-01-24T10:07:10.976Z, "beat"=>{"hostname"=>"0b3b67f06ae8", "name"=>"cujo", "version"=>"6.5.4"}, "source"=>"/mnt/logs/sample.log", "log"=>{"flags"=>["multiline"]}, "tags"=>["kv", "beats_input_codec_plain_applied"], "@version"=>"1", "host"=>{"name"=>"cujo"}, "offset"=>100}}
[2019-01-24T10:08:15,309][DEBUG][logstash.pipeline        ] filter received {"event"=>{"input"=>{"type"=>"log"}, "prospector"=>{"type"=>"log"}, "message"=>"timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: [but if I have brackets in\nthe [message] it doesnt work again]", "@timestamp"=>2019-01-24T10:07:10.976Z, "beat"=>{"hostname"=>"0b3b67f06ae8", "name"=>"cujo", "version"=>"6.5.4"}, "source"=>"/mnt/logs/sample.log", "log"=>{"flags"=>["multiline"]}, "tags"=>["kv", "beats_input_codec_plain_applied"], "@version"=>"1", "host"=>{"name"=>"cujo"}, "offset"=>211}}
[2019-01-24T10:08:15,370][DEBUG][logstash.pipeline        ] output received {"event"=>{"input"=>{"type"=>"log"}, "level"=>"INFO", "prospector"=>{"type"=>"log"}, "message"=>"[but if I have brackets in", "@timestamp"=>2019-01-24T07:04:42.322Z, "beat"=>{"hostname"=>"0b3b67f06ae8", "name"=>"cujo", "version"=>"6.5.4"}, "source"=>"/mnt/logs/sample.log", "log"=>{"flags"=>["multiline"]}, "tags"=>["kv", "beats_input_codec_plain_applied"], "@version"=>"1", "host"=>{"name"=>"cujo"}, "offset"=>211}}
[2019-01-24T10:08:15,370][DEBUG][logstash.pipeline        ] output received {"event"=>{"input"=>{"type"=>"log"}, "level"=>"INFO", "prospector"=>{"type"=>"log"}, "message"=>"just this line", "@timestamp"=>2019-01-24T07:04:42.322Z, "beat"=>{"hostname"=>"0b3b67f06ae8", "name"=>"cujo", "version"=>"6.5.4"}, "source"=>"/mnt/logs/sample.log", "log"=>{"flags"=>["multiline"]}, "tags"=>["kv", "beats_input_codec_plain_applied"], "@version"=>"1", "host"=>{"name"=>"cujo"}, "offset"=>0}}
[2019-01-24T10:08:15,373][DEBUG][logstash.pipeline        ] output received {"event"=>{"input"=>{"type"=>"log"}, "level"=>"INFO", "prospector"=>{"type"=>"log"}, "message"=>"proper multi\nline\nmessage because of the brackets", "@timestamp"=>2019-01-24T07:23:15.429Z, "beat"=>{"hostname"=>"0b3b67f06ae8", "name"=>"cujo", "version"=>"6.5.4"}, "source"=>"/mnt/logs/sample.log", "log"=>{"flags"=>["multiline"]}, "tags"=>["kv", "beats_input_codec_plain_applied"], "@version"=>"1", "host"=>{"name"=>"cujo"}, "offset"=>100}}

These are the test log messages:

timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: just this line
of the 
message is stored
timestamp: 2019-01-24T07:23:15.429Z, level: INFO, message: [proper multi
line
message because of the brackets]
timestamp: 2019-01-24T07:04:42.322Z, level: INFO, message: [but if I have brackets in
the [message] it doesnt work again]