td-agent Error Log

[sugahara]

Hi,

I set up Netflow v9 settings to EdgeRouterX and exporting flows to td-agent.
When Netflow v5, this plugin process correctly, but td-agent outs following error in Netflow v9.

2018-02-25 23:59:09 +0900 [warn]: #0 unexpected error on parsing data="\"\\x00\\t\\x00\\a\\x00R\\x9AwZ\\x92\\xCF=\\x00\\x00\\x00I\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\\\\\x04\\x01\\x00\\x15\\x00\\x15\\x00\\x04\\x00\\x16\\x00\\x04\\x00\\x01\\x00\\x04\\x00\\x02\\x00\\x04\\x00<\\x00\\x01\\x00\\n\\x00\\x02\\x00\\x0E\\x00\\x02\\x00=\\x00\\x01\\x00\\x03\\x00\\x04\\x00\\b\\x00\\x04\\x00\\f\\x00\\x04\\x00\\a\\x00\\x02\\x00\\v\\x00\\x02\\x00\\x05\\x00\\x01\\x00\\x06\\x00\\x01\\x00\\x04\\x00\\x01\\x008\\x00\\x06\\x00P\\x00\\x06\\x00:\\x00\\x02\\x00\\xC9\\x00\\x04\\x000\\x00\\x01\\x00\\x00\\x00\\\\\\x04\\x02\\x00\\x15\\x00\\x15\\x00\\x04\\x00\\x16\\x00\\x04\\x00\\x01\\x00\\x04\\x00\\x02\\x00\\x04\\x00<\\x00\\x01\\x00\\n\\x00\\x02\\x00\\x0E\\x00\\x02\\x00=\\x00\\x01\\x00\\x03\\x00\\x04\\x00\\b\\x00\\x04\\x00\\f\\x00\\x04\\x00\\a\\x00\\x02\\x00\\v\\x00\\x02\\x00\\x05\\x00\\x01\\x00\\x06\\x00\\x01\\x00\\x04\\x00\\x01\\x00Q\\x00\\x06\\x009\\x00\\x06\\x00;\\x00\\x02\\x00\\xC9\\x00\\x04\\x000\\x00\\x01\\x00\\x00\\x00\\\\\\b\\x01\\x00\\x15\\x00\\x15\\x00\\x04\\x00\\x16\\x00\\x04\\x00\\x01\\x00\\x04\\x00\\x02\\x00\\x04\\x00<\\x00\\x01\\x00\\n\\x00\\x02\\x00\\x0E\\x00\\x02\\x00=\\x00\\x01\\x00\\x03\\x00\\x04\\x00\\e\\x00\\x10\\x00\\x1C\\x00\\x10\\x00\\x05\\x00\\x01\\x00\\a\\x00\\x02\\x00\\v\\x00\\x02\\x00\\x06\\x00\\x01\\x00\\x04\\x00\\x01\\x008\\x00\\x06\\x00P\\x00\\x06\\x00:\\x00\\x02\\x00\\xC9\\x00\\x04\\x000\\x00\\x01\\x00\\x00\\x00\\\\\\b\\x02\\x00\\x15\\x00\\x15\\x00\\x04\\x00\\x16\\x00\\x04\\x00\\x01\\x00\\x04\\x00\\x02\\x00\\x04\\x00<\\x00\\x01\\x00\\n\\x00\\x02\\x00\\x0E\\x00\\x02\\x00=\\x00\\x01\\x00\\x03\\x00\\x04\\x00\\e\\x00\\x10\\x00\\x1C\\x00\\x10\\x00\\x05\\x00\\x01\\x00\\a\\x00\\x02\\x00\\v\\x00\\x02\\x00\\x06\\x00\\x01\\x00\\x04\\x00\\x01\\x00Q\\x00\\x06\\x009\\x00\\x06\\x00;\\x00\\x02\\x00\\xC9\\x00\\x04\\x000\\x00\\x01\\x00\\x01\\x00\\x1A\\x10\\x01\\x00\\x04\\x00\\f\\x00\\x01\\x00\\x04\\x000\\x00\\x01\\x001\\x00\\x01\\x002\\x00\\x04\\x10\\x01\\x00\\x0E\\x00\\x00\\x00\\x00\\x01\\x02\\x00\\x00\\x01,\\x04\\x02\\x00@\\x00\\er%\\x00\\er%\\x00\\x00\\x004\\x00\\x00\\x00\\x01\\x04\\x00\\x00\\x00\\x02\\x01\\x00\\x00\\x00\\x00\\xC0\\xA8\\x00\\x01\\xC0\\xA8\\x00\\x98\\xA4\\xBB\\x99\\xBE\\x00\\x10\\x06\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x02\\x01\"" error_class=ArgumentError error="negative length -4 given"
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/io.rb:115:in `read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/io.rb:115:in `read_raw'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/io.rb:312:in `read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/io.rb:276:in `readbytes'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/string.rb:118:in `read_and_return_value'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/base_primitive.rb:129:in `do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 (eval):2:in `do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/struct.rb:139:in `block in do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/struct.rb:139:in `each'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/struct.rb:139:in `do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/array.rb:310:in `block in do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/array.rb:307:in `loop'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/array.rb:307:in `do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/struct.rb:139:in `block in do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/struct.rb:139:in `each'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/struct.rb:139:in `do_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/base.rb:147:in `block in read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/base.rb:254:in `start_read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/base.rb:145:in `read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/bindata-2.4.2/lib/bindata/base.rb:21:in `read'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-netflow-0.2.8/lib/fluent/plugin/parser_netflow.rb:57:in `call'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-netflow-0.2.8/lib/fluent/plugin/in_netflow.rb:75:in `receive_data'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-netflow-0.2.8/lib/fluent/plugin/in_netflow.rb:111:in `call'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-netflow-0.2.8/lib/fluent/plugin/in_netflow.rb:111:in `on_readable'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.5.1/lib/cool.io/io.rb:186:in `on_readable'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.5.1/lib/cool.io/loop.rb:88:in `run_once'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/cool.io-1.5.1/lib/cool.io/loop.rb:88:in `run'
  2018-02-25 23:59:09 +0900 [warn]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-netflow-0.2.8/lib/fluent/plugin/in_netflow.rb:64:in `run'

[repeatedly]

Hmm... one possible case is exported data is something wrong as v9.
If you know the data format of your v9 log, you can customize the field definition via yaml setting: https://github.com/repeatedly/fluent-plugin-netflow#field-definition-for-netflow-v9

[4hiziri]

I met this error and examined code and netflow v9 packets.
This error raised from Netflow9PDU.read(payload) at parser_netflow.rb.
As a result of my survey, Netflow9PDU failed to parse netflow v9 packet which has specific FlowSet order.
That packet has flowsets Data Templates -> Opiton Template -> flows, but Netflow9PDU failed to parse flows after templates.
Fields of Data Template and Option Template is valid.