Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error processing IPFIX messages using telegraf [[inputs.netflow]] #13305

Closed
vknyazhev opened this issue May 22, 2023 · 11 comments · Fixed by #13320
Closed

Error processing IPFIX messages using telegraf [[inputs.netflow]] #13305

vknyazhev opened this issue May 22, 2023 · 11 comments · Fixed by #13320
Labels
bug unexpected problem or unintended behavior

Comments

@vknyazhev
Copy link

vknyazhev commented May 22, 2023

Relevant telegraf.conf

# Netflow v5, Netflow v9 and IPFIX collector
[[inputs.netflow]]
  ## Address to listen for netflow/ipfix packets.
  ##   example: service_address = "udp://:2055"
  ##            service_address = "udp4://:2055"
  ##            service_address = "udp6://:2055"
  service_address = "udp://:2055"

  ## Set the size of the operating system's receive buffer.
  ##   example: read_buffer_size = "64KiB"
  ## Uses the system's default if not set.
  # read_buffer_size = "64KiB"

  ## Protocol version to use for decoding.
  ## Available options are
  ##   "netflow v5" -- Netflow v5 protocol
  ##   "netflow v9" -- Netflow v9 protocol (also works for IPFIX)
  ##   "ipfix"      -- IPFIX / Netflow v10 protocol (also works for Netflow v9)
   protocol = "ipfix"

  ## Dump incoming packets to the log
  ## This can be helpful to debug parsing issues. Only active if
  ## Telegraf is in debug mode.
  # dump_packets = false

 [[outputs.influxdb]]
urls = ["http://localhost:8086"]

[agent]  
  ## ...
  debug = true
  quiet = false
  logtarget = "file"
  logfile = "/var/log/telegraf/telegraf.log"

Logs from Telegraf

