v9 template parsing issue

[bernd]

There seems to be a problem with template parsing. The first error shows that there is no template for a packet. The second error, 2 seconds later, shows a template parsing issue.

2017-08-08_13:58:03.28568 2017-08-08 13:58:03,285 ERROR: org.graylog.plugins.netflow.codecs.NetFlowCodec - Error parsing NetFlow packet <b78b2476-7c40-11e7-a3ff-005056b6418d> received from <10.1.10.26:54482>
2017-08-08_13:58:03.28569 org.graylog.plugins.netflow.flows.EmptyTemplateException: Unable to parse NetFlow 9 records without template. Discarding packet.
2017-08-08_13:58:03.28569 	at org.graylog.plugins.netflow.v9.NetFlowV9Parser.parsePacket(NetFlowV9Parser.java:56) ~[graylog-plugin-netflow-2.3.0-rc.4.jar:?]
2017-08-08_13:58:03.28569 	at org.graylog.plugins.netflow.flows.NetFlowParser.parse(NetFlowParser.java:63) ~[graylog-plugin-netflow-2.3.0-rc.4.jar:?]
2017-08-08_13:58:03.28569 	at org.graylog.plugins.netflow.codecs.NetFlowCodec.decodeMessages(NetFlowCodec.java:107) [graylog-plugin-netflow-2.3.0-rc.4.jar:?]
2017-08-08_13:58:03.28569 	at org.graylog2.shared.buffers.processors.DecodingProcessor.processMessage(DecodingProcessor.java:144) [graylog.jar:?]
2017-08-08_13:58:03.28570 	at org.graylog2.shared.buffers.processors.DecodingProcessor.onEvent(DecodingProcessor.java:87) [graylog.jar:?]
2017-08-08_13:58:03.28570 	at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:74) [graylog.jar:?]
2017-08-08_13:58:03.28570 	at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:42) [graylog.jar:?]
2017-08-08_13:58:03.28570 	at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) [graylog.jar:?]
2017-08-08_13:58:03.28570 	at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
2017-08-08_13:58:03.28571 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]

2017-08-08_13:58:05.34156 2017-08-08 13:58:05,341 ERROR: org.graylog2.shared.buffers.processors.DecodingProcessor - Unable to decode raw message RawMessage{id=b81c8f00-7c40-11e7-a3ff-005056b6418d, journalOffset=250337669, codec=netflow, payloadSize=492, timestamp=2017-08-08T13:51:46.672Z, remoteAddress=/10.1.9.2:7560} on input <5980f99075010f0b154d87e9>.
2017-08-08_13:58:05.34220 2017-08-08 13:58:05,341 ERROR: org.graylog2.shared.buffers.processors.DecodingProcessor - Error processing message RawMessage{id=b81c8f00-7c40-11e7-a3ff-005056b6418d, journalOffset=250337669, codec=netflow, payloadSize=492, timestamp=2017-08-08T13:51:46.672Z, remoteAddress=/10.1.9.2:7560}
2017-08-08_13:58:05.34221 java.lang.IndexOutOfBoundsException: readerIndex(492) + length(2) exceeds writerIndex(492): UnpooledHeapByteBuf(ridx: 492, widx: 492, cap: 492/492)
2017-08-08_13:58:05.34222 	at io.netty.buffer.AbstractByteBuf.checkReadableBytes0(AbstractByteBuf.java:1395) ~[graylog.jar:?]
2017-08-08_13:58:05.34223 	at io.netty.buffer.AbstractByteBuf.readShort(AbstractByteBuf.java:706) ~[graylog.jar:?]
2017-08-08_13:58:05.34223 	at io.netty.buffer.AbstractByteBuf.readUnsignedShort(AbstractByteBuf.java:722) ~[graylog.jar:?]
2017-08-08_13:58:05.34224 	at org.graylog.plugins.netflow.v9.NetFlowV9Parser.parseTemplates(NetFlowV9Parser.java:122) ~[?:?]
2017-08-08_13:58:05.34224 	at org.graylog.plugins.netflow.v9.NetFlowV9Parser.parsePacket(NetFlowV9Parser.java:45) ~[?:?]
2017-08-08_13:58:05.34224 	at org.graylog.plugins.netflow.flows.NetFlowParser.parse(NetFlowParser.java:63) ~[?:?]
2017-08-08_13:58:05.34224 	at org.graylog.plugins.netflow.codecs.NetFlowCodec.decodeMessages(NetFlowCodec.java:107) ~[?:?]
2017-08-08_13:58:05.34224 	at org.graylog2.shared.buffers.processors.DecodingProcessor.processMessage(DecodingProcessor.java:144) ~[graylog.jar:?]
2017-08-08_13:58:05.34225 	at org.graylog2.shared.buffers.processors.DecodingProcessor.onEvent(DecodingProcessor.java:87) [graylog.jar:?]
2017-08-08_13:58:05.34225 	at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:74) [graylog.jar:?]
2017-08-08_13:58:05.34225 	at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:42) [graylog.jar:?]
2017-08-08_13:58:05.34225 	at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) [graylog.jar:?]
2017-08-08_13:58:05.34225 	at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
2017-08-08_13:58:05.34225 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]

[joschi]

@bernd Would it be possible to get a packet capture (PCAP) of the packets causing this?

[kroepke]

The first just looks like we need to buffer it until we receive the necessary template.

The second one is odd, because it seems like an incomplete message. Not sure how that can happen.

[timmernet]

I seem to run into a similar error:

2017-08-24T09:55:34.413Z ERROR [DecodingProcessor] Unable to decode raw message RawMessage{id=5f64fea0-88b2-11e7-becd-005056a89166, journalOffset=997, codec=netflow, payloadSize=1468, timestamp=2017-08-24T09:55:34.410Z, remoteAddress=/172.16.20.254:15493} on input <599e9ce7a5a4c81d2fe85095>.
2017-08-24T09:55:34.413Z ERROR [DecodingProcessor] Error processing message RawMessage{id=5f64fea0-88b2-11e7-becd-005056a89166, journalOffset=997, codec=netflow, payloadSize=1468, timestamp=2017-08-24T09:55:34.410Z, remoteAddress=/172.16.20.254:15493}
java.lang.NullPointerException: null
at org.graylog.plugins.netflow.flows.NetFlowFormatter.toMessageString(NetFlowFormatter.java:54) ~[?:?]
at org.graylog.plugins.netflow.flows.NetFlowFormatter.toMessage(NetFlowFormatter.java:119) ~[?:?]
at org.graylog.plugins.netflow.flows.NetFlowParser.lambda$parse$2(NetFlowParser.java:66) ~[?:?]
at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193) ~[?:1.8.0_131]
at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175) ~[?:1.8.0_131]
at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948) ~[?:1.8.0_131]
at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) ~[?:1.8.0_131]
at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[?:1.8.0_131]
at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708) ~[?:1.8.0_131]
at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:1.8.0_131]
at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499) ~[?:1.8.0_131]
at org.graylog.plugins.netflow.flows.NetFlowParser.parse(NetFlowParser.java:67) ~[?:?]
at org.graylog.plugins.netflow.codecs.NetFlowCodec.decodeMessages(NetFlowCodec.java:107) ~[?:?]
at org.graylog2.shared.buffers.processors.DecodingProcessor.processMessage(DecodingProcessor.java:144) ~[graylog.jar:?]
at org.graylog2.shared.buffers.processors.DecodingProcessor.onEvent(DecodingProcessor.java:87) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:74) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:42) [graylog.jar:?]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) [graylog.jar:?]
at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]

ciscoasa-netflow.pcap.txt