influxdata / influxdata/telegraf

Multiple tail input instances with inotify not working as expected

Open
#8,449 3 comments 7 reactions 0 assignees View on GitHub
area/tail bug
Dominant language
Go
Stars
17.8k
Forks
5.8k
Avg merge
1d 20h
Merged PRs (30d)
161

Description

### Relevant telegraf.conf:

```toml
[[outputs.file]]
files = ["stdout"]
data_format = "influx"

[[inputs.tail]]
name_override = "tail1"

files = ["/config/telegraf/test.log"]
from_beginning = false
watch_method = "inotify"

data_format = "value"
data_type = "string"

[[inputs.tail]]
name_override = "tail2"

files = ["/config/telegraf/test.log"]
from_beginning = false
watch_method = "inotify"

data_format = "value"
data_type = "string"
```

### System info:

```
$ telegraf --version
Telegraf 1.16.2 (git: release-1.16 962082f6)
$ cat /etc/issue
Ubuntu 20.04.1 LTS
$ uname -ris
Linux 5.4.0-53-generic x86_64
```

### Steps to reproduce:

Run
```
$ telegraf --config test.conf
```
and then in another terminal
```
$ echo "line 1" >> /config/telegraf/test.log
$ echo "line 2" >> /config/telegraf/test.log
$ echo "line 3" >> /config/telegraf/test.log
```

### Expected behavior:

In the terminal where telegraf is running, something like
```
[after first echo]
tail1,host=server,path=/config/telegraf/test.log value="line 1" 1606042136271573374
tail2,host=server,path=/config/telegraf/test.log value="line 1" 1606042136271573364
[after second echo]
tail1,host=server,path=/config/telegraf/test.log value="line 2" 1606042142526207498
tail2,host=server,path=/config/telegraf/test.log value="line 2" 1606042142526220753
[after third echo]
tail1,host=server,path=/config/telegraf/test.log value="line 3" 1606042152533259345
tail2,host=server,path=/config/telegraf/test.log value="line 3" 1606042152533300898
```

### Actual behavior:

```
[after first echo]
tail1,host=server,path=/config/telegraf/test.log value="line 1" 1606042481061620892
[after second echo]
tail2,host=server,path=/config/telegraf/test.log value="line 1" 1606042532796022014
tail2,host=server,path=/config/telegraf/test.log value="line 2" 1606042532796048376
[after third echo]
tail1,host=server,path=/config/telegraf/test.log value="line 2" 1606042545797547384
tail1,host=server,path=/config/telegraf/test.log value="line 3" 1606042545797574024
```

### Additional info:
It seems like the inotify event only arrives at one tail plugin instance (either tail1 or tail2) for every file append.
It seems to be random which tail instance receives the first append, and for subsequent appends it seems to alternate between the instances.
Using `poll` for both instances yields the expected behavior.

**Why would I want to do that?**
I want to parse the same logfile with different grok patterns and I want to add a tag based on which grok pattern matched a line. Since I did not find a way doing that using the grok parser, my solution was to use mutliple instances of tail (one for each grok pattern) and add a different via `[inputs.tail.tags]` in each instance. Then I encountered the described problem. In the meantime, however, I can live with simply using the polling mode.

Contributor guide

Open the contributing guide

Research direction

Reproduce the issue with the supplied telegraf.conf, two inputs.tail instances, and watch_method set to inotify; compare it with poll mode. Start by tracing the tail input's inotify handling and how events are delivered to multiple instances. Done means both tail1 and tail2 receive every appended line, with a regression test covering the configuration.

Written by the indexing model from the issue text.

Assessment

Tech stack
go, linux
Domain
observability-sre
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
38/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.