Plugins behaviour when shutting down fluentd

[Tsai Li Ming]

Hi,

Should plugins behave properly when fluentd is being shutdown?

Here’s an example of the influxdb after sending some data over the local tcp port.

ctrl-c doesn’t shutdown fluentd.

# td-agent -v -c /tmp/test.conf
2015-09-16 18:38:11 +0800 [info]: fluent/supervisor.rb:403:read_config: reading config file path="/tmp/test.conf"
2015-09-16 18:38:11 +0800 [info]: fluent/supervisor.rb:279:supervise: starting fluentd-0.12.12
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-mixin-config-placeholders' version '0.3.0'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-mixin-plaintextformatter' version '0.2.6'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-influxdb' version '0.2.1'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-kafka' version '0.0.14'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-mongo' version '0.7.10'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-mqtt' version '0.0.3'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-norikra' version '0.3.0'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-reassemble' version '0.0.8'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-rewrite-tag-filter' version '1.4.1'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-s3' version '0.5.9'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-scribe' version '0.10.14'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-secure-forward' version '0.3.2'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-slack' version '0.6.1'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-sql' version '0.4.2'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-td' version '0.10.27'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-td-monitoring' version '0.2.1'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-twitter' version '0.4.1'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluent-plugin-webhdfs' version '0.4.1'
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:90:block in configure: gem 'fluentd' version '0.12.12'
2015-09-16 18:38:11 +0800 [info]: fluent/agent.rb:123:add_match: adding match pattern="foo" type="influxdb"
2015-09-16 18:38:11 +0800 [info]: fluent/root_agent.rb:142:add_source: adding source type="tcp"
2015-09-16 18:38:11 +0800 [info]: fluent/engine.rb:97:configure: using configuration file: <ROOT>
<source>
type tcp
format json
bind 192.168.56.102
port 8222
tag foo
</source>
<match foo>
type influxdb
host localhost
port 8086
dbname data
use_ssl false
time_precision s
</match>
</ROOT>
2015-09-16 18:38:11 +0800 [debug]: plugin/in_tcp.rb:27:listen: listening tcp socket on 192.168.56.102:8222
^C2015-09-16 18:38:36 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:38:36 +0800 [debug]: fluent/supervisor.rb:501:block in install_main_process_signal_handlers: getting start to shutdown main process
2015-09-16 18:38:36 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:38:36 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:38:36 +0800 [info]: fluent/engine.rb:175:run: shutting down fluentd
2015-09-16 18:38:36 +0800 [debug]: plugin/out_influxdb.rb:65:write: []
E, [2015-09-16T18:38:36.540345 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.01s.
E, [2015-09-16T18:38:36.553928 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.02s.
E, [2015-09-16T18:38:36.582079 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.04s.
E, [2015-09-16T18:38:36.627000 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.08s.
E, [2015-09-16T18:38:36.709096 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.16s.
E, [2015-09-16T18:38:36.874916 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.32s.
E, [2015-09-16T18:38:37.199424 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 0.64s.
E, [2015-09-16T18:38:37.849067 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 1.28s.
E, [2015-09-16T18:38:39.134489 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 2.56s.
E, [2015-09-16T18:38:41.698881 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 5.12s.
^C2015-09-16 18:38:42 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:38:42 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:38:42 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
^C2015-09-16 18:38:44 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:38:44 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:38:44 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
^C2015-09-16 18:38:45 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:38:45 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:38:45 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
E, [2015-09-16T18:38:46.821567 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 10.24s.
E, [2015-09-16T18:38:57.064418 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 20.48s.
E, [2015-09-16T18:39:17.547419 #18327] ERROR -- : [InfluxDB] Failed to contact host localhost: #<Errno::ECONNREFUSED: Connection refused - connect(2) for "localhost" port 8086> - retrying in 30s.
^C2015-09-16 18:39:18 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:39:18 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:39:18 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
^C2015-09-16 18:39:18 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:39:18 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:39:18 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
^C2015-09-16 18:39:19 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:39:19 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:39:19 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
^C2015-09-16 18:39:19 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:39:19 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:39:19 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT

If no data is being received, it will shutdown cleanly:
2015-09-16 18:41:08 +0800 [debug]: plugin/in_tcp.rb:27:listen: listening tcp socket on 192.168.56.102:8222
^C2015-09-16 18:41:10 +0800 [debug]: fluent/supervisor.rb:332:block in install_supervisor_signal_handlers: fluentd supervisor process get SIGINT
2015-09-16 18:41:10 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:41:10 +0800 [debug]: fluent/supervisor.rb:501:block in install_main_process_signal_handlers: getting start to shutdown main process
2015-09-16 18:41:10 +0800 [debug]: fluent/supervisor.rb:498:block in install_main_process_signal_handlers: fluentd main process get SIGINT
2015-09-16 18:41:10 +0800 [info]: fluent/engine.rb:175:run: shutting down fluentd
2015-09-16 18:41:11 +0800 [info]: fluent/supervisor.rb:296:supervise: process finished code=0

Thanks!

[Mr. Fiber]

Generally, output destination should not stop before fluentd shutdown

because if users use memory buffer, these logs are gone.

BTW, this error should be fixed.

Hmm... maybe outputs warning message and ignoring errors is better.

Could you send a patch?

Masahiro

--
You received this message because you are subscribed to the Google Groups "Fluentd Google Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to fluentd+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Li Ming Tsai]

I filed an issue on the source: https://github.com/fangli/fluent-plugin-influxdb/issues/29