2023-05-22T16:05:11Z I! Starting Telegraf 1.26.2
2023-05-22T16:05:11Z I! Available plugins: 235 inputs, 9 aggregators, 27 processors, 22 parsers, 57 outputs, 2 secret-stores
2023-05-22T16:05:11Z I! Loaded inputs: cpu disk diskio kernel mem netflow processes swap system
2023-05-22T16:05:11Z I! Loaded aggregators: 
2023-05-22T16:05:11Z I! Loaded processors: 
2023-05-22T16:05:11Z I! Loaded secretstores: 
2023-05-22T16:05:11Z I! Loaded outputs: influxdb
2023-05-22T16:05:11Z I! Tags enabled: host=home
2023-05-22T16:05:11Z I! [agent] Config: Interval:10s, Quiet:false, Hostname:"home", Flush Interval:10s
2023-05-22T16:05:11Z D! [agent] Initializing plugins
2023-05-22T16:05:11Z D! [agent] Connecting outputs
2023-05-22T16:05:11Z D! [agent] Attempting connection to [outputs.influxdb]
2023-05-22T16:05:11Z D! [agent] Successfully connected to outputs.influxdb
2023-05-22T16:05:11Z D! [agent] Starting service inputs
2023-05-22T16:05:11Z I! [inputs.netflow] Listening on udp://[::]:2055
2023-05-22T16:05:21Z D! [outputs.influxdb] Wrote batch of 13 metrics in 3.864526ms
2023-05-22T16:05:21Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:05:27Z D! [inputs.netflow] received 308 bytes
2023-05-22T16:05:27Z E! [inputs.netflow] Error in plugin: No info template 261 found for and domain id 231
2023-05-22T16:05:27Z D! [inputs.netflow] received 304 bytes
2023-05-22T16:05:27Z E! [inputs.netflow] Error in plugin: No info template 261 found for and domain id 231
2023-05-22T16:05:27Z D! [inputs.netflow] received 308 bytes
2023-05-22T16:05:27Z E! [inputs.netflow] Error in plugin: No info template 261 found for and domain id 231
2023-05-22T16:05:28Z D! [inputs.netflow] received 272 bytes
2023-05-22T16:05:28Z E! [inputs.netflow] Error in plugin: No info template 261 found for and domain id 231
2023-05-22T16:05:28Z D! [inputs.netflow] received 980 bytes
2023-05-22T16:05:28Z D! [inputs.netflow] received 588 bytes
2023-05-22T16:05:28Z D! [inputs.netflow] received 240 bytes
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {false 151 0 [100 107 146 215]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 123 35632 [0 0 0 0]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 124 35632 [0 0 0 0]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 125 35632 [0 0 0 31]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 127 35632 [0 0 0 0]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 109 35632 [0 0 0 0]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 110 35632 [0 0 0 0]}
2023-05-22T16:05:28Z D! [inputs.netflow] unknown data field {true 118 35632 [0 196]}
2023-05-22T16:05:28Z I! Starting Telegraf 1.26.2
2023-05-22T16:05:28Z I! Available plugins: 235 inputs, 9 aggregators, 27 processors, 22 parsers, 57 outputs, 2 secret-stores
2023-05-22T16:05:28Z I! Loaded inputs: cpu disk diskio kernel mem netflow processes swap system
2023-05-22T16:05:28Z I! Loaded aggregators: 
2023-05-22T16:05:28Z I! Loaded processors: 
2023-05-22T16:05:28Z I! Loaded secretstores: 
2023-05-22T16:05:28Z I! Loaded outputs: influxdb
2023-05-22T16:05:28Z I! Tags enabled: host=home
2023-05-22T16:05:28Z I! [agent] Config: Interval:10s, Quiet:false, Hostname:"home", Flush Interval:10s
2023-05-22T16:05:28Z D! [agent] Initializing plugins
2023-05-22T16:05:28Z D! [agent] Connecting outputs
2023-05-22T16:05:28Z D! [agent] Attempting connection to [outputs.influxdb]
2023-05-22T16:05:28Z D! [agent] Successfully connected to outputs.influxdb
2023-05-22T16:05:28Z D! [agent] Starting service inputs
2023-05-22T16:05:28Z I! [inputs.netflow] Listening on udp://[::]:2055
2023-05-22T16:05:38Z D! [outputs.influxdb] Wrote batch of 13 metrics in 4.481734ms
2023-05-22T16:05:38Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:05:48Z D! [outputs.influxdb] Wrote batch of 18 metrics in 8.401294ms
2023-05-22T16:05:48Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:05:58Z D! [outputs.influxdb] Wrote batch of 18 metrics in 9.703192ms
2023-05-22T16:05:58Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:06:06Z D! [inputs.netflow] received 264 bytes
2023-05-22T16:06:06Z E! [inputs.netflow] Error in plugin: No info template 261 found for and domain id 231
2023-05-22T16:06:08Z D! [outputs.influxdb] Wrote batch of 18 metrics in 5.965499ms
2023-05-22T16:06:08Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:06:18Z D! [outputs.influxdb] Wrote batch of 18 metrics in 6.475799ms
2023-05-22T16:06:18Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:06:27Z D! [inputs.netflow] received 152 bytes
2023-05-22T16:06:27Z E! [inputs.netflow] Error in plugin: No info template 257 found for and domain id 231
2023-05-22T16:06:28Z D! [outputs.influxdb] Wrote batch of 18 metrics in 5.801752ms
2023-05-22T16:06:28Z D! [outputs.influxdb] Buffer fullness: 0 / 10000 metrics
2023-05-22T16:06:37Z D! [inputs.netflow] received 224 bytes
2023-05-22T16:06:37Z E! [inputs.netflow] Error in plugin: No info template 259 found for and domain id 231
2023-05-22T16:06:37Z D! [inputs.netflow] received 176 bytes
2023-05-22T16:06:37Z E! [inputs.netflow] Error in plugin: No info template 259 found for and domain id 231
2023-05-22T16:06:37Z D! [inputs.netflow] received 272 bytes
2023-05-22T16:06:37Z E! [inputs.netflow] Error in plugin: No info template 261 found for and domain id 231
2023-05-22T16:06:37Z D! [inputs.netflow] received 228 bytes
2023-05-22T16:06:37Z E! [inputs.netflow] Error in plugin: No info template 259 found for and domain id 231
2023-05-22T16:06:37Z D! [inputs.netflow] received 188 bytes
2023-05-22T16:06:37Z E! [inputs.netflow] Error in plugin: No info template 259 found for and domain id 231
2023-05-22T16:06:38Z D! [inputs.netflow] received 980 bytes
2023-05-22T16:06:38Z D! [inputs.netflow] received 588 bytes
2023-05-22T16:06:38Z D! [inputs.netflow] received 244 bytes
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {false 151 0 [100 107 146 238]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 123 35632 [0 0 0 0]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 124 35632 [0 0 0 0]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 125 35632 [0 0 0 19]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 127 35632 [0 0 0 0]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 109 35632 [0 0 0 0]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 110 35632 [0 0 0 0]}
2023-05-22T16:06:38Z D! [inputs.netflow] unknown data field {true 118 35632 [0 126]}
2023-05-22T16:06:38Z I! Starting Telegraf 1.26.2

