multiline_flush_interval does not work in combination with enable_watch_timer false
- Dominant language
- Ruby
- Stars
- 13.6k
- Forks
- 1.4k
- Avg merge
- 1d 3h
- Merged PRs (30d)
- 20
Description
**Describe the bug**
In the case of a multiline tail log source, the last record in the file is not flushed after multiline_flush_interval has passed if the enable_watch_timer parameter is set to false. If enable_watch_timer parameter is set to true then all works as expected.
**To Reproduce**
Configure multiline tail source with multiline_flush_interval set to 10s and enable_watch_timer parameter set to false.
Prepare log file with several records.
Start fluentd and wait more than 10 seconds and then stop fluentd.
As a result first records flushed immediately but the last record flushed only during fluentd stopping.
**Expected behavior**
First records flushed immediately and last record flushed after 10 seconds according to multiline_flush_interval.
**Your Environment**
- fluentd 1.11.2
- Windows 10
**Your Configuration**
Configuration example:
```
@type tail
path C:\Temp\logs.txt
pos_file C:\Temp\posfile.pos
tag test
read_from_head true
multiline_flush_interval 10s
enable_watch_timer false
@type multiline
format_firstline /\[[^\]]*\] /
format1 /\[(?
@type stdout
```
Log file example:
[logs.txt](https://github.com/fluent/fluentd/files/5600731/logs.txt)
```
[2020-10-19 12:21:33.8442]
1 Log message
[2020-10-19 12:22:33.8442]
2 Log message
```
**Your Error Log**
```
2020-11-26 12:24:02 +0700 [info]: adding match pattern="test" type="stdout"
2020-11-26 12:24:02 +0700 [info]: adding source type="tail"
2020-11-26 12:24:03 +0700 [info]: #0 starting fluentd worker pid=23040 ppid=11772 worker=0
2020-11-26 12:24:03 +0700 [info]: #0 following tail of C:\Temp\logs.txt
2020-10-19 12:21:33.844200000 +0700 test: {"message":"1 Log message"}
2020-11-26 12:24:03 +0700 [info]: #0 fluentd worker is now running worker=0
2020-11-26 12:24:49 +0700 [info]: Received graceful stop
2020-11-26 12:24:49 +0700 [info]: #0 fluentd worker is now stopping worker=0
2020-11-26 12:24:49 +0700 [info]: #0 shutting down fluentd worker worker=0
2020-11-26 12:24:49 +0700 [info]: #0 shutting down input plugin type=:tail plugin_id="object:ab4"
2020-10-19 12:22:33.844200000 +0700 test: {"message":"2 Log message"}
2020-11-26 12:24:49 +0700 [info]: #0 shutting down output plugin type=:stdout plugin_id="object:aa0"
2020-11-26 12:24:50 +0700 [info]: Worker 0 finished with status 0
```
**Additional context**
All works as expected if enable_watch_timer parameter is set to true.
Contributor guide
Research direction
Start by reproducing the multiline tail source configuration with multiline_flush_interval set to 10s and enable_watch_timer false, then compare it with the true setting. Trace the tail input and multiline parser behavior around timer-driven flushing; done means the final record is emitted after the interval without requiring Fluentd to stop, with coverage for both timer settings.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- ruby
- Domain
- observability-sre
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100