ククログ

株式会社クリアコード > ククログ > Fluentd実行中にgemが期待通りに読み込まれているか確認する方法 - fluent-plugin-record-modifierで$LOADED_FEATURESを確認

Fluentd実行中にgemが期待通りに読み込まれているか確認する方法 - fluent-plugin-record-modifierで$LOADED_FEATURESを確認

Fluentdを各種プラグインと組み合わせて使う際、指定したgemが期待通りに読み込まれていないという事例に遭遇したことがありました。

今回は、そんなときのために、「Fluentd実行中にgemが期待通りに読み込まれているか確認する方法」を紹介します。

問題となった事例

Fluentdでは、簡単に使えるようにDockerイメージを公開しています。 あるとき、CPU使用率が異常に高くなるトラブルの報告がありました。 問題はresolvライブラリーにあり、v0.2.1で修正されていたので、該当バージョンをインストールすれば解決するはずでした。1

しかし、実際には標準でバンドルされているほうのresolvが先に読み込まれてしまっていました。 せっかくインストールしたバージョンが使われていなかった 2 のです。

期待通りにgemが読み込まれているかを確認するには$LOADED_FEATURESを見れば確実なのですが、Fluentd本体をいじることなく設定ファイルの記述でそのあたりをうまくチェックするにはひと工夫必要です。3

結論からいうと、Fluentdの設定ファイルを次のようにして実行すると指定したgemが期待通りに読み込まれているか確認できます。

<source>
 @type sample
 tag sample
</source>

<filter>
  @type record_modifier
  remove_keys _dummy_
  <record>
    _dummy_ ${record['loaded'] = $LOADED_FEATURES.collect { |entry| entry if entry.include?('resolv.rb') }.compact }
  </record>
</filter>

<match sample>
  @type stdout
</match>

ポイントは record_modifierを使うところです。 fluent-plugin-record-modifierのREAME.mdで紹介されているRuby codetrick for complex logic というテクニックを使います。 これを使うことで、レコードを加工して読み込まれているresolv.rbのパスを取り出すという処理を追加できます。

次のようにDockerイメージを動かすことで、読み込まれたライブラリーのパスを確かめることができます。

% docker run -v $PWD:/fluentd/etc -it (record_modifierを組み込んだカスタムイメージを指定) -c /fluentd/etc/fluent.conf
fluentd -c /fluentd/etc/fluent.conf
2021-06-09 02:52:35 +0000 [info]: parsing config file is succeeded path="/fluentd/etc/fluent.conf"
2021-06-09 02:52:35 +0000 [info]: gem 'fluent-plugin-record-modifier' version '2.1.0'
2021-06-09 02:52:35 +0000 [info]: gem 'fluentd' version '1.12.4'
2021-06-09 02:52:35 +0000 [warn]: both of Plugin @id and path for <storage> are not specified. Using on-memory store.
2021-06-09 02:52:35 +0000 [warn]: both of Plugin @id and path for <storage> are not specified. Using on-memory store.
2021-06-09 02:52:35 +0000 [warn]: define <match fluent.**> to capture fluentd logs in top level is deprecated. Use <label @FLUENT_LOG> instead
2021-06-09 02:52:35 +0000 [info]: using configuration file: <ROOT>
  <source>
    @type sample
    tag "sample"
  </source>
  <filter>
    @type record_modifier
    remove_keys "_dummy_"
    <record>
      _dummy_ ${record['loaded'] = $LOADED_FEATURES.collect { |entry| entry if entry.include?('resolv.rb') }.compact }
    </record>
  </filter>
  <match sample>
    @type stdout
  </match>
</ROOT>
2021-06-09 02:52:35 +0000 [info]: starting fluentd-1.12.4 pid=7 ruby="2.6.7"
2021-06-09 02:52:35 +0000 [info]: spawn command to main:  cmdline=["/usr/local/bin/ruby", "-Eascii-8bit:ascii-8bit", "/usr/local/bundle/bin/fluentd", "-c", "/fluentd/etc/fluent.conf", "-p", "/fluentd/plugins", "--under-supervisor"]
2021-06-09 02:52:35 +0000 [info]: adding filter pattern="**" type="record_modifier"
2021-06-09 02:52:35 +0000 [info]: adding match pattern="sample" type="stdout"
2021-06-09 02:52:35 +0000 [info]: adding source type="sample"
2021-06-09 02:52:35 +0000 [warn]: #0 both of Plugin @id and path for <storage> are not specified. Using on-memory store.
2021-06-09 02:52:35 +0000 [warn]: #0 both of Plugin @id and path for <storage> are not specified. Using on-memory store.
2021-06-09 02:52:35 +0000 [warn]: #0 define <match fluent.**> to capture fluentd logs in top level is deprecated. Use <label @FLUENT_LOG> instead
2021-06-09 02:52:35 +0000 [info]: #0 starting fluentd worker pid=16 ppid=7 worker=0
2021-06-09 02:52:35 +0000 [info]: #0 fluentd worker is now running worker=0
2021-06-09 02:52:35 +0000 [warn]: #0 no patterns matched tag="fluent.info"
2021-06-09 02:52:35 +0000 [warn]: #0 no patterns matched tag="fluent.info"
2021-06-09 02:52:36.048169263 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}
2021-06-09 02:52:37.049527384 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}
2021-06-09 02:52:38.050816670 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}
2021-06-09 02:52:39.052066477 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}
2021-06-09 02:52:40.053464464 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}
2021-06-09 02:52:41.054786553 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}
^C2021-06-09 02:52:41 +0000 [info]: Received graceful stop

出力された2021-06-09 02:52:36.048169263 +0000 sample: {"message":"sample","loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]}というイベントに着目してみましょう。 "loaded":["/usr/local/bundle/gems/resolv-0.2.1/lib/resolv.rb"]とでているので、gemでインストールしたほうのresolvが使われていることがわかります。

さいごに

クリアコードではFluentd/Fluent Bitのサポートサービスを提供しています。 お困りのことがあれば、こちらのお問い合わせフォームからご連絡ください。

  1. なおRuby 2.6.7, 2.7.3 および 3.0.1がこの問題の影響を受けます。

  2. $LOAD_PATHを明示的に指定することで解決しました。

  3. Fluentd起動時に使われているFluentdのバージョンと、プラグインのバージョンならわかりますが、それらが依存しているgemについては表示されません。