robcowart / elastiflow

Network flow analytics (Netflow, sFlow and IPFIX) with the Elastic Stack
Other
2.49k stars 595 forks source link

Cant decode IPFIX flow from Mictotik #445

Closed Alex-0293 closed 4 years ago

Alex-0293 commented 5 years ago

ELK v 7.4.2 Elastiflow v 3.5.1

Good day! I have trouble with my flow decode. Can't (yet) decode flowset id 258 from observation domain id 0

Device, flow generator: Microtik RB760iGS PCAP inside. Thank you, for your support!

robcowart commented 5 years ago

@Alex-0293 did you intend to attach a PCAP?

redpeppers-01 commented 4 years ago

@robcowart i am also seeing this issue using a mikrotik. This is my first jab at installing and configuring elastiflow. I have now had the mikrotik router sending data for about 10 mins. Logstash log shows....

[2019-11-27T01:33:02,438][ERROR][logstash.inputs.udp ][elastiflow] Exception in inputworker {"exception"=>java.lang.NullPointerException, "backtrace"=>["org.jruby.runtime.invokedynamic.InvokeDynamicSupport.callMethodMissing(InvokeDynamicSupport.java:86)", "org.jruby.runtime.invokedynamic.MathLinker.callMethod(MathLinker.java:418)", "org.jruby.runtime.invokedynamic.MathLinker.fixnumOperatorFail(MathLinker.java:209)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$method$uint_field$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:391)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$method$ipfix_field_for$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:520)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$block$decode_ipfix$3(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:299)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.ir.runtime.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:477)", "org.jruby.ir.targets.YieldSite.yield(YieldSite.java:105)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$block$each$1(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb:208)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.RubyArray.each(RubyArray.java:1800)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$method$each$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb:208)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$method$each$0$VARARGS(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:91)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:90)", "org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:223)", "org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:230)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$block$decode_ipfix$2(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:294)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.exceptions.CatchThrow.enter(CatchThrow.java:32)", "org.jruby.RubyKernel.rbCatch19Common(RubyKernel.java:1197)", "org.jruby.RubyKernel.rbCatch19(RubyKernel.java:1193)", "org.jruby.RubyKernel$INVOKER$s$rbCatch19.call(RubyKernel$INVOKER$s$rbCatch19.gen)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$block$decode_ipfix$1(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:290)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.ir.runtime.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:477)", "org.jruby.ir.targets.YieldSite.yield(YieldSite.java:105)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$block$each$1(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb:208)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.RubyArray.each(RubyArray.java:1800)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$method$each$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb:208)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$method$each$0$VARARGS(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:91)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:90)", "org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:223)", "org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:230)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$method$decode_ipfix$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:289)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$block$decode$5(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:105)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.ir.runtime.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:477)", "org.jruby.ir.targets.YieldSite.yield(YieldSite.java:105)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$block$each$1(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb:208)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:170)", "org.jruby.RubyArray.each(RubyArray.java:1800)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$method$each$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb:208)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.bindata_minus_2_dot_4_dot_4.lib.bindata.array.RUBY$method$each$0$VARARGS(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/bindata-2.4.4/lib/bindata/array.rb)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:91)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:90)", "org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:223)", "org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:230)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_codec_minus_netflow_minus_4_dot_2_dot_1.lib.logstash.codecs.netflow.RUBY$method$decode$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-codec-netflow-4.2.1/lib/logstash/codecs/netflow.rb:104)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_input_minus_udp_minus_3_dot_3_dot_4.lib.logstash.inputs.udp.RUBY$method$inputworker$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-udp-3.3.4/lib/logstash/inputs/udp.rb:151)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_input_minus_udp_minus_3_dot_3_dot_4.lib.logstash.inputs.udp.RUBY$method$inputworker$0$VARARGS(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-udp-3.3.4/lib/logstash/inputs/udp.rb)", "org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:91)", "org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:90)", "org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:183)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_input_minus_udp_minus_3_dot_3_dot_4.lib.logstash.inputs.udp.RUBY$block$run$2(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-udp-3.3.4/lib/logstash/inputs/udp.rb:63)", "org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:136)", "org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:77)", "org.jruby.runtime.Block.call(Block.java:129)", "org.jruby.RubyProc.call(RubyProc.java:295)", "org.jruby.RubyProc.call(RubyProc.java:274)", "org.jruby.RubyProc.call(RubyProc.java:270)", "org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105)", "java.lang.Thread.run(Thread.java:748)"]} [2019-11-27T01:33:02,483][WARN ][logstash.codecs.netflow ][elastiflow] Can't (yet) decode flowset id 258 from observation domain id 0, because no template to decode it with has been received. This message will usually go away after 1 minute. [2019-11-27T01:33:02,483][WARN ][logstash.codecs.netflow ][elastiflow] Can't (yet) decode flowset id 258 from observation domain id 0, because no template to decode it with has been received. This message will usually go away after 1 minute.

