Hi.
I have a strange problem with data stream and filebeat. I've updated a mapping table and wanted to see if the new mappings work so I ran a manual rollup on the (test) data stream with
POST robobeat-ds-sim-01-7.17/_rollover?dry_run=false
which successfully created a new backing index (BI). The problem is that the events/docs comming from the same (test) filebeat instance, are being written to 2 different data stream's indices. Some events are being written to the newly created BI and some to the old/previous one. The only difference is that these events are coming from different filebeat.inputs.
This is the config of the inputs that are being written to the correct/new BI (including different input types):
# ROSLOG: just rosout.log (has a different pattern)
- type: filestream
id: ros-rosout
paths:
- /var/log/roslogs/*/rosout.log
fields:
service_name: "ros"
ros.log.file: "rosout"
fields_under_root: true
ignore_older: 336h
parsers:
- multiline:
pattern: '^\d+'
negate: true
match: after
processors:
- dissect:
tokenizer: "%{time} %{severity} %{node} [%{program.name}:%{program.line}(%{program.function})] [topics: %{topics}] %{msg}"
target_prefix: "ros"
- dissect:
tokenizer: "%{time} %{msg}"
target_prefix: "ros"
- rename:
fields:
- from: "ros.msg"
to: "msg"
- if.contains.message: "Could not capture frame"
then:
- rate_limit:
limit: "1/s"
- timestamp:
field: ros.time
layouts:
- 'UNIX' # don't use UNIX_MS since it doesn't work!
test:
- '1610102435.192563056'
# NRU
- type: journald
seek: cursor
id: app
include_matches:
- container.name=app
fields:
service_name: "app"
fields_under_root: true
ignore_older: 336h
processors:
- decode_json_fields:
fields: ["message"]
target: ""
add_error_key: true
- convert:
fields:
- {from: "level", type: "integer"}
- {from: "time", type: "string"}
- dissect:
tokenizer: "\u001b[0m[ %{log.level}] [%{ros.time}]: %{msg}\u001b[0m"
target_prefix: ""
- dissect:
tokenizer: "\u001b[0m[ %{log.level}] [%{ros.time}]: %{msg}"
target_prefix: ""
- dissect:
tokenizer: "%{pm2.time}: PM2 log: %{msg}"
target_prefix: ""
- dissect:
tokenizer: "%{pm2.time} [-] [%{ros.severity}] [%{ros.time}]: %{msg}"
target_prefix: ""
- dissect:
tokenizer: "%{pm2.time} [-] %{msg}"
target_prefix: ""
- timestamp:
field: pm2.time
target_field: pm2.time # overrides @timestamp if not specified
layouts:
- '2006-01-02 15:04:05-0700'
test:
- '2022-03-11 08:25:29+0100'
ignore_missing: true
- dissect:
tokenizer: "%{msg}"
target_prefix: ""
ignore_missing: true
And this is the config of the input being written to the wrong/old BI:
# ZONEMINDER
- type: journald
seek: tail
id: zoneminder
include_matches:
- container.name=zoneminder
fields_under_root: true
fields:
service_name: "zoneminder"
processors:
- rate_limit:
limit: "1/m"
- drop_event.when.equals.message: ""
- drop_event.when.contains.message: "==>"
- dissect:
tokenizer: "%{zm.time} %{+zm.time} %{zm.component}[%{zm.server.pid|integer}].%{log.level}-%{program.file}/%{program.line|integer} [%{msg}]"
target_prefix: ""
- dissect:
tokenizer: "%{zm.time} %{+zm.time} %{zm.component}[%{zm.server.pid|integer}].%{log.level} [%{zm.server.name}::%{zm.module}::%{zm.event}:%{program.line|integer}] [%{msg}]"
target_prefix: ""
- dissect:
tokenizer: "%{zm.time} %{+zm.time} %{zm.component}[%{zm.server.pid|integer}].%{log.level} [%{zm.server.name}::%{zm.event}:%{program.line|integer}] [%{msg}]"
target_prefix: ""
- dissect:
tokenizer: "%{zm.time} %{+zm.time} %{zm.component}[%{zm.server.pid|integer}].%{log.level} [%{zm.server.name}:%{program.line|integer}] [%{msg}]"
target_prefix: ""
- timestamp:
field: zm.time
ignore_missing: true
ignore_failure: true
layouts:
- '01/02/06 15:04:05.000000'
test:
- '01/27/22 17:10:59.512613'
- '03/17/22 08:37:14.187476'
Both of these configs are running on the same filebeat instance.
We only use 1 cluster, zone, node and shard without replicas, so no (custom) routing is set.
Here are the examples of documents being written to the same data stream, but to different BI.
Document written to the correct/new BI:
{
"_index": ".ds-robobeat-ds-sim-01-7.17-2022.07.13-000008",
"_type": "_doc",
"_id": "MkJJ9oEBGfN8Iuo-Pay_",
"_version": 1,
"_score": 1,
"_source": {
"@timestamp": "2022-07-13T06:40:00.022Z",
"input": {
"type": "journald"
},
"user": {
"id": "0",
"group": {
"id": "0"
}
},
"log": {
"level": "INFO",
"syslog": {
"priority": 6
},
"flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
]
},
"msg": "Closing '2022-07-13-08-15-00_1989.bag'.",
"message": "\u001b[0m[ INFO] [1657693200.006758587]: Closing '2022-07-13-08-15-00_1989.bag'.\u001b[0m",
"host": {
"hostname": "simko-01",
"id": "aa0d24ee9f224bf2b36906870153a837",
"name": "robobeat"
},
"error": {
"message": "parsing input as JSON: invalid character '\\x1b' looking for beginning of value",
"data": "\u001b[0m[ INFO] [1657693200.006758587]: Closing '2022-07-13-08-15-00_1989.bag'.\u001b[0m",
"field": "message"
},
"ros": {
"time": "1657693200.006758587"
},
"event": {
"created": "2022-07-13T06:40:03.743Z",
"kind": "event"
},
"syslog": {
"priority": 6,
"identifier": "e958524b3567"
},
"service_name": "app",
"systemd": {
"transport": "journal",
"invocation_id": "a267cc4df272478da7a4c15d87998baa",
"slice": "system.slice",
"cgroup": "/system.slice/docker.service",
"unit": "docker.service"
},
"robot": {
"id": "sim-01"
},
"ecs": {
"version": "1.12.0"
},
"agent": {
"hostname": "robobeat",
"ephemeral_id": "991d07be-335f-4b8e-b514-116c6aba1da5",
"id": "bf251720-9aaf-4acd-98ed-0699a68eca63",
"name": "robobeat",
"type": "filebeat",
"version": "7.17.4"
}
},
"fields": {
"msg": [
"Closing '2022-07-13-08-15-00_1989.bag'."
],
"error.field": [
"message"
],
"systemd.cgroup": [
"/system.slice/docker.service"
],
"host.hostname": [
"simko-01"
],
"agent.type": [
"filebeat"
],
"systemd.slice": [
"system.slice"
],
"log.level": [
"INFO"
],
"agent.name": [
"robobeat"
],
"systemd.unit": [
"docker.service"
],
"host.name": [
"robobeat"
],
"error.data": [
"\u001b[0m[ INFO] [1657693200.006758587]: Closing '2022-07-13-08-15-00_1989.bag'.\u001b[0m"
],
"log.syslog.priority": [
6
],
"event.kind": [
"event"
],
"host.id": [
"aa0d24ee9f224bf2b36906870153a837"
],
"systemd.transport": [
"journal"
],
"user.id": [
0
],
"service_name": [
"app"
],
"syslog.priority": [
6
],
"systemd.invocation_id": [
"a267cc4df272478da7a4c15d87998baa"
],
"input.type": [
"journald"
],
"agent.hostname": [
"robobeat"
],
"log.flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"syslog.identifier": [
"e958524b3567"
],
"message": [
"\u001b[0m[ INFO] [1657693200.006758587]: Closing '2022-07-13-08-15-00_1989.bag'.\u001b[0m"
],
"msg.keyword": [
"Closing '2022-07-13-08-15-00_1989.bag'."
],
"ros.time": [
"2022-07-13T06:20:00.006758587Z"
],
"@timestamp": [
"2022-07-13T06:40:00.022Z"
],
"agent.id": [
"bf251720-9aaf-4acd-98ed-0699a68eca63"
],
"ecs.version": [
"1.12.0"
],
"error.message": [
"parsing input as JSON: invalid character '\\x1b' looking for beginning of value"
],
"event.created": [
"2022-07-13T06:40:03.743Z"
],
"robot.id": [
"sim-01"
],
"agent.ephemeral_id": [
"991d07be-335f-4b8e-b514-116c6aba1da5"
],
"agent.version": [
"7.17.4"
],
"user.group.id": [
0
]
}
}
And a document, closely following the previous one, being written to the wrong/old BI:
{
"_index": ".ds-robobeat-ds-sim-01-7.17-2022.07.07-000004",
"_type": "_doc",
"_id": "OTzc9YEBGfN8Iuo-ZBSW",
"_version": 1,
"_score": 1,
"_ignored": [
"zm.time"
],
"_source": {
"@timestamp": "2022-07-13T06:41:06.509Z",
"syslog": {
"identifier": "575822533d29",
"priority": 6
},
"user": {
"id": "0",
"group": {
"id": "0"
}
},
"program": {
"line": 411
},
"agent": {
"name": "robobeat",
"type": "filebeat",
"version": "7.17.4",
"hostname": "robobeat",
"ephemeral_id": "991d07be-335f-4b8e-b514-116c6aba1da5",
"id": "bf251720-9aaf-4acd-98ed-0699a68eca63"
},
"event": {
"kind": "event",
"created": "2022-07-13T04:41:09.526Z"
},
"host": {
"hostname": "simko-01",
"id": "aa0d24ee9f224bf2b36906870153a837",
"name": "robobeat"
},
"input": {
"type": "journald"
},
"log": {
"flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"level": "INF",
"syslog": {
"priority": 6
}
},
"robot": {
"id": "sim-01"
},
"msg": "Starting pending process, zmc -d /dev/video0",
"systemd": {
"cgroup": "/system.slice/docker.service",
"slice": "system.slice",
"invocation_id": "a267cc4df272478da7a4c15d87998baa",
"transport": "journal",
"unit": "docker.service"
},
"message": "07/13/22 06:41:06.509320 zmdc[473].INF [ZMServer:411] [Starting pending process, zmc -d /dev/video0]",
"service_name": "zoneminder",
"zm": {
"time": "07/13/22 06:41:06.509320",
"component": "zmdc",
"server": {
"pid": 473,
"name": "ZMServer"
}
},
"ecs": {
"version": "1.12.0"
}
},
"fields": {
"agent.version.keyword": [
"7.17.4"
],
"msg": [
"Starting pending process, zmc -d /dev/video0"
],
"systemd.slice.keyword": [
"system.slice"
],
"host.name.keyword": [
"robobeat"
],
"host.hostname": [
"simko-01"
],
"agent.hostname.keyword": [
"robobeat"
],
"ecs.version.keyword": [
"1.12.0"
],
"event.kind.keyword": [
"event"
],
"log.level": [
"INF"
],
"systemd.transport.keyword": [
"journal"
],
"agent.name": [
"robobeat"
],
"systemd.unit": [
"docker.service"
],
"host.id.keyword": [
"aa0d24ee9f224bf2b36906870153a837"
],
"host.name": [
"robobeat"
],
"event.kind": [
"event"
],
"user.id": [
0
],
"service_name": [
"zoneminder"
],
"agent.id.keyword": [
"bf251720-9aaf-4acd-98ed-0699a68eca63"
],
"input.type": [
"journald"
],
"agent.hostname": [
"robobeat"
],
"log.flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"program.line": [
411
],
"agent.id": [
"bf251720-9aaf-4acd-98ed-0699a68eca63"
],
"ecs.version": [
"1.12.0"
],
"event.created": [
"2022-07-13T04:41:09.526Z"
],
"host.hostname.keyword": [
"simko-01"
],
"robot.id": [
"sim-01"
],
"agent.version": [
"7.17.4"
],
"user.group.id": [
0
],
"zm.server.pid": [
473
],
"input.type.keyword": [
"journald"
],
"zm.component": [
"zmdc"
],
"systemd.cgroup": [
"/system.slice/docker.service"
],
"systemd.cgroup.keyword": [
"/system.slice/docker.service"
],
"agent.type": [
"filebeat"
],
"systemd.slice": [
"system.slice"
],
"log.syslog.priority": [
6
],
"host.id": [
"aa0d24ee9f224bf2b36906870153a837"
],
"systemd.unit.keyword": [
"docker.service"
],
"agent.type.keyword": [
"filebeat"
],
"agent.ephemeral_id.keyword": [
"991d07be-335f-4b8e-b514-116c6aba1da5"
],
"systemd.transport": [
"journal"
],
"zm.server.name": [
"ZMServer"
],
"agent.name.keyword": [
"robobeat"
],
"syslog.priority": [
6
],
"systemd.invocation_id": [
"a267cc4df272478da7a4c15d87998baa"
],
"systemd.invocation_id.keyword": [
"a267cc4df272478da7a4c15d87998baa"
],
"syslog.identifier": [
"575822533d29"
],
"message": [
"07/13/22 06:41:06.509320 zmdc[473].INF [ZMServer:411] [Starting pending process, zmc -d /dev/video0]"
],
"@timestamp": [
"2022-07-13T06:41:06.509Z"
],
"agent.ephemeral_id": [
"991d07be-335f-4b8e-b514-116c6aba1da5"
],
"syslog.identifier.keyword": [
"575822533d29"
]
},
"ignored_field_values": {
"zm.time": [
"07/13/22 06:41:06.509320"
]
}
}
Note the different values under _index. The new/correct BI (after rollup) is .ds-robobeat-ds-sim-01-7.17-2022.07.13-000008 the old one (before rollup) is .ds-robobeat-ds-sim-01-7.17-2022.07.07-000004.
The main issue here is that the "Zoneminder" events are being written to the old index with the old mapping, which shouldn't be used anymore.
Restarting the filebeat instance didn't help.
Here is the relevant part of filebeat.yml
filebeat.config.inputs:
enabled: true
path: beats/[^_]*.yml # don't include the files starting with '_'
reload.enabled: true
reload.period: 10s
fields_under_root: true
fields:
robot.id: ${ROBOT_ID}
output.elasticsearch:
hosts: ["${ELASTIC_HOST}"]
username: "${FILEBEAT_USERNAME}"
password: "${FILEBEAT_PASSWORD}"
protocol: https
index: "robobeat-ds-${ROBOT_ID}-${ELASTIC_VERSION}"
setup:
ilm.enabled: false
template:
name: "robobeat-ds-${ELASTIC_VERSION}"
pattern: "robobeat-ds-*"
overwrite: false
enabled: true
P.S.
As I was writing this, the "Zoneminder" events started being written to the correct/new BI even though I haven't touched any of the filebeat nor Elasticsearch configs nor have I restarted any instances. I'd still like to know what's happening and how to fix this, since some events were being written to the wrong BI for more than 8 hours.
The switch happened between these 2 documents.
Old BI:
{
"_index": ".ds-robobeat-ds-sim-01-7.17-2022.07.07-000004",
"_type": "_doc",
"_id": "pDzf9YEBGfN8Iuo-Jjip",
"_version": 1,
"_score": 1,
"_ignored": [
"zm.time"
],
"_source": {
"@timestamp": "2022-07-13T06:44:08.481Z",
"input": {
"type": "journald"
},
"program": {
"line": 411
},
"msg": "Starting pending process, zmc -d /dev/video1",
"syslog": {
"identifier": "575822533d29",
"priority": 6
},
"event": {
"kind": "event",
"created": "2022-07-13T04:44:10.804Z"
},
"message": "07/13/22 06:44:08.481257 zmdc[473].INF [ZMServer:411] [Starting pending process, zmc -d /dev/video1]",
"log": {
"syslog": {
"priority": 6
},
"flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"level": "INF"
},
"systemd": {
"invocation_id": "a267cc4df272478da7a4c15d87998baa",
"transport": "journal",
"slice": "system.slice",
"cgroup": "/system.slice/docker.service",
"unit": "docker.service"
},
"host": {
"id": "aa0d24ee9f224bf2b36906870153a837",
"hostname": "simko-01",
"name": "robobeat"
},
"user": {
"id": "0",
"group": {
"id": "0"
}
},
"zm": {
"server": {
"pid": 473,
"name": "ZMServer"
},
"time": "07/13/22 06:44:08.481257",
"component": "zmdc"
},
"ecs": {
"version": "1.12.0"
},
"agent": {
"id": "bf251720-9aaf-4acd-98ed-0699a68eca63",
"name": "robobeat",
"type": "filebeat",
"version": "7.17.4",
"hostname": "robobeat",
"ephemeral_id": "991d07be-335f-4b8e-b514-116c6aba1da5"
},
"robot": {
"id": "sim-01"
},
"service_name": "zoneminder"
},
"fields": {
"agent.version.keyword": [
"7.17.4"
],
"msg": [
"Starting pending process, zmc -d /dev/video1"
],
"systemd.slice.keyword": [
"system.slice"
],
"host.name.keyword": [
"robobeat"
],
"host.hostname": [
"simko-01"
],
"agent.hostname.keyword": [
"robobeat"
],
"ecs.version.keyword": [
"1.12.0"
],
"event.kind.keyword": [
"event"
],
"log.level": [
"INF"
],
"systemd.transport.keyword": [
"journal"
],
"agent.name": [
"robobeat"
],
"systemd.unit": [
"docker.service"
],
"host.id.keyword": [
"aa0d24ee9f224bf2b36906870153a837"
],
"host.name": [
"robobeat"
],
"event.kind": [
"event"
],
"user.id": [
0
],
"service_name": [
"zoneminder"
],
"agent.id.keyword": [
"bf251720-9aaf-4acd-98ed-0699a68eca63"
],
"input.type": [
"journald"
],
"agent.hostname": [
"robobeat"
],
"log.flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"program.line": [
411
],
"agent.id": [
"bf251720-9aaf-4acd-98ed-0699a68eca63"
],
"ecs.version": [
"1.12.0"
],
"event.created": [
"2022-07-13T04:44:10.804Z"
],
"host.hostname.keyword": [
"simko-01"
],
"robot.id": [
"sim-01"
],
"agent.version": [
"7.17.4"
],
"user.group.id": [
0
],
"zm.server.pid": [
473
],
"input.type.keyword": [
"journald"
],
"zm.component": [
"zmdc"
],
"systemd.cgroup": [
"/system.slice/docker.service"
],
"systemd.cgroup.keyword": [
"/system.slice/docker.service"
],
"agent.type": [
"filebeat"
],
"systemd.slice": [
"system.slice"
],
"log.syslog.priority": [
6
],
"host.id": [
"aa0d24ee9f224bf2b36906870153a837"
],
"systemd.unit.keyword": [
"docker.service"
],
"agent.type.keyword": [
"filebeat"
],
"agent.ephemeral_id.keyword": [
"991d07be-335f-4b8e-b514-116c6aba1da5"
],
"systemd.transport": [
"journal"
],
"zm.server.name": [
"ZMServer"
],
"agent.name.keyword": [
"robobeat"
],
"syslog.priority": [
6
],
"systemd.invocation_id": [
"a267cc4df272478da7a4c15d87998baa"
],
"systemd.invocation_id.keyword": [
"a267cc4df272478da7a4c15d87998baa"
],
"syslog.identifier": [
"575822533d29"
],
"message": [
"07/13/22 06:44:08.481257 zmdc[473].INF [ZMServer:411] [Starting pending process, zmc -d /dev/video1]"
],
"@timestamp": [
"2022-07-13T06:44:08.481Z"
],
"agent.ephemeral_id": [
"991d07be-335f-4b8e-b514-116c6aba1da5"
],
"syslog.identifier.keyword": [
"575822533d29"
]
},
"ignored_field_values": {
"zm.time": [
"07/13/22 06:44:08.481257"
]
}
}
New BI:
{
"_index": ".ds-robobeat-ds-sim-01-7.17-2022.07.13-000008",
"_type": "_doc",
"_id": "nTzf9YEBGfN8Iuo-_EYk",
"_version": 1,
"_score": 1,
"_ignored": [
"zm.time"
],
"_source": {
"@timestamp": "2022-07-13T06:45:02.608Z",
"syslog": {
"priority": 6,
"identifier": "575822533d29"
},
"zm": {
"server": {
"pid": 473,
"name": "ZMServer"
},
"time": "07/13/22 06:45:02.608923",
"component": "zmdc"
},
"program": {
"line": 411
},
"msg": "Starting pending process, zmc -d /dev/video0",
"host": {
"name": "robobeat",
"id": "aa0d24ee9f224bf2b36906870153a837",
"hostname": "simko-01"
},
"systemd": {
"invocation_id": "a267cc4df272478da7a4c15d87998baa",
"cgroup": "/system.slice/docker.service",
"unit": "docker.service",
"transport": "journal",
"slice": "system.slice"
},
"ecs": {
"version": "1.12.0"
},
"event": {
"created": "2022-07-13T04:45:04.943Z",
"kind": "event"
},
"input": {
"type": "journald"
},
"message": "07/13/22 06:45:02.608923 zmdc[473].INF [ZMServer:411] [Starting pending process, zmc -d /dev/video0]",
"user": {
"group": {
"id": "0"
},
"id": "0"
},
"robot": {
"id": "sim-01"
},
"service_name": "zoneminder",
"agent": {
"id": "bf251720-9aaf-4acd-98ed-0699a68eca63",
"name": "robobeat",
"type": "filebeat",
"version": "7.17.4",
"hostname": "robobeat",
"ephemeral_id": "991d07be-335f-4b8e-b514-116c6aba1da5"
},
"log": {
"syslog": {
"priority": 6
},
"flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"level": "INF"
}
},
"fields": {
"msg": [
"Starting pending process, zmc -d /dev/video0"
],
"zm.component": [
"zmdc"
],
"systemd.cgroup": [
"/system.slice/docker.service"
],
"host.hostname": [
"simko-01"
],
"agent.type": [
"filebeat"
],
"systemd.slice": [
"system.slice"
],
"log.level": [
"INF"
],
"agent.name": [
"robobeat"
],
"systemd.unit": [
"docker.service"
],
"host.name": [
"robobeat"
],
"log.syslog.priority": [
6
],
"event.kind": [
"event"
],
"host.id": [
"aa0d24ee9f224bf2b36906870153a837"
],
"systemd.transport": [
"journal"
],
"zm.server.name": [
"ZMServer"
],
"user.id": [
0
],
"service_name": [
"zoneminder"
],
"syslog.priority": [
6
],
"systemd.invocation_id": [
"a267cc4df272478da7a4c15d87998baa"
],
"input.type": [
"journald"
],
"agent.hostname": [
"robobeat"
],
"log.flags": [
"dissect_parsing_error",
"dissect_parsing_error",
"dissect_parsing_error"
],
"syslog.identifier": [
"575822533d29"
],
"message": [
"07/13/22 06:45:02.608923 zmdc[473].INF [ZMServer:411] [Starting pending process, zmc -d /dev/video0]"
],
"msg.keyword": [
"Starting pending process, zmc -d /dev/video0"
],
"program.line": [
411
],
"@timestamp": [
"2022-07-13T06:45:02.608Z"
],
"agent.id": [
"bf251720-9aaf-4acd-98ed-0699a68eca63"
],
"ecs.version": [
"1.12.0"
],
"event.created": [
"2022-07-13T04:45:04.943Z"
],
"robot.id": [
"sim-01"
],
"agent.ephemeral_id": [
"991d07be-335f-4b8e-b514-116c6aba1da5"
],
"agent.version": [
"7.17.4"
],
"user.group.id": [
0
],
"zm.server.pid": [
473
]
},
"ignored_field_values": {
"zm.time": [
"07/13/22 06:45:02.608923"
]
}
}
I don't really think this has anything to do with filebeat, because it's sending data to only one/the same data stream, but probably has to do something with Elastic?
Any help/insight would be greatly appreciated.