Fluentd Container Outputs Overwhelming Amount of Error/Warn Logs

[amrubal01]

Hi all, I am currently encountering an issue in which my fluentd container outputs an overwhelming amount of error and warn logs regarding output plug ins.

1. Fluentd Conf file:

`<source>
    @type  forward
    port  24224
  </source>

  <filter @FLUENT_LOG>
    @type stdout
  </filter>

  <match docker.**>
    @type file 
    path /fluentd/log/clabs.*.log
    symlink_path /fluentd/log/docker.log
    append  true
    <buffer>
      timekey 1d
      timekey_use_utc true
      timekey_wait 1m
    </buffer>
  </match>`

2. Environment:
   I built a fluentd ubuntu image using the guide on the fluentd site. I originally thought the fluentd docker image I was pulling was the culprit.

`2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: init supervisor logger path=nil rotate_age=nil rotate_size=nil
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: parsing config file is succeeded path="/etc/fluent/fluentd.conf"
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluentd' version '1.16.3'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-calyptia-monitoring' version '0.1.3'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-elasticsearch' version '5.4.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-flowcounter-simple' version '0.1.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-kafka' version '0.19.2'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-metrics-cmetrics' version '0.1.2'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-opensearch' version '1.1.4'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-prometheus' version '2.1.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-prometheus_pushgateway' version '0.1.1'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-record-modifier' version '2.1.1'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-rewrite-tag-filter' version '2.4.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-s3' version '1.7.2'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-sd-dns' version '0.1.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-systemd' version '1.0.5'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-td' version '1.2.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-utmpx' version '0.5.0'
2023-12-07 05:01:40 +0000 [info]: fluent/log.rb:362:info: gem 'fluent-plugin-webhdfs' version '1.5.0'`

The error/warn logs I get look like this:

` 2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/output.rb:915:in `metadata'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/output.rb:1042:in `block in handle_stream_with_custom_format'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/event.rb:110:in `each'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/output.rb:1041:in `handle_stream_with_custom_format'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/output.rb:969:in `execute_chunking'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/output.rb:897:in `emit_buffered'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/event_router.rb:115:in `emit_stream'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/event_router.rb:106:in `emit'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/in_forward.rb:355:in `on_message'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/in_forward.rb:226:in `block in handle_connection'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/in_forward.rb:263:in `block (3 levels) in read_messages'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/in_forward.rb:262:in `feed_each'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/in_forward.rb:262:in `block (2 levels) in read_messages'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin/in_forward.rb:271:in `block in read_messages'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin_helper/server.rb:640:in `on_read_without_connection'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/cool.io-1.8.0/lib/cool.io/io.rb:123:in `on_readable'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/cool.io-1.8.0/lib/cool.io/io.rb:186:in `on_readable'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/cool.io-1.8.0/lib/cool.io/loop.rb:88:in `run_once'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/cool.io-1.8.0/lib/cool.io/loop.rb:88:in `run'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin_helper/event_loop.rb:93:in `block in start'
  2023-12-07 04:32:05 +0000 [warn]: #0 /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'`

They only occur when the match block is present, essentially adding file persistence causes these warn/error logs to be output when I run 'logs -f'. Any advice or direction would be greatly appreciated! Please let me know if I can provide any additional information!

[UriZafrir]

i have exactly the same problem! any solution for this?

2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection: /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin_helper/event_loop.rb:93:in `block in start'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'  
2025-03-09 09:33:21 +0000 [warn]: #0 fluent/log.rb:383: warn: unexpected error error="Could not parse data entirely (0 != 1429)"  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin/in_http.rb:375:in `<<' 
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin/in_http.rb:375:in `on_read'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:/usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin/in_http.rb:267:in `block in on_server_connect'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin_helper/server.rb:649:in `on_read_without_connection'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection: /usr/local/bundle/gems/cool.io-1.9.0/lib/cool.io/io.rb:123:in `on_readable'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/cool.io-1.9.0/lib/cool.io/io.rb:186:in `on_readable'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/cool.io-1.9.0/lib/cool.io/loop.rb:88:in `run_once' 
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/cool.io-1.9.0/lib/cool.io/loop.rb:88:in `run'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin_helper/event_loop.rb:93:in `block in start'  
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection:  /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'  

[daipom]

2025-03-09 09:33:21 +0000 [warn]: #0 fluent/log.rb:383: warn: unexpected error error="Could not parse data entirely (0 != 1429)"
2025-03-09 09:33:21 +0000 [warn]: #0 plugin_helper/server.rb:649: on_read_without_connection: /usr/local/bundle/gems/fluentd-1.18.0/lib/fluent/plugin/in_http.rb:375:in `<<'

It looks like the in_http plugin receives data with an incorrect format.

[daipom]

The error/warn logs I get look like this:

Sorry for the late response.
These logs are stack traces.
There should be an original error or warning log.

[UriZafrir]

Hi, thanks for the replies!
these logs are debug logs from "docker logs -f kong"...
where can i find the original error or warning log?
does this have to do with the fluent.conf down below?
it did work for me in a different environment. I also tried switching kong versions so as to see maybe this has to do with an old http plugin version.
I also tried tcpdump on the messages sent from kong and sending the http message directly to fluentd.. it also worked.

<label @KONG>
  <filter **>
    @type record_transformer
    enable_ruby true
    <record>
      request_id ${record["request"]["id"]}
      request_size ${record["request"]["size"]}
      request_method ${record["request"]["method"]}
      request_uri ${record["request"]["uri"]}
      request_url ${record["request"]["url"]}
      request_querystring ${record["request"]["querystring"].to_json}
      request_headers ${record["request"]["headers"].to_json}
    </record>
    remove_keys request
  </filter>
  <match **>
    @type opensearch
    host opensearch
    port 9200
    @log_level debug
    index_name kong
    <buffer>
      @type memory
      flush_interval 1s 
    </buffer>
  </match>
</label>