robcowart commented 4 years ago

Could you provide a PCAP of the flies so that I can test it?

redpeppers-01 commented 4 years ago

@robcowart , is there a way to send the pcap file directly to you instead of posting it publicly?

robcowart commented 4 years ago

Yes. Please send it to elastiflow@gmail.com

redpeppers-01 commented 4 years ago

Yes. Please send it to elastiflow@gmail.com

sent...

robcowart commented 4 years ago

@redpeppers-01 I have no problem decoding the flow records you are receiving using the field definitions that are part of ElastiFlow. Here is an example (IPs and MACs modified)...

{
         "ipfix" => {
                        "ingressInterface" => 33,
                              "flowset_id" => 258,
                    "postSourceMacAddress" => "a4:b1:c4:d8:e7:fe",
                         "octetDeltaCount" => 185,
                     "sourceTransportPort" => 49423,
                      "protocolIdentifier" => 6,
                  "sourceIPv4PrefixLength" => 0,
             "destinationIPv4PrefixLength" => 0,
                             "isMulticast" => 0,
                "tcpAcknowledgementNumber" => 2530510257,
                            "icmpTypeIPv4" => 0,
                      "flowStartSysUpTime" => 868307224,
                                   "ipTTL" => 124,
                            "icmpCodeIPv4" => 0,
                "destinationTransportPort" => 443,
                                "igmpType" => 0,
                  "destinationIPv4Address" => "111.177.222.224",
                               "ipVersion" => 4,
                           "ipTotalLength" => 145,
                "postNATSourceIPv4Address" => "111.86.222.22",
                        "flowEndSysUpTime" => 868307224,
                        "sourceMacAddress" => "a8:b9:c4:dd:e5:f0",
                   "destinationMacAddress" => "a4:b1:c4:d8:e7:f0",
                       "sourceIPv4Address" => "111.18.222.254",
                          "ipHeaderLength" => 5,
                        "ipClassOfService" => 0,
           "postNATDestinationIPv4Address" => "111.177.222.224",
                        "packetDeltaCount" => 2,
        "postNAPTDestinationTransportPort" => 443,
                         "egressInterface" => 26,
             "postNAPTSourceTransportPort" => 49423,
                    "ipNextHopIPv4Address" => "111.86.222.21",
                           "tcpWindowSize" => 258,
                          "tcpControlBits" => 24,
                       "tcpSequenceNumber" => 2785517459,
                        "udpMessageLength" => 0,
                                 "version" => 10
    },
      "@version" => "1",
    "@timestamp" => 2019-11-27T16:34:28.000Z,
          "host" => "127.0.0.1"
}

Additionally IPFIX template packets are sent after exactly every 20 flow packets. Which is definitely enough that you should very quickly receive a template.

The only thing I can thing might be an issue would be if you are dropping UDP packets, and simply missing the template packets.

The flow record packets contain 14 flows each, and you are receiving ~101/sec, which is ~1400 flows/sec. If Logstash does not have the resources to keep up with this rate of flows, you WILL drop packets. If you are using default Linux network parameters, I can almost guarantee this to be the case.

Try running netstat -su. You will get an output like this...

IcmpMsg:
    InType3: 37
    OutType3: 7
Udp:
    597 packets received
    0 packets to unknown port received
    0 packet receive errors
    608 packets sent
    0 receive buffer errors
    0 send buffer errors
UdpLite:
IpExt:
    InOctets: 3346796334
    OutOctets: 1586209167
    InNoECTPkts: 39163736

What you are interested in is receive buffer errors (this might also be called RcvbufErrors) under Udp:. If you run that command a few times and you see this value increasing significantly, you are dropping packets.

To alleviate this issue, run the following commands to increase important kernel networking parameters:

sudo sysctl -w net.core.somaxconn=2048
sudo sysctl -w net.core.netdev_max_backlog=8192
sudo sysctl -w net.core.rmem_max=33554432
sudo sysctl -w net.core.rmem_default=262144
sudo sysctl -w net.ipv4.udp_rmem_min=131072
sudo sysctl -w net.ipv4.udp_mem="2097152 4194304 8388608"

To make this a permanent change, add a file to /etc/sysctl.d which contains the following...

net.core.somaxconn=2048
net.core.netdev_max_backlog=8192
net.core.rmem_max=33554432
net.core.rmem_default=262144
net.ipv4.udp_rmem_min=131072
net.ipv4.udp_mem="2097152 4194304 8388608"

Also increase the priority of the Logstash process. By default it has a Nice value of 19, the lowest priority. Increase this to 0 by editing /etc/systemd/system/logstash.service, and change Nice=19 to Nice=0. You will then need to restart Logstash.

redpeppers-01 commented 4 years ago

Thanks, these settings did the trick!

