Error: "undefined method `+' for nil:NilClass" in plugin/output.rb #1161

bungoume · 2016-08-15T03:38:44Z

I got this error in fluentd 0.14.

20:29:12 fluentd.1   | 2016-08-14 20:29:12 +0000 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `+' for nil:NilClass" tag="store.access.uwsgi.api-gateway-dev"
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/output.rb:862:in `submit_flush_once'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/output.rb:533:in `emit_buffered'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/output.rb:511:in `emit_events'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/out_copy.rb:38:in `block in process'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/out_copy.rb:37:in `each'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/out_copy.rb:37:in `process'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/multi_output.rb:85:in `emit_sync'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluent-plugin-forest-0.3.1/lib/fluent/plugin/out_forest.rb:172:in `emit'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/compat/output.rb:194:in `process'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/bare_output.rb:53:in `emit_sync'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event_router.rb:90:in `emit_stream'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event_router.rb:81:in `emit'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluent-plugin-rewrite-tag-filter-1.5.5/lib/fluent/plugin/out_rewrite_tag_filter.rb:75:in `block in emit'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event.rb:186:in `block in each'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event.rb:185:in `each'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event.rb:185:in `each'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluent-plugin-rewrite-tag-filter-1.5.5/lib/fluent/plugin/out_rewrite_tag_filter.rb:72:in `emit'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/compat/output.rb:157:in `process'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/output.rb:520:in `emit_sync'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event_router.rb:154:in `emit_events'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/event_router.rb:90:in `emit_stream'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:176:in `on_message'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:296:in `call'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:296:in `block in on_read_msgpack'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:295:in `feed_each'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:295:in `on_read_msgpack'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:281:in `call'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:281:in `on_read'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/cool.io-1.4.4/lib/cool.io/io.rb:123:in `on_readable'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/cool.io-1.4.4/lib/cool.io/io.rb:186:in `on_readable'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/cool.io-1.4.4/lib/cool.io/loop.rb:88:in `run_once'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/cool.io-1.4.4/lib/cool.io/loop.rb:88:in `run'
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: /usr/local/bundle/gems/fluentd-0.14.2/lib/fluent/plugin/in_forward.rb:117:in `run'
20:29:12 fluentd.1   | 2016-08-14 20:29:12 +0000 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `+' for nil:NilClass" tag="access.uwsgi"
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: suppressed same stacktrace
20:29:12 fluentd.1   | 2016-08-14 20:29:12 +0000 [error]: forward error error=#<NoMethodError: undefined method `+' for nil:NilClass> error_class=NoMethodError
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [error]: suppressed same stacktrace
20:29:12 fluentd.1   | 2016-08-14 20:29:12 +0000 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `+' for nil:NilClass" tag="store.access.uwsgi.api-gateway-dev"
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: suppressed same stacktrace
20:29:12 fluentd.1   | 2016-08-14 20:29:12 +0000 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `+' for nil:NilClass" tag="access.uwsgi"
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [warn]: suppressed same stacktrace
20:29:12 fluentd.1   | 2016-08-14 20:29:12 +0000 [error]: forward error error=#<NoMethodError: undefined method `+' for nil:NilClass> error_class=NoMethodError
20:29:12 fluentd.1   |   2016-08-14 20:29:12 +0000 [error]: suppressed same stacktrace
20:29:14 fluentd.1   | 2016-08-14 20:29:14 +0000 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `+' for nil:NilClass" tag="store.access.uwsgi.api-gateway-dev"
20:29:14 fluentd.1   |   2016-08-14 20:29:14 +0000 [warn]: suppressed same stacktrace

This error did not occur in Fluentd 0.12.26.

Config

configuration is like this.

<source>
  @type forward
  port 24224
  bind 0.0.0.0
</source>

<match access.**>
  @type rewrite_tag_filter
  rewriterule1 app_name ^(.+)$ store.${tag}.$1
</match>

<match store.access.**>
  @type forest
  subtype copy
  <template>
    <store>
      @type s3
      ...
    </store>
    <store>
      @type elasticsearch
      ...
    </store>
  </template>
</match>

environment

Running in Docker container.

FROM ruby:2.3

RUN gem install foreman oj && \
    gem install fluentd -v 0.14.2 && \
    gem install fluent-plugin-ua-parser fluent-plugin-geoip-filter fluent-plugin-ignore-filter \
                fluent-plugin-forest fluent-plugin-s3 fluent-plugin-elasticsearch fluent-plugin-rewrite-tag-filter \
                fluent-plugin-sentry fluent-plugin-parser fluent-plugin-record-reformer && \
    gem install fluent-plugin-bigquery -v 0.2.16

root@a93c9fd549b6:/app# ruby -v
ruby 2.3.1p112 (2016-04-26 revision 54768) [x86_64-linux]
root@a93c9fd549b6:/app# gem list

*** LOCAL GEMS ***

activesupport (5.0.0.1)
addressable (2.4.0)
aws-sdk (2.5.3)
aws-sdk-core (2.5.3)
aws-sdk-resources (2.5.3)
bigdecimal (default: 1.2.8)
bundler (1.12.5)
concurrent-ruby (1.0.2)
cool.io (1.4.4)
did_you_mean (1.0.0)
elasticsearch (2.0.0)
elasticsearch-api (2.0.0)
elasticsearch-transport (2.0.0)
excon (0.51.0)
faraday (0.9.2)
fluent-mixin-config-placeholders (0.4.0)
fluent-mixin-plaintextformatter (0.2.6)
fluent-plugin-bigquery (0.2.16)
fluent-plugin-buffer-lightening (0.0.2)
fluent-plugin-elasticsearch (1.5.0)
fluent-plugin-forest (0.3.1)
fluent-plugin-geoip-filter (0.3.0)
fluent-plugin-ignore-filter (1.1.0)
fluent-plugin-parser (0.6.1)
fluent-plugin-record-reformer (0.8.1)
fluent-plugin-rewrite-tag-filter (1.5.5)
fluent-plugin-s3 (0.7.0)
fluent-plugin-sentry (0.0.5)
fluent-plugin-ua-parser (1.1.0)
fluentd (0.14.2, 0.12.27)
foreman (0.82.0)
geoip (1.6.2)
google-api-client (0.9.11)
googleauth (0.5.1)
http_parser.rb (0.6.0)
httpclient (2.8.1)
hurley (0.2)
i18n (0.7.0)
io-console (default: 0.4.5)
jmespath (1.3.1)
json (default: 1.8.3)
jwt (1.5.4)
little-plugger (1.1.4)
logging (2.1.0)
lru_redux (1.1.0)
ltsv (0.1.0)
memoist (0.14.0)
mime-types (3.1)
mime-types-data (3.2016.0521)
minitest (5.8.3)
msgpack (1.0.0, 0.5.12)
multi_json (1.12.1)
multipart-post (2.0.0)
net-telnet (0.1.1)
oj (2.17.1)
os (0.9.6)
power_assert (0.2.6)
psych (default: 2.0.17)
rake (10.4.2)
rdoc (default: 4.2.1)
representable (2.3.0)
retriable (2.1.0)
rubygems-update (2.6.6)
sentry-raven (0.15.6)
serverengine (1.6.4)
sigdump (0.2.4)
signet (0.7.3)
string-scrub (0.0.5)
strptime (0.1.8)
test-unit (3.1.5)
thor (0.19.1)
thread_safe (0.3.5)
tzinfo (1.2.2)
tzinfo-data (1.2016.6)
uber (0.0.15)
user_agent_parser (2.3.0)
uuidtools (2.1.5)
yajl-ruby (1.2.1)

The text was updated successfully, but these errors were encountered:

tagomoris · 2016-08-15T04:46:00Z

Oh, I found a bug that MultiOutput (base class of out_copy) doesn't call #start of @outputs.

tagomoris · 2016-08-15T05:52:46Z

This bug is caused by the combination of these reasons:

plugins' lifecycle methods will be called from RootAgent
RootAgent calls lifecycle methods of instances in lifecycle_control_list
MultiOutput instantiates and configures output plugins for <store> sections, but doesn't set its @outputs content into one of RootAgent

tagomoris · 2016-09-26T08:19:48Z

I found that the case below still has problem that doesn't call lifecycle methods correctly (e.g., #start, #shutdown).
It's caused from the combination of things below:

out_copy in v0.14 delegates calling methods of plugins to RootAgent
RootAgent expects that all sub-plugins must be created in #configure
fluent-plugin-forest generates instances of plugins dynamically, and calls lifecycle methods by itself

When out_forest calls lifecycle methods of out_copy (generated after #start), out_copy doesn't nothing because it expects RootAgent does it. But RootAgent cannot find sub-sub-plugin instances with this configuration...

tagomoris · 2016-09-26T08:30:21Z

For the case of @bungoume, the solution is to use copy plugin first, and then use forest plugin in <store> sections.

tagomoris · 2016-09-28T09:15:10Z

#1242 merged.

tagomoris added bug Something isn't working v0.14 labels Aug 15, 2016

tagomoris mentioned this issue Aug 18, 2016

Fix to add plugin instances created by MultiOutput plugins, into agents #1167

Merged

tagomoris closed this as completed in #1167 Aug 22, 2016

tagomoris reopened this Sep 26, 2016

tagomoris mentioned this issue Sep 26, 2016

Lifecycle method called correctly once #1242

Merged

tagomoris closed this as completed Sep 28, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Error: "undefined method `+' for nil:NilClass" in plugin/output.rb #1161

Error: "undefined method `+' for nil:NilClass" in plugin/output.rb #1161

bungoume commented Aug 15, 2016

tagomoris commented Aug 15, 2016

tagomoris commented Aug 15, 2016

tagomoris commented Sep 26, 2016

tagomoris commented Sep 26, 2016

tagomoris commented Sep 28, 2016

Error: "undefined method `+' for nil:NilClass" in plugin/output.rb #1161

Error: "undefined method `+' for nil:NilClass" in plugin/output.rb #1161

Comments

bungoume commented Aug 15, 2016

Config

environment

tagomoris commented Aug 15, 2016

tagomoris commented Aug 15, 2016

tagomoris commented Sep 26, 2016

tagomoris commented Sep 26, 2016

tagomoris commented Sep 28, 2016