can't convert nil into an exact number

[scalp42]

@kaecyra I'm running into an issue trying to parse Docker logs using FluentD logging driver.

Error is:

2015-11-25 21:36:01 +0000 [warn]: emit transaction failed: error_class=TypeError error="can't convert nil into an exact number" tag="requestbin"
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/out_stdout.rb:44:in `at'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/out_stdout.rb:44:in `block in emit'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event.rb:54:in `call'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event.rb:54:in `each'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/out_stdout.rb:43:in `emit'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event_router.rb:88:in `emit_stream'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/engine.rb:116:in `emit_stream'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/engine.rb:107:in `emit'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-burrow-1.1/lib/fluent/plugin/out_burrow.rb:143:in `block in emit'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event.rb:54:in `call'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event.rb:54:in `each'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-burrow-1.1/lib/fluent/plugin/out_burrow.rb:102:in `emit'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event_router.rb:88:in `emit_stream'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/event_router.rb:79:in `emit'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:169:in `on_message'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:243:in `call'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:243:in `block in on_read_msgpack'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:242:in `feed_each'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:242:in `on_read_msgpack'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:228:in `call'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:228:in `on_read'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.3.0/lib/cool.io/io.rb:123:in `on_readable'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.3.0/lib/cool.io/io.rb:186:in `on_readable'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.3.0/lib/cool.io/loop.rb:88:in `run_once'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.3.0/lib/cool.io/loop.rb:88:in `run'
  2015-11-25 21:36:01 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.12/lib/fluent/plugin/in_forward.rb:91:in `run'
2015-11-25 21:36:01 +0000 [warn]: emit transaction failed: error_class=TypeError error="can't convert nil into an exact number" tag="marathon.requestbin"
  2015-11-25 21:36:01 +0000 [warn]: suppressed same stacktrace
2015-11-25 21:36:01 +0000 [error]: forward error error=#<TypeError: can't convert nil into an exact number> error_class=TypeError
  2015-11-25 21:36:01 +0000 [error]: suppressed same stacktrace
2015-11-25 21:36:01 +0000 [warn]: emit transaction failed: error_class=TypeError error="can't convert nil into an exact number" tag="requestbin"
  2015-11-25 21:36:01 +0000 [warn]: suppressed same stacktrace
2015-11-25 21:36:01 +0000 [warn]: emit transaction failed: error_class=TypeError error="can't convert nil into an exact number" tag="marathon.requestbin"

Logs are emitted with tag marathon.requestbin.

My FluentD conf:

<match marathon.requestbin*>
    type burrow
    key_name log
    action inplace
    remove_prefix marathon
    format json
</match>

<match requestbin*>
  type stdout
</match>

Here is what the log look like on stdout:

2015-11-25 21:38:11 +0000 marathon.requestbin: {"log":"10.42.122.245 - - [25/Nov/2015 21:38:11] \"GET /delay/2 HTTP/1.1\" 200 -","container_id":"467f6f962940172a8c5a21e2dce3354d23604ed73386975c37a533455989f822","container_name":"/mesos-a84767fb-caaf-46cb-921c-e083f441715a-S1.7e7380da-fb88-4429-b26a-8449ad6edd1b","source":"stderr"}
2015-11-25 21:38:21 +0000 marathon.requestbin: {"log":"10.42.122.245 - - [25/Nov/2015 21:38:21] \"GET /delay/2 HTTP/1.1\" 200 -","container_id":"467f6f962940172a8c5a21e2dce3354d23604ed73386975c37a533455989f822","container_name":"/mesos-a84767fb-caaf-46cb-921c-e083f441715a-S1.7e7380da-fb88-4429-b26a-8449ad6edd1b","source":"stderr"}

Any ideas? Thanks in advance for looking at it.

[kaecyra]

How are these logs being read? From a file?

[scalp42]

From the default forward port localhost:24224 (https://docs.docker.com/engine/reference/logging/fluentd/ if it helps).

[sinkcup]

I also encountered this problem