From: Rob Cowart notifications@github.com Sent: Wednesday, November 27, 2019 12:43 PM To: robcowart/elastiflow elastiflow@noreply.github.com Cc: redpeppers-01 shawn.c.peppers@gmail.com; Mention mention@noreply.github.com Subject: Re: [robcowart/elastiflow] Cant decode IPFIX flow from Mictotik (#445)

@redpeppers-01 https://github.com/redpeppers-01 I have no problem decoding the flow records you are receiving using the field definitions that are part of ElastiFlow. Here is an example (IPs and MACs modified)...

{ "ipfix" => { "ingressInterface" => 33, "flowset_id" => 258, "postSourceMacAddress" => "a4:b1:c4:d8:e7:fe", "octetDeltaCount" => 185, "sourceTransportPort" => 49423, "protocolIdentifier" => 6, "sourceIPv4PrefixLength" => 0, "destinationIPv4PrefixLength" => 0, "isMulticast" => 0, "tcpAcknowledgementNumber" => 2530510257, "icmpTypeIPv4" => 0, "flowStartSysUpTime" => 868307224, "ipTTL" => 124, "icmpCodeIPv4" => 0, "destinationTransportPort" => 443, "igmpType" => 0, "destinationIPv4Address" => "111.177.222.224", "ipVersion" => 4, "ipTotalLength" => 145, "postNATSourceIPv4Address" => "111.86.222.22", "flowEndSysUpTime" => 868307224, "sourceMacAddress" => "a8:b9:c4:dd:e5:f0", "destinationMacAddress" => "a4:b1:c4:d8:e7:f0", "sourceIPv4Address" => "111.18.222.254", "ipHeaderLength" => 5, "ipClassOfService" => 0, "postNATDestinationIPv4Address" => "111.177.222.224", "packetDeltaCount" => 2, "postNAPTDestinationTransportPort" => 443, "egressInterface" => 26, "postNAPTSourceTransportPort" => 49423, "ipNextHopIPv4Address" => "111.86.222.21", "tcpWindowSize" => 258, "tcpControlBits" => 24, "tcpSequenceNumber" => 2785517459, "udpMessageLength" => 0, "version" => 10 }, "@version" => "1", "@timestamp" => 2019-11-27T16:34:28.000Z, "host" => "127.0.0.1" }

Additionally IPFIX template packets are sent after exactly every 20 flow packets. Which is definitely enough that you should very quickly receive a template.

The only thing I can thing might be an issue would be if you are dropping UDP packets, and simply missing the template packets.

The flow record packets contain 14 flows each, and you are receiving ~101/sec, which is ~1400 flows/sec. If Logstash does not have the resources to keep up with this rate of flows, you WILL drop packets. If you are using default Linux network parameters, I can almost guarantee this to be the case.

Try running netstat -su. You will get an output like this...

IcmpMsg: InType3: 37 OutType3: 7 Udp: 597 packets received 0 packets to unknown port received 0 packet receive errors 608 packets sent 0 receive buffer errors 0 send buffer errors UdpLite: IpExt: InOctets: 3346796334 OutOctets: 1586209167 InNoECTPkts: 39163736

What you are interested in is receive buffer errors (this might also be called RcvbufErrors) under Udp:. If you run that command a few times and you see this value increasing significantly, you are dropping packets.

To alleviate this issue, run the following commands to increase important kernel networking parameters:

sudo sysctl -w net.core.somaxconn=2048 sudo sysctl -w net.core.netdev_max_backlog=8192 sudo sysctl -w net.core.rmem_max=33554432 sudo sysctl -w net.core.rmem_default=262144 sudo sysctl -w net.ipv4.udp_rmem_min=131072 sudo sysctl -w net.ipv4.udp_mem="2097152 4194304 8388608"

To make this a permanent change, add a file to /etc/sysctl.d which contains the following...

net.core.somaxconn=2048 net.core.netdev_max_backlog=8192 net.core.rmem_max=33554432 net.core.rmem_default=262144 net.ipv4.udp_rmem_min=131072 net.ipv4.udp_mem="2097152 4194304 8388608"

Also increase the priority of the Logstash process. By default it has a Nice value of 19, the lowest priority. Increase this to 0 by editing /etc/systemd/system/logstash.service, and change Nice=19 to Nice=0. You will then need to restart Logstash.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/robcowart/elastiflow/issues/445?email_source=notifications&email_token=AMMJNVQVRMBL5ERFKYBSB23QV25VBA5CNFSM4JHSMZJ2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEFKNMPI#issuecomment-559207997 , or unsubscribe https://github.com/notifications/unsubscribe-auth/AMMJNVWCQ5H527VIKYLCWVTQV25VBANCNFSM4JHSMZJQ .

robcowart commented 4 years ago

Great! I need to update the install guide and stress that these changes should be made on all installations.