multiline_flush_interval does not work in combination with enable_watch_timer false

[LittleBro2]

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:

<source>
  @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
  <parse>
    @type multiline
    format_firstline /\[[^\]]*\] /
    format1 /\[(?<time>[^\]]*)\] \r?\n(?<message>.*) \r?\n/
  </parse>  
</source>

<match test>
  @type stdout
</match>

Log file example: 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.

[kenhys]

I can reproduce it with 1.11.5 and master on Debian/unstable.

[kenhys]

When enable_watch_timer is disabled, the flush event is triggered when logs.txt is updated.

[LittleBro2]

Closed by mistake, sorry

[github-actions[bot]]

This issue has been automatically marked as stale because it has been open 90 days with no activity. Remove stale label or comment or this issue will be closed in 30 days

[github-actions[bot]]

This issue was automatically closed because of stale in 30 days

[yusufgungor]

We can approve this issue still persist for td-agent version 1.11.2