influxdata / influxdata/telegraf

Missing log entry when telegraf restarts in tail | csv

Open
#13,317 7 comments 0 reactions 0 assignees View on GitHub
area/csv area/tail feature request help wanted size/m
Dominant language
Go
Stars
17.8k
Forks
5.8k
Avg merge
1d 20h
Merged PRs (30d)
161

Description

### Relevant telegraf.conf

```toml
[global_tags]

[agent]
interval = "1s"
round_interval = true
metric_batch_size = 10000
metric_buffer_limit = 100000
collection_jitter = "1s"
flush_interval = "11s"
flush_jitter = "1s"
precision = "1ms"
debug = true
quiet = false
logfile = "./telegraf.log"
logtarget = "file"
logfile_rotation_interval = 0
logfile_rotation_max_size = "100KB"
logfile_rotation_max_archives = 50
hostname = ""
omit_hostname = true

[[inputs.tail]]
name_override = "Product_State"
interval = "2s"
files = ["C://_ProduData//*//Log//ProductState//Log_ProductState_*.csv"]
from_beginning = false
watch_method = "poll"
character_encoding = "utf-8"
max_undelivered_lines = 4000
data_format = "csv"
csv_header_row_count = 1
csv_column_names = ["Timestamp","ProductionRunGUID"]
csv_column_types = ["string", "string"]
csv_skip_rows = 0
csv_skip_columns = 0
csv_delimiter = ";"
csv_trim_space = false
csv_tag_columns = []
csv_measurement_column = ""
csv_timestamp_column = "Timestamp"
csv_timestamp_format = "2006-01-02T15:04:05.999Z"
csv_timezone = "UTC"
csv_skip_values = [""]
path_tag = ""
[inputs.tail.tags]
_in = "ProductStateTest"

[[outputs.file]]
files = ["stdout", "./tail_test.out"]
[outputs.file.tagpass]
_in = ["ProductStateTest"]
```

### Logs from Telegraf

```text
...
2023-05-23T08:36:34Z I! Loaded inputs: tail
2023-05-23T08:36:34Z I! Loaded aggregators:
2023-05-23T08:36:34Z I! Loaded processors:
2023-05-23T08:36:34Z I! Loaded outputs: file
2023-05-23T08:36:34Z I! Tags enabled:
2023-05-23T08:36:34Z I! [agent] Config: Interval:1s, Quiet:false, Hostname:"", Flush Interval:11s
2023-05-23T08:36:34Z D! [agent] Initializing plugins
2023-05-23T08:36:34Z D! [agent] Connecting outputs
2023-05-23T08:36:34Z D! [agent] Attempting connection to [outputs.file]
2023-05-23T08:36:34Z D! [agent] Successfully connected to outputs.file
2023-05-23T08:36:34Z D! [agent] Starting service inputs
2023-05-23T08:36:34Z D! [inputs.tail] Tail added for "C:\\_ProduData\\99999\\Log\\ProductState\\Log_ProductState_TEST.csv"
2023-05-23T08:36:46Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:36:57Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:37:09Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:37:20Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:37:32Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:37:43Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:37:55Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
2023-05-23T08:38:06Z D! [outputs.file] Wrote batch of 1 metrics in 359.1µs
2023-05-23T08:38:06Z D! [outputs.file] Buffer fullness: 0 / 100000 metrics
...
```

### System info

Windows10 64 bit, the issue is verified on telegraf versions 1.20.3 and 1.26.3.

### Docker

_No response_

### Steps to reproduce

1. Start telegraf with a tail plugin and csv_header_row_count = 1.
2. Read in a log file and produce log-entries "A" and "B".
In this example Log_ProductState_TEST.csv with content:

Timestamp;ProductionRunGUID;
2023-05-15T04:58:24.001Z;A;
2023-05-15T04:58:25.002Z;B;

4. Restart telegraf.
5. Add new log-entry "C" to the tailed log file.
6. Add a second new log-entry "D" to the tailed log file. Save the file.
7. Check the telegraf output. Only the second log-entry "D" gets shown, "C" gets missed.

### Expected behavior

Telegraf tail csv should check that the header is only at the beginning of a file and not the first new log-entry.
Both log-entries "C" and "D" should get shown.

content of ./tail_test.out:

Product_State,_in=ProductStateTest ProductionRunGUID="A" 1684126704001000000
Product_State,_in=ProductStateTest ProductionRunGUID="B" 1684126705002000000
**Product_State,_in=ProductStateTest ProductionRunGUID="C" 1684126705003000000**
Product_State,_in=ProductStateTest ProductionRunGUID="D" 1684126705004000000

### Actual behavior

Only the second log-entry "D" gets shown, the first log-entry "C" gets missed:

content of ./tail_test.out:

Product_State,_in=ProductStateTest ProductionRunGUID="A" 1684126704001000000
Product_State,_in=ProductStateTest ProductionRunGUID="B" 1684126705002000000
Product_State,_in=ProductStateTest ProductionRunGUID="D" 1684126705004000000

### Additional info

Workaround 1:
Using from_beginning = true. However, this is not a nice solution as the complete files get reread whenever telegraf restarts. Not an option for my use case unfortunatly but maybe for other use cases.

Workaround 2:
One can use csv_header_row_count = 0 instead and filter out the header data in a e.g. starlark processor later on. However, this might limit other features, get kind of complex and as well error prone. Therefore a fix of the bug would be highly appreciated.

Contributor guide

Open the contributing guide

Research direction

Start with the inputs.tail plugin's CSV handling and the state used when a file is reopened after Telegraf restarts. Reproduce the configuration with csv_header_row_count = 1, then verify that the first new entry after the restart is retained along with subsequent entries, while the original header is still handled correctly.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
observability
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Clearly specified
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.