FluentD keeps crashing when state_file is set

[ESH-Schroeder]

System Information

• OS: Debian 11 ( Bullseye )
• Install Method: via APT using LTS Channel
• Software: fluent-package v5.0.2 ( FluentD 1.16.3 )

Plugin Information

• fluent-gem install fluent-plugin-sql --no-document // ( => v. 2.3.0 )
• fluent-gem install mysql2 --no-document // ( => v. 0.5.5 )

Plugin Config

<system>
  log_level trace
</system>
(...)
<source>
  @type sql
  @id input_sql_db

  host localhost
  port 3306
  adapter mysql2
  database <database>
  username <db_user>
  password <db_pw>

  state_file /var/log/fluent/sql.state

  <table>
    table table1
    tag sql_table1
    time_column date
  </table>

  <table>
    table table2
    tag sql_table2
    time_column startdate
    time_format %Y-%m-%d %H:%M:%S
  </table>
</source>
(...)

Current Behaviour

If the parameter 'state_file' is omitted, Fluentd starts normally,
but keeps transferring the whole DB Tables to our Logging System on each restart of FluentD.
The SQL Plugin became successfully initialized.

If 'state_file' is set, FluentD tries to read the target file but keeps crashing while initializing the SQL Plugin.
I already tried different things to fix this issue:

• Recreate the target file manually
• Change the file Ownership from root to _fluentd
• Change the file permissions to 0777
• Relocate the target file to various different paths, writeable to the _fluentd user
• Placing singleticks or doubleticks around the literal path

Crash Logs

2024-01-08 11:45:50 +0100 [info]: fluent/log.rb:362:info: adding source type="tail"
2024-01-08 11:45:50 +0100 [trace]: #0 fluent/log.rb:319:trace: registered parser plugin 'regexp'
2024-01-08 11:45:50 +0100 [trace]: #0 fluent/log.rb:319:trace: registered parser plugin 'multiline'
2024-01-08 11:45:50 +0100 [trace]: #0 fluent/log.rb:319:trace: registered input plugin 'tail'
2024-01-08 11:45:50 +0100 [info]: fluent/log.rb:362:info: adding source type="sql"
2024-01-08 11:45:50 +0100 [trace]: #0 fluent/log.rb:319:trace: registered input plugin 'sql'
2024-01-08 11:45:50 +0100 [debug]: #0 fluent/log.rb:341:debug: No fluent logger for internal event
2024-01-08 11:45:50 +0100 [info]: #0 fluent/log.rb:362:info: starting fluentd worker pid=3856210 ppid=3856188 worker=0
2024-01-08 11:45:50 +0100 [debug]: #0 fluent/log.rb:341:debug: buffer started instance=3040 stage_size=0 queue_size=0
2024-01-08 11:45:50 +0100 [error]: #0 fluent/log.rb:404:error: unexpected error error_class=NoMethodError error="undefined method `exists?' for File:Class"
2024-01-08 11:45:50 +0100 [debug]: #0 fluent/log.rb:341:debug: flush_thread actually running
2024-01-08 11:45:50 +0100 [debug]: #0 fluent/log.rb:341:debug: enqueue_thread actually running
2024-01-08 11:45:50 +0100 [trace]: #0 fluent/log.rb:319:trace: enqueueing all chunks in buffer instance=3040
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluent-plugin-sql-2.3.0/lib/fluent/plugin/in_sql.rb:285:in `initialize'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluent-plugin-sql-2.3.0/lib/fluent/plugin/in_sql.rb:186:in `new'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluent-plugin-sql-2.3.0/lib/fluent/plugin/in_sql.rb:186:in `start'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:203:in `block in start'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:192:in `block (2 levels) in lifecycle'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:191:in `each'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:191:in `block in lifecycle'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:178:in `each'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:178:in `lifecycle'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/root_agent.rb:202:in `start'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/engine.rb:248:in `start'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/engine.rb:147:in `run'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/supervisor.rb:617:in `block in run_worker'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/supervisor.rb:962:in `main_process'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/supervisor.rb:608:in `run_worker'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/lib/fluent/command/fluentd.rb:372:in `<top (required)>'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: <internal:/opt/fluent/lib/ruby/site_ruby/3.2.0/rubygems/core_ext/kernel_require.rb>:127:in `require'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: <internal:/opt/fluent/lib/ruby/site_ruby/3.2.0/rubygems/core_ext/kernel_require.rb>:127:in `require'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/lib/ruby/gems/3.2.0/gems/fluentd-1.16.3/bin/fluentd:15:in `<top (required)>'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/bin/fluentd:25:in `load'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /opt/fluent/bin/fluentd:25:in `<top (required)>'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /usr/sbin/fluentd:15:in `load'
  2024-01-08 11:45:50 +0100 [error]: #0 fluent/supervisor.rb:962:main_process: /usr/sbin/fluentd:15:in `<main>'

[rophy]

Not sure if this plugin is still active, but I have managed to find the root cause, and created a patch for it: #144

Before the patch got merged. For me, I can workaround it by manually "patching it" in locally installed gem:

1. Locate gems/fluent-plugin-sql-2.3.0/lib/fluent/plugin/in_sql.rb in your local ruby installation.
2. Change this line:

if File.exists?(@path)

to:

if File.exist?(@path)

[ashie]

Fixed by #144. Thanks!