search

CESNET / ipfixcol

IPFIXcol is an implementation of an IPFIX (RFC 7011) collector
Other
64 stars 37 forks source link

Long closing time of storage plugin can result in removal of valid templates #185

Closed sirK84 closed 7 years ago

sirK84 commented 7 years ago

Hi, I'm trying to write storage plugin for ipfixcol, and I came across some odd behavior. In case of short disconnection of ipfix exporter (shorter than closing time of storage plugin), we can loose templates that were received after reconnect and thus shall not be removed.

ipfixcol version: 0.9.2

I've prepared simple storage plugin implementation just for testing purposes (see attachment test_plugin.zip), and tested it in following scenario:

  1. start ipfixcol with plugin: $ ipfixcol -s -v3 ... Jan 23 15:18:23 ipfixcol[5863]: INFO: configurator: [5863] Opening storage xml_conf: /usr/local/share/ipfixcol/plugins/libtest_storage_plugin.so Jan 23 15:18:23 ipfixcol[5863]: INFO: configurator: No profile configuration ...
  2. start sending ipfix data with exporter: ... Jan 23 15:19:53 ipfixcol[5863]: INFO: SCTP input: New SCTP association from ::ffff:127.0.0.1 Jan 23 15:19:53 ipfixcol[5863]: DEBUG: ipfix_message: [0] Processing data Jan 23 15:19:53 ipfixcol[5863]: INFO: preprocessor: [0] New template ID 65535 Jan 23 15:19:54 ipfixcol[5863]: DEBUG: ipfix_message: [0] Processing data Jan 23 15:19:54 ipfixcol[5863]: DEBUG: dummy intermediate process: [0] Received IPFIX message Jan 23 15:19:54 ipfixcol[5863]: INFO: test_storage: GOT PACKET | ODID : 0 | SEQUENCE_NUMBER : 1 ...
  3. disconnect exporter for short period of time: ... Jan 23 15:19:58 ipfixcol[5863]: INFO: SCTP input: SCTP input plugin: Exporter disconnected Jan 23 15:19:58 ipfixcol[5863]: DEBUG: output manager: [0] Closed source Jan 23 15:19:58 ipfixcol[5863]: DEBUG: output manager: [0] No source; releasing templates... Jan 23 15:19:58 ipfixcol[5863]: INFO: storage plugin thread: [0] No more data from Data Manager Jan 23 15:19:58 ipfixcol[5863]: INFO: storage plugin thread: [0] Closing storage plugin thread Jan 23 15:19:58 ipfixcol[5863]: INFO: test_storage: CLOSING STORAGE PLUGIN Jan 23 15:19:59 ipfixcol[5863]: INFO: SCTP input: New SCTP association from ::ffff:127.0.0.1 Jan 23 15:19:59 ipfixcol[5863]: DEBUG: ipfix_message: [0] Processing data Jan 23 15:19:59 ipfixcol[5863]: INFO: preprocessor: [0] New template ID 65535 ...
  4. wait for storage plugin to close: ... Jan 23 15:20:03 ipfixcol[5863]: INFO: test_storage: STORAGE PLUGIN CLOSED Jan 23 15:20:03 ipfixcol[5863]: INFO: template manager: [0] Removing all templates Jan 23 15:20:03 ipfixcol[5863]: DEBUG: template manager: Removing all templates Jan 23 15:20:03 ipfixcol[5863]: DEBUG: template manager: Removing all option templates Jan 23 15:20:03 ipfixcol[5863]: DEBUG: template manager: Removing all templates Jan 23 15:20:03 ipfixcol[5863]: DEBUG: template manager: Removing all option templates ...
  5. after that it can be observed that "Removing all templates" also removed the ones that were received after reconnect: ... Jan 23 15:20:03 ipfixcol[5863]: DEBUG: ipfix_message: [0] Processing data Jan 23 15:20:03 ipfixcol[5863]: WARNING: preprocessor: [0] Data template with ID 65535 not found Jan 23 15:20:03 ipfixcol[5863]: DEBUG: dummy intermediate process: [0] Received IPFIX message Jan 23 15:20:03 ipfixcol[5863]: INFO: test_storage: NO METADATA Jan 23 15:20:04 ipfixcol[5863]: DEBUG: ipfix_message: [0] Processing data Jan 23 15:20:04 ipfixcol[5863]: WARNING: preprocessor: [0] Data template with ID 65535 not found Jan 23 15:20:04 ipfixcol[5863]: DEBUG: dummy intermediate process: [0] Received IPFIX message Jan 23 15:20:04 ipfixcol[5863]: INFO: test_storage: NO METADATA ...

I think that this is not desired behavior since it's not hard to imagine that some storage plugins can have prolonged closing time (especially if they are connected to remote databases).

I've tried this also for TCP input and results were the same. I'm attaching the logs for review: logs.zip

Kind Regards Krzysztof

Lukas955 commented 7 years ago

Hi, thanks for the precise description of the issue. I'm able to reproduce it and I'll try to fix it ASAP. I'll notify you when the issue is fixed.

Lukas

Lukas955 commented 7 years ago

Fixed by ef9ffef51a11606c407c2db1b1605cffcd795282. (devel branch)

By the way, you probably noticed that API for accessing message elements, etc. is not very userfriendly. We are working on a new, much better, collector API and internal collector design. Stay tuned.