We are trying to use fluentd on Windows for logs collection, but it seems that buffer section's chunk_limit_size is not working on windows.
Even though chunk_limit_size value is defined as high as 64 MB, fluentd creates a lot of small small chunk files of size 0-1 KB with just 1 log line in each.
Because of this the Windows file descriptors limit(for a process) is reached and then fluentd fails with Error Logs saying not able to write new chunk file and failed to flush the buffer.
Steps to reproduce the behavior:
[Windows] Create a sample log file with significant amount of log lines (say 100k)
Below is a sample from IIS Access Log file used for testing
#Software: Microsoft Internet Information Services 10.0
#Version: 1.0
#Date: 2019-11-19 00:08:21
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) cs(Referer) sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2019-11-19 00:08:21 W3SVC50001 127.0.0.1 GET /XXXXX/health.html - 50001 - 127.0.0.1 ELB-HealthChecker/2.0 - 200 0 0 311 153 608
2019-11-19 00:08:21 W3SVC50001 ::1 GET /XXXXX/health.html - 50001 - ::1 ELB-HealthChecker/2.0 - 200 0 0 311 153 666
...
around 100k lines
Install td-agent(td-agent-3.5.1-0-x64.msi), configure it using below config file and then start fluentd Service.
Expected behavior:
Fluentd should not create a lot of small small chunk files of size 0-1KB, rather respect the chunk_size_limit value of defined 64MB.
Testing environment:
- td-agent package version: td-agent-3.5.1-0-x64.msi
- Operating system: Windows 10 Pro (same behaviour on Windows Server 2016 also)
Test config:
<source>
@type tail
path "E:/IntraWeb/logs/IISAccessLog/W3SVC/*.log"
pos_file "C:\\opt\\td-agent\\pos\\td-agent-iis.pos"
format /^(?<timestamp>\d+-\d+-\d+\s\d+:\d+:\d+)\s(?<s_sitename>[^\s]*)\s(?<s_ip>[^\s]*)\s(?<cs_method>[^\s]*)\s(?<cs_uri_stem>[^\s]*)\s(?<cs_uri_query>[^\s]*)\s(?<s_port>[^\s]*)\s(?<cs_username>[^\s]*)\s(?<c_ip>[^\s]*)\s(?<cs_user_agent>[^\s]*)\s(?<cs_referer>[^\s]*)\s(?<sc_status>[^\s]*)\s(?<sc_substatus>[^\s]*)\s(?<sc_win32_status>[^\s]*)\s(?<sc_bytes>[^\s]*)\s(?<cs_bytes>[^\s]*)\s(?<time_taken>[^\s]*)?$/
keep_time_key true
time_key timestamp
time_format %Y-%m-%d %H:%M:%S
read_from_head true
limit_recently_modified 3d
tag xxxx
</source>
<match xxxx>
@type s3
aws_key_id xxxx
aws_sec_key xxxx
s3_bucket xxxx
s3_region xxxx
path xxxx
s3_object_key_format %{path}%{time_slice}/%{index}.%{file_extension}
time_slice_format %Y-%m-%d/%H #%Y%m%d%H
time_format %Y-%m-%dT%H:%M:%S.%L%z
format json
time_key time
include_time_key true
<buffer tag,time>
@type file
path C:\opt\td-agent\buffer
timekey 3600 # 1 hour partition
chunk_limit_size 64MB
flush_mode interval
flush_interval 30s
flush_thread_count 4
flush_at_shutdown true
</buffer>
</match>
Error Log:
Within 1-2 sec of starting Fluentd Service, the buffer folder suddenly explodes with 2040 files (buffer.xx.log and buffer.xx.log.meta file combos).
Each of the buffer.xx.log contains only 1 log line event and td-agent log starts showing warn logs stating Can't create new buffer file.
2019-12-04 11:16:35 +0800 [info]: parsing config file is succeeded path="C:/opt/td-agent/etc/td-agent/td-agent.conf"
2019-12-04 11:16:37 +0800 [info]: using configuration file: <ROOT>
<source>
@type tail
path "E:/IntraWeb/logs/IISAccessLog/W3SVC/*.log"
pos_file "C:\\opt\\td-agent\\pos\\td-agent-iis.pos"
format /^(?<timestamp>\d+-\d+-\d+\s\d+:\d+:\d+)\s(?<s_sitename>[^\s]*)\s(?<s_ip>[^\s]*)\s(?<cs_method>[^\s]*)\s(?<cs_uri_stem>[^\s]*)\s(?<cs_uri_query>[^\s]*)\s(?<s_port>[^\s]*)\s(?<cs_username>[^\s]*)\s(?<c_ip>[^\s]*)\s(?<cs_user_agent>[^\s]*)\s(?<cs_referer>[^\s]*)\s(?<sc_status>[^\s]*)\s(?<sc_substatus>[^\s]*)\s(?<sc_win32_status>[^\s]*)\s(?<sc_bytes>[^\s]*)\s(?<cs_bytes>[^\s]*)\s(?<time_taken>[^\s]*)?$/
keep_time_key true
time_key timestamp
time_format %Y-%m-%d %H:%M:%S
read_from_head true
limit_recently_modified 3d
tag "xxxx"
<parse>
time_key timestamp
time_format %Y-%m-%d %H:%M:%S
keep_time_key true
@type regexp
expression ^(?<timestamp>\d+-\d+-\d+\s\d+:\d+:\d+)\s(?<s_sitename>[^\s]*)\s(?<s_ip>[^\s]*)\s(?<cs_method>[^\s]*)\s(?<cs_uri_stem>[^\s]*)\s(?<cs_uri_query>[^\s]*)\s(?<s_port>[^\s]*)\s(?<cs_username>[^\s]*)\s(?<c_ip>[^\s]*)\s(?<cs_user_agent>[^\s]*)\s(?<cs_referer>[^\s]*)\s(?<sc_status>[^\s]*)\s(?<sc_substatus>[^\s]*)\s(?<sc_win32_status>[^\s]*)\s(?<sc_bytes>[^\s]*)\s(?<cs_bytes>[^\s]*)\s(?<time_taken>[^\s]*)?$
</parse>
</source>
<filter xxxx>
@type record_modifier
<record>
xxxxxx xxxxxx
xxxxxx xxxxxx
time ${record['timestamp']}
</record>
</filter>
<match xxxx>
@type s3
aws_key_id xxxxxx
aws_sec_key xxxxxx
s3_bucket xxxxxx
s3_region xxxxxx
path "xxxxxx/"
s3_object_key_format "%{path}%{time_slice}/xxxxxx/%{index}.%{file_extension}"
time_slice_format %Y-%m-%d/%H
time_format %Y-%m-%dT%H:%M:%S.%L%z
format json
time_key time
include_time_key true
<buffer tag,time>
@type "file"
path "C:\\opt\\td-agent\\buffer"
timekey 3600
chunk_limit_size 64MB
flush_mode interval
flush_interval 30s
flush_thread_count 4
flush_at_shutdown true
</buffer>
<format>
@type json
</format>
<inject>
time_key time
time_format %Y-%m-%dT%H:%M:%S.%L%z
time_type string
</inject>
</match>
</ROOT>
2019-12-04 11:16:37 +0800 [info]: starting fluentd-1.7.4 pid=5376 ruby="2.4.9"
2019-12-04 11:16:37 +0800 [info]: spawn command to main: cmdline=["C:/opt/td-agent/embedded/bin/ruby.exe", "-Eascii-8bit:ascii-8bit", "C:/opt/td-agent/embedded/bin/fluentd", "-c", "C:/opt/td-agent/etc/td-agent/td-agent.conf", "-o", "C:/opt/td-agent/td-agent.log", "-x", "fluentdwinsvc", "--under-supervisor"]
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-elasticsearch' version '3.5.5'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-kafka' version '0.12.1'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-parser-winevt_xml' version '0.2.0'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-prometheus' version '1.7.0'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-record-modifier' version '2.0.1'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '2.2.0'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-s3' version '1.2.0'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-td' version '1.0.0'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-td-monitoring' version '0.2.4'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-webhdfs' version '1.2.4'
2019-12-04 11:16:38 +0800 [info]: gem 'fluent-plugin-windows-eventlog' version '0.4.3'
2019-12-04 11:16:38 +0800 [info]: gem 'fluentd' version '1.7.4'
2019-12-04 11:16:38 +0800 [info]: adding filter pattern="xxxx" type="record_modifier"
2019-12-04 11:16:38 +0800 [info]: adding match pattern="xxxx" type="s3"
2019-12-04 11:16:39 +0800 [info]: adding source type="tail"
2019-12-04 11:16:39 +0800 [info]: #0 starting fluentd worker pid=9320 ppid=5376 worker=0
2019-12-04 11:16:41 +0800 [info]: #0 following tail of E:/IntraWeb/logs/IISAccessLog/W3SVC/u_ex191128.log
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Software: Microsoft Internet Information Services 10.0"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Version: 1.0"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Date: 2019-11-28 01:30:42"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) cs(Referer) sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Software: Microsoft Internet Information Services 10.0"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Version: 1.0"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Date: 2019-11-28 01:47:12"
2019-12-04 11:16:41 +0800 [warn]: #0 pattern not matched: "#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) cs(Referer) sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken"
2019-12-04 11:16:42 +0800 [warn]: #0 failed to write data into buffer by buffer overflow action=:throw_exception
2019-12-04 11:16:42 +0800 [warn]: #0 emit transaction failed: error_class=Fluent::Plugin::Buffer::BufferOverflowError error="can't create buffer file for C:\\opt\\td-agent\\buffer/buffer.*.log. Stop creating buffer files: error = Too many open files @ rb_sysopen - C:\\opt\\td-agent\\buffer/buffer.b598d83de671a4b73ff303f141c3bfc6f.log" location="C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:291:in `rescue in create_new_chunk'" tag="xxxx"
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:291:in `rescue in create_new_chunk'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:283:in `create_new_chunk'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:54:in `initialize'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buf_file.rb:173:in `new'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buf_file.rb:173:in `generate_chunk'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:555:in `block in write_once'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/2.4.0/monitor.rb:214:in `mon_synchronize'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:555:in `write_once'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:278:in `block in write'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:276:in `each'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:276:in `write'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:954:in `block in handle_stream_with_custom_format'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:880:in `write_guard'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:953:in `handle_stream_with_custom_format'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:872:in `execute_chunking'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:800:in `emit_buffered'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/event_router.rb:160:in `emit_events'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/event_router.rb:97:in `emit_stream'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:410:in `receive_lines'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:528:in `wrap_receive_lines'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:762:in `block in handle_notify'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:806:in `with_io'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:742:in `handle_notify'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:738:in `block in on_notify'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:738:in `synchronize'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:738:in `on_notify'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:558:in `on_notify'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:532:in `attach'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:281:in `setup_watcher'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:312:in `block in start_watchers'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:298:in `each'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:298:in `start_watchers'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:275:in `refresh_watchers'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:203:in `start'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:203:in `block in start'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:192:in `block (2 levels) in lifecycle'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:191:in `each'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:191:in `block in lifecycle'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:178:in `each'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:178:in `lifecycle'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/root_agent.rb:202:in `start'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/engine.rb:274:in `start'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/engine.rb:219:in `run'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/supervisor.rb:816:in `run_engine'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/supervisor.rb:559:in `block in run_worker'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/supervisor.rb:741:in `main_process'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/supervisor.rb:554:in `run_worker'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/command/fluentd.rb:330:in `<top (required)>'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/site_ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/site_ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/bin/fluentd:8:in `<top (required)>'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/bin/fluentd:23:in `load'
2019-12-04 11:16:42 +0800 [warn]: #0 C:/opt/td-agent/embedded/bin/fluentd:23:in `<main>'
2019-12-04 11:16:42 +0800 [info]: #0 fluentd worker is now running worker=0
2019-12-04 11:16:43 +0800 [warn]: #0 failed to write data into buffer by buffer overflow action=:throw_exception
2019-12-04 11:16:43 +0800 [warn]: #0 emit transaction failed: error_class=Fluent::Plugin::Buffer::BufferOverflowError error="can't create buffer file for C:\\opt\\td-agent\\buffer/buffer.*.log. Stop creating buffer files: error = Too many open files @ rb_sysopen - C:\\opt\\td-agent\\buffer/buffer.b598d83df69790119ca6cba13d84aab66.log" location="C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:291:in `rescue in create_new_chunk'" tag="xxxx"
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:291:in `rescue in create_new_chunk'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:283:in `create_new_chunk'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer/file_chunk.rb:54:in `initialize'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buf_file.rb:173:in `new'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buf_file.rb:173:in `generate_chunk'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:555:in `block in write_once'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/2.4.0/monitor.rb:214:in `mon_synchronize'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:555:in `write_once'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:278:in `block in write'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:276:in `each'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/buffer.rb:276:in `write'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:954:in `block in handle_stream_with_custom_format'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:880:in `write_guard'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:953:in `handle_stream_with_custom_format'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:872:in `execute_chunking'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/output.rb:800:in `emit_buffered'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/event_router.rb:160:in `emit_events'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/event_router.rb:97:in `emit_stream'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:410:in `receive_lines'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:528:in `wrap_receive_lines'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:762:in `block in handle_notify'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:806:in `with_io'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:742:in `handle_notify'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:738:in `block in on_notify'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:738:in `synchronize'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:738:in `on_notify'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:558:in `on_notify'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin/in_tail.rb:644:in `on_timer'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/cool.io-1.5.4/lib/cool.io/loop.rb:88:in `run_once'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/cool.io-1.5.4/lib/cool.io/loop.rb:88:in `run'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin_helper/event_loop.rb:93:in `block in start'
2019-12-04 11:16:43 +0800 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.7.4/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2019-12-04 11:16:44 +0800 [warn]: #0 failed to flush the buffer. retry_time=0 next_retry_seconds=2019-12-04 11:16:45 +0800 chunk="598d83dd34653b8762cfb31e650b22df" error_class=Errno::EMFILE error="Failed to open TCP connection to ac-conversion-log-bucket.s3.ap-northeast-1.amazonaws.com:443 (Too many open files - socket(2) for \"ac-conversion-log-bucket.s3.ap-northeast-1.amazonaws.com\" port 443)"
...
retry log continues from flush buffer
Additional context:
Using same config inside a fluent Debian container fluent/fluentd:v1.7-debian-1 works fine on both Linux and Windows 10 Pro(with linux container support).
Problem happens only while running fluentd directly as a service on Windows or using same config inside a fluent Windows container Windows Server 2016(can't run linux container).
So I suspect there is something wrong specifically with fluent packaging on Windows. Please help!
We are trying to use fluentd on Windows for logs collection, but it seems that buffer section's
chunk_limit_sizeis not working on windows.Even though
chunk_limit_sizevalue is defined as high as 64 MB, fluentd creates a lot of small small chunk files of size 0-1 KB with just 1 log line in each.Because of this the Windows file descriptors limit(for a process) is reached and then fluentd fails with Error Logs saying not able to write new chunk file and failed to flush the buffer.
Steps to reproduce the behavior:
[Windows] Create a sample log file with significant amount of log lines (say 100k)
Below is a sample from IIS Access Log file used for testing
Install td-agent(td-agent-3.5.1-0-x64.msi), configure it using below config file and then start fluentd Service.
Expected behavior:
Fluentd should not create a lot of small small chunk files of size 0-1KB, rather respect the
chunk_size_limitvalue of defined 64MB.Testing environment:
Test config:
Error Log:
Within 1-2 sec of starting Fluentd Service, the buffer folder suddenly explodes with 2040 files (buffer.xx.log and buffer.xx.log.meta file combos).
Each of the buffer.xx.log contains only 1 log line event and td-agent log starts showing warn logs stating Can't create new buffer file.
Additional context:
Using same config inside a fluent Debian container fluent/fluentd:v1.7-debian-1 works fine on both Linux and Windows 10 Pro(with linux container support).
Problem happens only while running fluentd directly as a service on Windows or using same config inside a fluent Windows container Windows Server 2016(can't run linux container).
So I suspect there is something wrong specifically with fluent packaging on Windows. Please help!