System info

Telegraf 1.26.2, Ubuntu 18.04.6 LTS

Docker

No response

Steps to reproduce

  1. Created a configuration file /etc/telegraf/telegraf.d/ipfix_cgs.conf with plugin [[inputs.netflow]]
  2. Restarted telegraf, error logs
  3. ipfix stream arrives at the server, but as a result, data is not written from telegraf to influxdb
    ...

Expected behavior

The fields of recipients, senders, ip-addresses, etc. will appear, everything that is transmitted to the collector

Actual behavior

The logs show that an error occurs: E! [inputs.netflow] Error in plugin: No info template 259 found for and domain id 231

and after that telegraf is restarted, the data is not written to influxdb

Additional info

No response

@vknyazhev vknyazhev added the bug unexpected problem or unintended behavior label May 22, 2023
@vknyazhev
Copy link
Author

ipfix.pcap.txt

@srebhan
Copy link
Member

srebhan commented May 23, 2023

@vknyazhev can I use your captured packets to create unit-tests and add them to the repository, i.e. make them public?

@vknyazhev
Copy link
Author

@srebhan Yes, sure.

srebhan added a commit to srebhan/telegraf that referenced this issue May 23, 2023
@srebhan
Copy link
Member

srebhan commented May 23, 2023

@vknyazhev can you please test the binary built in #13320 once CI finished the tests?! Let me know if it fixes your issue!

@vknyazhev
Copy link
Author

изображение
@srebhan I don't understand a bit, do I need to run some file (what?) on the host on which telegraf is running?

@vknyazhev
Copy link
Author

May 23 14:43:05 home systemd[1]: Starting Telegraf...
May 23 14:43:05 home telegraf[27538]: 2023-05-23T14:43:05Z I! Loading config: /etc/telegraf/telegraf.conf
May 23 14:43:05 home telegraf[27538]: 2023-05-23T14:43:05Z I! Loading config: /etc/telegraf/telegraf.d/ipfix_cgs.conf
May 23 14:43:05 home systemd[1]: Started Telegraf.
May 23 14:43:11 home telegraf[27538]: panic: invalid length for uint buffer []
May 23 14:43:11 home telegraf[27538]: goroutine 49 [running]:
May 23 14:43:11 home telegraf[27538]: github.com/influxdata/telegraf/plugins/inputs/netflow.decodeUint({0xc000ea008e?, 0xc00023fbc0?, 0x4?})
May 23 14:43:11 home telegraf[27538]: /go/src/github.com/influxdata/telegraf/plugins/inputs/netflow/type_conversion.go:101 +0x10e
May 23 14:43:11 home telegraf[27538]: github.com/influxdata/telegraf/plugins/inputs/netflow.(*netflowDecoder).decodeValueIPFIX(0xc0009ee510, {0x1, 0xbc, 0x8b30, {0x55938c0, 0xc000673ba8}})
May 23 14:43:11 home telegraf[27538]: /go/src/github.com/influxdata/telegraf/plugins/inputs/netflow/netflow_decoder.go:687 +0x6ad
May 23 14:43:11 home telegraf[27538]: github.com/influxdata/telegraf/plugins/inputs/netflow.(*netflowDecoder).Decode(0xc0009ee510, {0xc001409be0, 0x10, 0x10}, {0xc000ea0000, 0xc0, 0x10000})
May 23 14:43:11 home telegraf[27538]: /go/src/github.com/influxdata/telegraf/plugins/inputs/netflow/netflow_decoder.go:597 +0xd85
May 23 14:43:11 home telegraf[27538]: github.com/influxdata/telegraf/plugins/inputs/netflow.(*NetFlow).read(0xc00050e070, {0x708eb80, 0xc000266960})
May 23 14:43:11 home telegraf[27538]: /go/src/github.com/influxdata/telegraf/plugins/inputs/netflow/netflow.go:124 +0x1e4
May 23 14:43:11 home telegraf[27538]: github.com/influxdata/telegraf/plugins/inputs/netflow.(*NetFlow).Start.func1()
May 23 14:43:11 home telegraf[27538]: /go/src/github.com/influxdata/telegraf/plugins/inputs/netflow/netflow.go:94 +0x66
May 23 14:43:11 home telegraf[27538]: created by github.com/influxdata/telegraf/plugins/inputs/netflow.(*NetFlow).Start
May 23 14:43:11 home telegraf[27538]: /go/src/github.com/influxdata/telegraf/plugins/inputs/netflow/netflow.go:92 +0x274
May 23 14:43:11 home systemd[1]: telegraf.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
May 23 14:43:11 home systemd[1]: telegraf.service: Failed with result 'exit-code'.
May 23 14:43:11 home systemd[1]: telegraf.service: Service hold-off time over, scheduling restart.
May 23 14:43:11 home systemd[1]: telegraf.service: Scheduled restart job, restart counter is at 1.
May 23 14:43:11 home systemd[1]: Stopped Telegraf.
May 23 14:43:11 home systemd[1]: Starting Telegraf...
May 23 14:43:11 home telegraf[27580]: 2023-05-23T14:43:11Z I! Loading config: /etc/telegraf/telegraf.conf
May 23 14:43:11 home telegraf[27580]: 2023-05-23T14:43:11Z I! Loading config: /etc/telegraf/telegraf.d/ipfix_cgs.conf
May 23 14:43:11 home systemd[1]: Started Telegraf.

