Skip to content

Buffer's chunk_limit_size not working as expected on Windows platform #2713

@mandyjohar23

Description

@mandyjohar23

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!

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type
No fields configured for issues without a type.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions