Logstash log is not properly parsed after spliting logstash pipelines

Hi, can I ask you for help?

I have a Filebeat which handles Logstash logging. When I used only one main pipeline in Logstash, the logs were parsed correctly and looked like this.

Summary

PS: This parsing error in message is our error :slight_smile: not Beat or Logstash

{
"_index": "filebeat-7.5.1-2020.01.14-000001",
"_type": "_doc",
"_id": "dBWen3ABJIF-oOIgwMm6",
"_score": 1,
"_source": {
"kubernetes": {
"container": {
"image": "docker.elastic.co/logstash/logstash:7.6.0",
"name": "logstash"
},
"node": {
"name": "k8s-01-vm"
},
"pod": {
"uid": "831b114d-313a-4224-806d-d69e864bb419",
"name": "logstash-848ccbcddc-vwxmt"
},
"namespace": "default",
"replicaset": {
"name": "logstash-848ccbcddc"
},
"labels": {
"app": "logstash",
"pod-template-hash": "848ccbcddc"
}
},
"agent": {
"hostname": "filebeat-69j2p",
"id": "d39f7c50-cbdd-497e-939c-394878f35349",
"type": "filebeat",
"ephemeral_id": "6cfe32d8-da63-403d-bfbc-f7002d3dcd33",
"version": "7.5.1"
},
"log": {
"file": {
"path": "/var/log/containers/logstash-848ccbcddc-vwxmt_default_logstash-20ec33c48c1806e6d753ec500ef8486237b22d32ba3f0bcb09b515b4f4b0b459.log"
},
"offset": 108274,
"level": "WARN",
"flags": [
"multiline"
]
},
"fileset": {
"name": "log"
},
"message": "Error parsing json {:source=>"message", :raw=>"{\\\"Message\\\":\\\"Function: Install-LogetoProduct\\\",\\\"Source\\\":\\\"PS_PM\\\",\\\"Timestamp\\\":\\\"\\\\/Date(1583149531075)\\\\/\\\",\\\"Exception\\\":\\\"Exception calling \\\\\\\"DownloadFile\\\\\\\" with \\\\\\\"2\\\\\\\" argument(s): \\\\\\\"Vzd\\xE1len\\xFD server vr\\xE1til chybu: (404) Nenalezeno.\\\\\\\"\\\",\\\"LogType\\\":\\\"Error\\\",\\\"SourcePartition\\\":null}", :exception=>#<LogStash::Json::ParserError: Unexpected character ('\' (code 92)): was expecting double-quote to start field name\n at [Source: (byte)"{\"Message\":\"Function: Install-LogetoProduct\",\"Source\":\"PS_PM\",\"Timestamp\":\"\\/Date(1583149531075)\\/\",\"Exception\":\"Exception calling \\\"DownloadFile\\\" with \\\"2\\\" argument(s): \\\"Vzd\xE1len\xFD server vr\xE1til chybu: (404) Nenalezeno.\\\"\",\"LogType\":\"Error\",\"SourcePartition\":null}"; line: 1, column: 3]>}",
"input": {
"type": "container"
},
"logstash": {
"log": {
"module": "logstash.filters.json",
"pipeline_id": "main"
}
},
"@timestamp": "2020-03-03T08:58:55.637Z",
"ecs": {
"version": "1.1.0"
},
"stream": "stdout",
"service": {
"type": "logstash"
},
"host": {
"hostname": "filebeat-69j2p",
"os": {
"kernel": "5.3.0-28-generic",
"codename": "Core",
"name": "CentOS Linux",
"family": "redhat",
"version": "7 (Core)",
"platform": "centos"
},
"containerized": true,
"name": "filebeat-69j2p",
"architecture": "x86_64"
},
"event": {
"timezone": "+00:00",
"created": "2020-03-03T08:58:55.637Z",
"module": "logstash",
"dataset": "logstash.log"
}
},
"fields": {
"event.created": [
"2020-03-03T08:58:55.637Z"
],
"suricata.eve.timestamp": [
"2020-03-03T08:58:55.637Z"
],
"@timestamp": [
"2020-03-03T08:58:55.637Z"
]
}
}

But now we have splited our Logstash main pipeline into multiple pipelines with distributor pattern. After this split we get weird logstash logs from filebeat. They look like this, with error "Provided Grok expressions do not match field value:".

Summary

{
"_index": "filebeat-7.6.1-2020.03.09-000001",
"_type": "_doc",
"_id": "GA_MyHABU8mhUkZ3FVHl",
"_score": 1,
"_source": {
"kubernetes": {
"container": {
"image": "docker.elastic.co/logstash/logstash:7.6.1",
"name": "logstash"
},
"node": {
"name": "k8s-01-vm"
},
"pod": {
"uid": "3d89b0c0-5b61-4388-85c3-91e9a6485d9a",
"name": "logstash-d4f758d57-2lmlq"
},
"namespace": "default",
"replicaset": {
"name": "logstash-d4f758d57"
},
"labels": {
"app": "logstash",
"pod-template-hash": "d4f758d57"
}
},
"agent": {
"hostname": "filebeat-rt8zv",
"id": "d39f7c50-cbdd-497e-939c-394878f35349",
"ephemeral_id": "d4b66045-4c40-4363-a3aa-3d615dbe67e1",
"type": "filebeat",
"version": "7.6.1"
},
"log": {
"file": {
"path": "/var/log/containers/logstash-d4f758d57-2lmlq_default_logstash-23c95bcd54a092a82713b3126a3ec10809fd0e1a2e32fa95d9f756b979ef74b0.log"
},
"offset": 473601
},
"fileset": {
"name": "log"
},
"message": "[WARN ] 2020-03-11 08:52:47.273 [[release_operation]>worker0] elasticsearch - Could not index event to Elasticsearch. {:status=>400, :action=>["index", {:_id=>"%{UniqueId}", :_index=>"release_operation", :routing=>nil, :_type=>"_doc"}, #LogStash::Event:0xd2d8d2a], :response=>{"index"=>{"_index"=>"release_operation-2020.02.07-00001", "_type"=>"_doc", "_id"=>"%{UniqueId}", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"failed to parse field [Timestamp] of type [date] in document with id '%{UniqueId}'. Preview of field's value: '/Date(1583916826833)/'", "caused_by"=>{"type"=>"illegal_argument_exception", "reason"=>"failed to parse date field [/Date(1583916826833)/] with format [strict_date_optional_time||epoch_millis]", "caused_by"=>{"type"=>"date_time_parse_exception", "reason"=>"Failed to parse with all enclosed parsers"}}}}}}",
"error": {
"message": "Provided Grok expressions do not match field value: [[WARN ] 2020-03-11 08:52:47.273 [[release_operation]>worker0] elasticsearch - Could not index event to Elasticsearch. {:status=>400, :action=>[\"index\", {:_id=>\"%{UniqueId}\", :_index=>\"release_operation\", :routing=>nil, :_type=>\"_doc\"}, #LogStash::Event:0xd2d8d2a], :response=>{\"index\"=>{\"_index\"=>\"release_operation-2020.02.07-00001\", \"_type\"=>\"_doc\", \"_id\"=>\"%{UniqueId}\", \"status\"=>400, \"error\"=>{\"type\"=>\"mapper_parsing_exception\", \"reason\"=>\"failed to parse field [Timestamp] of type [date] in document with id '%{UniqueId}'. Preview of field's value: '/Date(1583916826833)/'\", \"caused_by\"=>{\"type\"=>\"illegal_argument_exception\", \"reason\"=>\"failed to parse date field [/Date(1583916826833)/] with format [strict_date_optional_time||epoch_millis]\", \"caused_by\"=>{\"type\"=>\"date_time_parse_exception\", \"reason\"=>\"Failed to parse with all enclosed parsers\"}}}}}}]"
},
"input": {
"type": "container"
},
"@timestamp": "2020-03-11T08:52:47.274Z",
"ecs": {
"version": "1.4.0"
},
"stream": "stdout",
"service": {
"type": "logstash"
},
"host": {
"hostname": "filebeat-rt8zv",
"os": {
"kernel": "5.3.0-40-generic",
"codename": "Core",
"name": "CentOS Linux",
"family": "redhat",
"version": "7 (Core)",
"platform": "centos"
},
"containerized": true,
"name": "filebeat-rt8zv",
"architecture": "x86_64"
},
"event": {
"timezone": "+00:00",
"module": "logstash",
"dataset": "logstash.log"
}
},
"fields": {
"suricata.eve.timestamp": [
"2020-03-11T08:52:47.274Z"
],
"@timestamp": [
"2020-03-11T08:52:47.274Z"
]
}
}

There is not parsed log level or logstash.log.module and pipeline_id. Can you help me find out where we made a mistake? I can send you any logstash config. :slight_smile:

I think you can try to debug the pattern using Grok debugger (https://grokdebug.herokuapp.com/). You can verify it with your log entries.

I probably already know where the problem is. It is caused by logstash. When using multiple pipelines, logstash changes its log structure, which then does not match the expectations of the beats - logstash module. Look here https://github.com/elastic/logstash/issues/11678

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