fluentdでUndefinedConversionErrorに遭遇した

エラーログはこんな感じ。

  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluent-mixin-plaintextformatter-0.2.6/lib/fluent/mixin/plaintextformatter.rb:85:in `encode'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluent-mixin-plaintextformatter-0.2.6/lib/fluent/mixin/plaintextformatter.rb:85:in `to_json'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluent-mixin-plaintextformatter-0.2.6/lib/fluent/mixin/plaintextformatter.rb:85:in `stringify_record'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluent-mixin-plaintextformatter-0.2.6/lib/fluent/mixin/plaintextformatter.rb:115:in `format'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/output.rb:590:in `block in emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/event.rb:149:in `feed_each'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/event.rb:149:in `each'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/output.rb:574:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluent-plugin-forest-0.3.3/lib/fluent/plugin/out_forest.rb:175:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/event_router.rb:90:in `emit_stream'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/out_relabel.rb:24:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/output.rb:42:in `next'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/out_relabel.rb:25:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/output.rb:42:in `next'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/out_relabel.rb:25:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/output.rb:42:in `next'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluent-plugin-flowcounter-0.4.3/lib/fluent/plugin/out_flowcounter.rb:202:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/output.rb:42:in `next'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/out_copy.rb:78:in `emit'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/event_router.rb:90:in `emit_stream'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/in_forward.rb:178:in `on_message'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/in_forward.rb:338:in `call'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/in_forward.rb:338:in `block in on_read_msgpack'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/in_forward.rb:337:in `feed_each'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/in_forward.rb:337:in `on_read_msgpack'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/cool.io-1.5.0/lib/cool.io/io.rb:123:in `on_readable'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/cool.io-1.5.0/lib/cool.io/io.rb:186:in `on_readable'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/cool.io-1.5.0/lib/cool.io/loop.rb:88:in `run_once'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/cool.io-1.5.0/lib/cool.io/loop.rb:88:in `run'
  2017-08-07 12:25:55 +0900 [warn]: /path/to/ruby-2.2/lib/ruby/gems/2.2.0/gems/fluentd-0.12.39/lib/fluent/plugin/in_forward.rb:120:in `run'
  2017-08-07 12:25:55 +0900 [warn]: emit transaction failed: error_class=Encoding::UndefinedConversionError error="\"\\xE3\" from ASCII-8BIT to UTF-8" tag="..."

fluentdやプラグインのバージョンを上げる作業をしていて遭遇しました。

いろいろ試行錯誤して結局msgpackのバージョンを1.1.0から0.5.12にしたら回避できた。

fluend 0.12.32からmsgpackのバージョンが上がったのが原因ぽい。
https://github.com/fluent/fluentd/commit/e50a98ce518cadb3a37f76cde67ba8c6e076f638

これはmsgpack 0.6.0でバイナリを扱うようになり、今まではASCII-8BIT→msgpackのシリアライズ→デシリアライズUTF-8→to_jsonでエラーにならなかったのが、ASCII-8BITをto_jsonでエラーということっぽい。
https://github.com/msgpack/msgpack-ruby/issues/44

よく見ると本家のFAQにあったけど、要は上流のデータの文字コード指定が間違ってるという話
https://docs.fluentd.org/v0.12/articles/faq#i-got-enconding-error-inside-plugin-how-to-fix-it

確かにin_tailでマルチバイト文字を見てるところあるな。。。

ただfluentdの送信側をこちらでコントロールできない場合があるので、どうしたものか。。。


2017/08/09追記
in_tailでマルチバイト文字見てると思ったらurl encodeされてたので大丈夫そう。
そもそもfluent-plugin-flowcounterからfluent-mixin-plaintextformatterがなぜ呼び出されてるのかわからん。
fluent-plugin-forestからfluent-plugin-webhdfsを使ってはいるけど関係してないと思うんだけどなあ。