search

tagomoris / fluent-plugin-flowcounter

TODO: one-line summary of your gem
Other
53 stars 20 forks source link

<match **.*> with flowcounter causes count undefined method `bytesize' for nil:NilClass" #13

Closed jdoss closed 8 years ago

jdoss commented 8 years ago

Hey there,

I am seeing a weird error when trying to count message keys. This is with fluentd-0.12.19 and fluent-plugin-flowcounter-0.3.1. You can see my current config below. 

 <match **.*>
    @type copy
    <store>
      @type secure_forward
      shared_key secret
      self_hostname dev
      secure no
      buffer_type file
      buffer_path /var/log/td-agent/buffer/buffer
      buffer_chunk_limit 8m
      buffer_queue_limit 4096
      flush_interval 10s
      flush_at_shutdown true
      keepalive 300
      <server>
        host 01
        port 24284
      </server>
      <server>
        host 02
        port 24284
      </server>
      <secondary>
        @type file
        path /var/log/td-agent/failed/forward
        buffer_path /var/log/td-agent/failed/forward.*
      </secondary>
    </store>
    <store>
      @type flowcounter
      count_keys message
      unit second
      aggregate tag
      tag fluentd.traffic.dev
      output_style tagged
    </store>
  </match>
  <match fluentd.traffic.*>
    type stdout
  </match>

Which then produces this stack trace when any event gets processed.

2015-12-30 21:07:24 +0000 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `bytesize' for nil:NilClass" tag="apache.access"
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-flowcounter-0.3.1/lib/fluent/plugin/out_flowcounter.rb:181:in `block (2 levels) in emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-flowcounter-0.3.1/lib/fluent/plugin/out_flowcounter.rb:181:in `each'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-flowcounter-0.3.1/lib/fluent/plugin/out_flowcounter.rb:181:in `inject'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-flowcounter-0.3.1/lib/fluent/plugin/out_flowcounter.rb:181:in `block in emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/event.rb:128:in `call'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/event.rb:128:in `block in each'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/event.rb:127:in `each'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/event.rb:127:in `each'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-flowcounter-0.3.1/lib/fluent/plugin/out_flowcounter.rb:179:in `emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/output.rb:32:in `next'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/buffer.rb:193:in `block in emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/2.1.0/monitor.rb:211:in `mon_synchronize'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/buffer.rb:187:in `emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/output.rb:440:in `emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/output.rb:32:in `next'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/out_copy.rb:74:in `emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/event_router.rb:152:in `emit'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/event_router.rb:88:in `emit_stream'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:245:in `receive_lines'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:337:in `call'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:337:in `wrap_receive_lines'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:529:in `call'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:529:in `on_notify'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:362:in `on_notify'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:463:in `call'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:463:in `on_change'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.4.2/lib/cool.io/loop.rb:88:in `run_once'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.4.2/lib/cool.io/loop.rb:88:in `run'
  2015-12-30 21:07:24 +0000 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.19/lib/fluent/plugin/in_tail.rb:230:in `run'

Oddly enough when you count_keys * it doesn't produce the error in the logs but no flowcounter data is produced to stdout either.

If I use this config without any wildcards in the match:

  <match system.iptables>
    @type copy
    <store>
      @type secure_forward
      shared_key secret
      self_hostname dev
      secure no
      buffer_type file
      buffer_path /var/log/td-agent/buffer/buffer_iptables
      buffer_chunk_limit 8m
      buffer_queue_limit 4096
      flush_interval 10s
      flush_at_shutdown true
      keepalive 300
      <server>
        host 01
        port 24285
      </server>
      <server>
        host 02
        port 24285
      </server>
      <secondary>
        @type file
        path /var/log/td-agent/failed/forward_iptables
        buffer_path /var/log/td-agent/failed/forward_iptables.*
      </secondary>
    </store>
    <store>
      type flowcounter
      count_keys message
      unit second
      output_style tagged
      tag fluentd.traffic.iptables.dev
    </store>
  </match>
  <match fluentd.traffic.iptables.*>
    type stdout
  </match>

It produces flowcounter data to stdout just fine:

2015-12-30 21:19:51 +0000 fluentd.traffic.iptables.dev: {"count":6,"bytes":1374,"count_rate":6.0,"bytes_rate":1374.0,"tag":"system.iptables","instance_hostname":"dev","instance_environment":"development","instance_purpose":"dev"}
2015-12-30 21:19:52 +0000 fluentd.traffic.iptables.dev: {"count":4,"bytes":914,"count_rate":4.0,"bytes_rate":914.0,"tag":"system.iptables","instance_hostname":"dev","instance_environment":"development","instance_purpose":"dev"}
2015-12-30 21:19:53 +0000 fluentd.traffic.iptables.dev: {"count":4,"bytes":914,"count_rate":4.0,"bytes_rate":914.0,"tag":"system.iptables","instance_hostname":"dev","instance_environment":"development","instance_purpose":"dev"}
2015-12-30 21:19:54 +0000 fluentd.traffic.iptables.dev: {"count":4,"bytes":914,"count_rate":4.0,"bytes_rate":914.0,"tag":"system.iptables","instance_hostname":"dev","instance_environment":"development","instance_purpose":"dev"}
tagomoris commented 8 years ago

I suppose that your data with tag system.iptables has a field named message, but data with another tag apache.access doesn't have it. It's a kind of bug, so i'll fix it now.

tagomoris commented 8 years ago

I released v0.3.2. It should work well with missing fields. @jdoss please open another issue for count_keys * if you still have troubles.