@srebhan
Copy link
Member

srebhan commented May 23, 2023

@vknyazhev please download Telegraf from #13320 (comment) as this has the fix. Extract or install Telegraf from the downloaded file and use the following config

[[inputs.netflow]]
  service_address = "udp://:2055"
  protocol = "ipfix"

[[outputs.file]]
  files = ["stdout"]

and run

# telegraf --config <the config above> --debug

on a console.

@vknyazhev
Copy link
Author

debug_from_console.txt

@srebhan
Copy link
Member

srebhan commented May 24, 2023

Some explanation... The

No info template 261 found for and domain id 231; skipping packet
...

warnings are there because your device first sends some data and only after the first batch sends the templates. We simply ignore that first bunch of data as we do not know how to interpret them. This should only happen shortly after startup until the device first (re-)sends the templates.

The

2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 123 35632 [0 0 0 0]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 124 35632 [0 0 0 2]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 125 35632 [0 0 0 4]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 127 35632 [0 0 0 0]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 109 35632 [0 0 0 0]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 128 35632 [0 0 0 0]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 110 35632 [0 0 0 0]}
2023-05-23T16:46:50Z D! [inputs.netflow] unknown PEN data field {true 118 35632 [0 91]}
...

messages indicate that your device sends flows with Private Enterprise Number fields, here 35632 which should be ntop. Currently the plugin does not know how to interpret them so you will find the data as type_35632_<field number> in the metric with a hex-encoded value.

So this looks good. Thanks for testing.

@vknyazhev
Copy link
Author

Good afternoon
Yes, indeed it is from Ntop, we add additional information items via ntop(For example %RETRANSMITTED_IN_BYTES %RETRANSMITTED_IN_PKTS %RETRANSMITTED_OUT_BYTES %RETRANSMITTED_OUT_PKTS %DNS_QUERY %DNS_QUERY_ID %DNS_QUERY_TYPE %DNS_RET_CODE %DNS_NUM_ANS WERS %DNS_TTL_ANSWER %DNS_RESPONSE %HTTP_URL %HTTP_METHOD %HTTP_RET_CODE %HTTP_REFERER %HTTP_UA %HTTP_MIME %HTTP_HOST %HTTP_SITE %HTTP_X_FORWARDED_FOR %HTTP_VIA %TLS_SERVER_NAME %TLS_CIPHER %TLS_UNSAFE_CIPHER %TLS_VERSION )

@srebhan
Copy link
Member

srebhan commented May 24, 2023

@vknyazhev please open a feature request for this as it is unrelated.

srebhan added a commit to srebhan/telegraf that referenced this issue May 24, 2023
srebhan added a commit to srebhan/telegraf that referenced this issue May 30, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug unexpected problem or unintended behavior
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants