search

emsearcy / fluent-plugin-gelf

Buffered fluentd output plugin to GELF (Graylog2)
Apache License 2.0
33 stars 57 forks source link

UndefinedConversionError #2

Open suprememoocow opened 9 years ago

suprememoocow commented 9 years ago

Hi,

I am experiencing UndefinedConversionError errors when emitting log messages containing non-ASCII characters, such as Russian or Japanese text.

For example: Log message contains "привет"...

2015-01-31 17:31:58 +0000 [warn]: emit transaction failed  error_class=Encoding::UndefinedConversionError error=#<Encoding::UndefinedConversionError: "\xD0" from ASCII-8BIT to UTF-8>
  2015-01-31 17:31:58 +0000 [warn]: /etc/td-agent/plugin/out_gelf.rb:77:in `encode'
  2015-01-31 17:31:58 +0000 [warn]: /etc/td-agent/plugin/out_gelf.rb:77:in `to_json'
  2015-01-31 17:31:58 +0000 [warn]: /etc/td-agent/plugin/out_gelf.rb:77:in `format'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/output.rb:259:in `block in format_stream'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/event.rb:55:in `call'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/event.rb:55:in `each'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/output.rb:258:in `format_stream'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/output.rb:244:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/match.rb:36:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/engine.rb:160:in `emit_stream'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/engine.rb:140:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-record-reformer-0.4.0/lib/fluent/plugin/out_record_reformer.rb:90:in `block in emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/event.rb:129:in `call'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/event.rb:129:in `block in each'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/event.rb:128:in `each'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/event.rb:128:in `each'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-record-reformer-0.4.0/lib/fluent/plugin/out_record_reformer.rb:87:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/output.rb:33:in `next'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-record-reformer-0.4.0/lib/fluent/plugin/out_record_reformer.rb:92:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/output.rb:33:in `next'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/out_copy.rb:73:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/match.rb:36:in `emit'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/engine.rb:160:in `emit_stream'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-mongo-slow-query-0.0.5/lib/fluent/plugin/in_mongo_slow_query.rb:71:in `receive_lines'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/in_tail.rb:1031:in `call'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/in_tail.rb:1031:in `on_notify'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/in_tail.rb:855:in `on_notify'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/in_tail.rb:966:in `call'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/in_tail.rb:966:in `on_change'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/loop.rb:88:in `run_once'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/loop.rb:88:in `run'
  2015-01-31 17:31:58 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.10.58/lib/fluent/plugin/in_tail.rb:768:in `run'
qburst-praven commented 8 years ago

Any luck getting this fixed? I've seen the http plugin, has switched from using 'json' to using 'yajl' to fix this - https://github.com/ento/fluent-plugin-out-http/pull/2 - Could something similar be done here?

Regards Praven

emsearcy commented 8 years ago

The above stack trace (to_json() from format()) is just for the case where you didn't parse out a short_message (e.g. wrap your in_tail regex in a (?<short_message>EVERYTHING ELSE HERE) ... it's a fallback json encoding of all the fields which isn't really meant to be used (see #3 for a discussion on the unintuitiveness of this behavior...). Yes, we could use yajl. However, you still will likely see problems because the gelf-rb library also uses to_json (https://github.com/jondot/gelf-rb/blob/master/lib/gelf/notifier.rb#L230) on our objects. I think a better fix would be to use the undocumented "encoding" param on your in_tails (https://github.com/fluent/fluentd/blob/master/lib/fluent/plugin/in_tail.rb#L67) ... or convince fluentd/in_tail upstream to (optionally?) autodetect charset instead of using File.open(File::BINARY)! Or, an alternative may be to fix all our strings back to UTF8 before we send them, since the GELF protocol says it expects UTF8.

Please let me know if "encoding" in_tail (or in_gelftail) param works for you, and check out the open pull requests on encoding.

emsearcy commented 7 years ago

Hi! So, I've got two things to address this. First, as of d7e6550 fluent-plugin-gelf no longer automatically constructs a json representation of the message, so you'll never see this with a stack trace of out_gelf.rb/format->to_json->encode any more. Unfortunately, this error still crops up with the to_json that gelf-rb (the Ruby GELF client library) uses, with a stack trace like:

2016-10-27 00:59:13 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:257:in `to_json'
2016-10-27 00:59:13 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:257:in `serialize_hash'
2016-10-27 00:59:13 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:227:in `datagrams_from_hash'
2016-10-27 00:59:13 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:162:in `notify_with_level!'
2016-10-27 00:59:13 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:119:in `notify!'
2016-10-27 00:59:13 +0000 [warn]: /etc/td-agent/plugin/out_gelf.rb:102:in `block in write'

To that end, I've created a pull request Graylog2/gelf-rb#53.

suneeta-mall commented 6 years ago

@emsearcy whats the status of this issue ? I still see it on the gelf_out plugin from master:

2017-09-24 22:21:39 +0000 [warn]: #0 failed to flush the buffer. retry_time=0 next_retry_seconds=2017-09-24 22:21:40 +0000 chunk="559f6dd9221f3cdd466888c48bf50b9b" error_class=Encoding::UndefinedConversionError error="\"\\xC2\" from ASCII-8BIT to UTF-8"
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:257:in `encode'
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:257:in `to_json'
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:257:in `serialize_hash'
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:227:in `datagrams_from_hash'
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:162:in `notify_with_level!'
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/gelf-3.0.0/lib/gelf/notifier.rb:119:in `notify!'
  2017-09-24 22:21:39 +0000 [warn]: #0 /var/lib/gems/2.3.0/gems/fluent-plugin-gelf-hs-1.0.4/lib/fluent/plugin/out_gelf.rb:79:in `block in write'

This is the message that it fails to convert:

kube-apiserver.log:55:I0922 00:17:12.144729       5 wrap.go:42] GET /api/v1/namespaces/default: (841.773µs) 200 [[kube-apiserver/v1.7.2 (linux/amd64) kubernetes/922a86c] 127.0.0.1:38142]

I have also tried this plugin https://github.com/bodhi-space/fluent-plugin-gelf-hs (forked from this one) but same issue.

kumaravel29 commented 6 years ago

Any updates on this issue Facing the same problem

Seji64 commented 6 years ago

I "fixed" the problem by doing the following:

It may help someone else.