SIFTR(4)

πŸ“¦ version 15.1, in freebsd 14.5, freebsd 15.1, nixpkgs unstable

okay bestie, welcome to SIFTR(4) from the Kernel Interfaces Manual πŸ’… this page is all about the SIFTR kernel module, and she is literally the Statistical Information For TCP Research girlie. buckle up 🫢

πŸ’– NAME πŸ’–

SIFTR β€” Statistical Information For TCP Research 🌸

✨ SYNOPSIS ✨

To load the driver as a module at run-time, run the following command as root:

kldload siftr

Alternatively, to load the driver as a module at boot time, add the following line into the loader.conf(5) file:

siftr_load="YES"

🌸 DESCRIPTION 🌸

The SIFTR (Statistical Information For TCP Research) kernel module logs a range of statistics on active TCP connections to a log file. It provides the ability to make highly granular measurements of TCP connection state, aimed at system administrators, developers and researchers. she ate πŸ’…

πŸ› οΈ Compile-time Configuration πŸ› οΈ

The default operation of SIFTR is to capture IPv4 TCP/IP packets. SIFTR can be configured to support IPv4 and IPv6 by uncommenting:

CFLAGS+=-DSIFTR_IPV6

in ⟨sys/modules/siftr/Makefile⟩ and recompiling. periodt πŸ”₯

In the IPv4-only (default) mode, standard dotted decimal notation (e.g. "136.186.229.95") is used to format IPv4 addresses for logging. In IPv6 mode, standard dotted decimal notation is used to format IPv4 addresses, and standard colon-separated hex notation (see RFC 4291) is used to format IPv6 addresses (e.g. "fd00::2") for logging. iykyk ✨

βš™οΈ Run-time Configuration βš™οΈ

SIFTR utilises the sysctl(8) interface to export its configuration variables to user-space. The following variables are available:

  • net.inet.siftr.enabled β€” controls whether the module performs its measurements or not. By default, the value is set to 0, which means the module will not be taking any measurements. Having the module loaded with net.inet.siftr.enabled set to 0 will have no impact on the performance of the network stack, as the packet filtering hooks are only inserted when net.inet.siftr.enabled is set to 1. πŸ’–
  • net.inet.siftr.ppl β€” controls how many inbound/outbound packets for a given TCP connection will cause a log message to be generated for the connection. By default, the value is set to 1, which means the module will log a message for every packet of every TCP connection. The value can be set to any integer in the range [1,2^32], and can be changed at any time, even while the module is enabled. πŸ”₯
  • net.inet.siftr.logfile β€” controls the path to the file that the module writes its log messages to. By default, the file /var/log/siftr.log is used. The path can be changed at any time, even while the module is enabled. πŸŽ€
  • net.inet.siftr.port_filter β€” controls on which source or destination port SIFTR should capture. By default, the value is set to 0, which means all ports are eligible for logging. Set to any other value, only packets where either the source or destination port is equal to this number are logged. 🌈

πŸ“ Log Format πŸ“

A typical SIFTR log file will contain 3 different types of log message. All messages are written in plain ASCII text. ngl, it’s giving structured-data realness πŸ’…

Note: the \ present in the example log messages in this section indicates a line continuation and is not part of the actual log message. don’t let it confuse the vibe check 🫢

The first type of log message is written to the file when the module is enabled and starts collecting data from the running kernel. The text below shows an example module enable log. The fields are tab delimited key-value pairs which describe some basic information about the system. ✨

enable_time_secs=1685191807    enable_time_usecs=160752 \
siftrver=1.3.0    sysname=FreeBSD    sysver=1400089    ipmode=4

Field descriptions are as follows:

  • enable_time_secs β€” time at which the module was enabled, in seconds since the UNIX epoch.
  • enable_time_usecs β€” time at which the module was enabled, in microseconds since enable_time_secs.
  • siftrver β€” version of SIFTR.
  • sysname β€” operating system name.
  • sysver β€” operating system version.
  • ipmode β€” IP mode as defined at compile time. An ipmode of "4" means IPv6 is not supported and IP addresses are logged in regular dotted quad format. An ipmode of "6" means IPv6 is supported, and IP addresses are logged in dotted quad or hex format, as described in the "Compile-time Configuration" subsection.

The second type of log message is written to the file when a data log message is generated. The text below shows an example data log triggered by an IPv4 TCP/IP packet. The data is CSV formatted. πŸ‘‘

o,1685191814.185109,10.1.1.2,32291,10.1.1.3,5001,1073725440, \
14480,2,65160,65700,7,9,4,1460,1000,1,16778209,230000,33580,0, \
65700,0,0,0,86707916,130

Field descriptions are as follows:

  1. Direction of packet that triggered the log message. Either "i" for in, or "o" for out.
  2. Time at which the packet that triggered the log message was processed by the pfil(9) hook function, in seconds and microseconds since the UNIX epoch.
  3. The IPv4 or IPv6 address of the local host, in dotted quad (IPv4 packet) or colon-separated hex (IPv6 packet) notation.
  4. The TCP port that the local host is communicating via.
  5. The IPv4 or IPv6 address of the foreign host, in dotted quad (IPv4 packet) or colon-separated hex (IPv6 packet) notation.
  6. The TCP port that the foreign host is communicating via.
  7. The slow start threshold for the flow, in bytes.
  8. The current congestion window for the flow, in bytes.
  9. The current state of the t_flags2 field for the flow.
  10. The current sending window for the flow, in bytes. The post scaled value is reported.
  11. The current receive window for the flow, in bytes. The post scaled value is always reported.
  12. The current window scaling factor for the sending window.
  13. The current window scaling factor for the receiving window.
  14. The current state of the TCP finite state machine, as defined in ⟨netinet/tcp_fsm.h⟩.
  15. The maximum segment size for the flow, in bytes.
  16. The current smoothed RTT estimate for the flow, in units of microsecond.
  17. SACK enabled indicator. 1 if SACK enabled, 0 otherwise.
  18. The current state of the TCP flags for the flow. See ⟨netinet/tcp_var.h⟩ for information about the various flags.
  19. The current retransmission timeout length for the flow, in units microsecond.
  20. The current size of the socket send buffer in bytes.
  21. The current number of bytes in the socket send buffer.
  22. The current size of the socket receive buffer in bytes.
  23. The current number of bytes in the socket receive buffer.
  24. The current number of unacknowledged bytes in-flight. Bytes acknowledged via SACK are not excluded from this count.
  25. The current number of segments in the reassembly queue.
  26. Flowid for the connection. A caveat: Zero '0' either represents a valid flowid or a default value when it’s not being set. There is no easy way to differentiate without looking at actual network interface card and drivers being used.
  27. Flow type for the connection. Flowtype defines which protocol fields are hashed to produce the flowid. A complete listing is available in sys/mbuf.h under M_HASHTYPE_*.

The third type of log message is written to the file when the module is disabled and ceases collecting data from the running kernel. The text below shows an example module disable log. The fields are tab delimited key-value pairs which provide statistics about operations since the module was most recently enabled. πŸ¦‹

disable_time_secs=1685191816    disable_time_usecs=629397 \
num_inbound_tcp_pkts=10    num_outbound_tcp_pkts=10 \
total_tcp_pkts=20    num_inbound_skipped_pkts_malloc=0 \
num_outbound_skipped_pkts_malloc=0    num_inbound_skipped_pkts_tcpcb=2 \
num_outbound_skipped_pkts_tcpcb=2    num_inbound_skipped_pkts_inpcb=0 \
num_outbound_skipped_pkts_inpcb=0    total_skipped_tcp_pkts=4 \
flow_list=10.1.1.2;32291-10.1.1.3;5001,10.1.1.2;58544-10.1.1.3;5001,

Field descriptions are as follows:

  • disable_time_secs β€” Time at which the module was disabled, in seconds since the UNIX epoch.
  • disable_time_usecs β€” Time at which the module was disabled, in microseconds since disable_time_secs.
  • num_inbound_tcp_pkts β€” Number of TCP packets that traversed up the network stack. This only includes inbound TCP packets during the periods when SIFTR was enabled.
  • num_outbound_tcp_pkts β€” Number of TCP packets that traversed down the network stack. This only includes outbound TCP packets during the periods when SIFTR was enabled.
  • total_tcp_pkts β€” The summation of num_inbound_tcp_pkts and num_outbound_tcp_pkts.
  • num_inbound_skipped_pkts_malloc β€” Number of inbound packets that were not processed because of failed malloc() calls.
  • num_outbound_skipped_pkts_malloc β€” how many outbound packets got ghosted because a malloc() call failed 😭 lowkey tragic but it happens.
  • num_inbound_skipped_pkts_tcpcb β€” how many inbound packets didn't get processed because we couldn't find the TCP control block that goes with them. it's giving "who dis" πŸ’€
  • num_outbound_skipped_pkts_tcpcb β€” same energy but outbound: packets that went unprocessed because their TCP control block was nowhere to be found.
  • num_inbound_skipped_pkts_inpcb β€” inbound packets that didn't get processed because the IP control block for them couldn't be located. searching the group chat and finding nothing 🫠
  • num_outbound_skipped_pkts_inpcb β€” outbound packets that didn't get processed because we couldn't find their IP control block.
  • total_skipped_tcp_pkts β€” literally just all those skipped packet counters added together. the sum, the whole sum, nothing but the sum ✨
  • flow_list β€” a CSV list of every TCP flow that triggered data log messages since the module was loaded πŸŽ€ each entry in the CSV is formatted like "local_ip;local_port-foreign_ip;foreign_port". if the list is empty (like, no data log messages were ever generated) the value is blank. if there's at least one entry in the list, there will always be a trailing comma. no cap.

okay so here's the vibe check on all that: the total number of data log messages you'll find in the log file for one module enable/disable cycle should equal total_tcp_pkts minus total_skipped_tcp_pkts. math is mathing πŸ’…


✨ IMPLEMENTATION NOTES ✨

So SIFTR hooks into the network stack using the pfil(9) interface πŸͺ in its current incarnation, it hooks into the AF_INET/AF_INET6 (IPv4/IPv6) pfil(9) filtering points, which means it's seeing packets at the IP layer of the network stack. translation: TCP packets coming inbound to the stack get intercepted before the TCP layer has processed them. packets going outbound get intercepted after the TCP layer has processed them. order matters, bestie ⭐

the diagram below shows exactly how SIFTR inserts itself into the stack:

      ----------------------------------
                 Upper Layers
      ----------------------------------
          ^                       |
          |                       |
          |                       |
          |                       v
       TCP in                  TCP out
      ----------------------------------
          ^                      |
          |________     _________|
                  |     |
                  |     v
                 ---------
                 | SIFTR |
                 ---------
                  ^     |
          ________|     |__________
          |                       |
          |                       v
      IPv{4/6} in            IPv{4/6} out
      ----------------------------------
          ^                       |
          |                       |
          |                       v
      Layer 2 in             Layer 2 out
      ----------------------------------
                Physical Layer
      ----------------------------------

SIFTR uses the alq(9) interface to manage writing data to disk. πŸ–ŠοΈ

okay so at first glance you might think SIFTR is out here extracting info from individual TCP packets β€” and bestie, that is not the case πŸ™ˆ SIFTR uses TCP packet events (inbound and outbound) for each TCP flow originating from the system to trigger a dump of the state of the TCP control block for that flow. with PPL set to 1, we're effectively sampling each TCP flow's control block state as frequently as flow packets enter/leave the system. for example, setting PPL to 2 halves the sampling rate β€” i.e. every second flow packet (inbound OR outbound) causes a dump of the control block state. half the tea, same cup πŸ“

this distinction between interrogating individual packets vs. interrogating the control block is important because SIFTR does not remove the need for packet capturing tools like tcpdump(1). SIFTR lets you correlate and observe the cause-and-affect relationship between what you see on the wire (captured with a tool like tcpdump(1)) and the changes in the TCP control block for the flow you care about. so it's genuinely useful to run SIFTR and a tool like tcpdump(1) to gather the data you need to piece together the complete picture. either tool on its own cannot give you all the necessary data β€” periodt πŸ‘‘

because it needs to interrogate the TCP control block, certain packets during a connection's lifecycle just can't trigger a SIFTR log message. the initial handshake happens without a control block existing or without the control block being fully initialized, and the final ACK is exchanged while the connection is in the TIMEWAIT state. so those ones are just... not invited to the party πŸŽ€

SIFTR was designed to minimise the delay introduced to packets traversing the network stack. that design called for a highly optimised and minimal hook function that extracted the minimal details necessary whilst holding the packet up, then passed those details to another thread for the actual processing and logging. efficiency icon πŸ’…

this multithreaded design does introduce some contention issues when accessing the data structure shared between the threads of operation 😬 when the hook function tries to place details in the structure, it must first acquire an exclusive lock. likewise, when the processing thread tries to read details from the structure, it must also acquire an exclusive lock to do so. if one thread holds the lock, the other has to wait before it can get it. so yeah β€” this does introduce some additional bounded delay into the kernel's packet processing code path. unavoidable, but noted fr fr.

in some cases (e.g. low memory, connection termination), TCP packets that enter the SIFTR pfil(9) hook function will not trigger a log message to be generated. SIFTR calls this outcome a "skipped packet". and here's the slay part: SIFTR always ensures packets are allowed to continue through the stack, even if they couldn't successfully trigger a data log message. so SIFTR will not introduce any packet loss for TCP/IP packets traversing the network stack. we love a considerate icon 🫢

🌸 Important Behaviours 🌸

so what happens if you change the log file path while the module is enabled? literally this:

  1. it attempts to open the new file path for writing. if that fails, the path change fails and the existing path keeps being used. no harm done πŸ’–
  2. assuming the new path is valid and opened successfully:
    • it flushes all pending log messages to the old file path.
    • it closes the old file path.
    • it switches the active log file pointer to point at the new file path.
    • it commences logging to the new file. ✨

and during that window between flushing pending log messages to the old file and starting to log to the new file, new log messages are still being generated and buffered. the second the new file path is ready for writing, all those accumulated log messages get written out to the file. nothing gets lost, bestie 🧚


πŸ”₯ EXAMPLES πŸ”₯

to enable the module's operations, run this as root:

sysctl net.inet.siftr.enabled=1

to change the granularity of log messages so that 1 log message is generated for every 10 TCP packets per connection, run this as root:

sysctl net.inet.siftr.ppl=10

to change the log file location to /tmp/siftr.log, run this as root:

sysctl net.inet.siftr.logfile=/tmp/siftr.log

πŸ‘€ SEE ALSO πŸ‘€

tcpdump(1), tcp(4), sysctl(8), alq(9), pfil(9)


πŸ’œ ACKNOWLEDGEMENTS πŸ’œ

development of this software was made possible in part by grants from the Cisco University Research Program Fund at Community Foundation Silicon Valley, and the FreeBSD Foundation. shoutout to the funders, absolute icons 🫢


🌈 HISTORY 🌈

SIFTR first appeared in FreeBSD 7.4 and FreeBSD 8.2. ✨

SIFTR was first released in 2007 by Lawrence Stewart and James Healy whilst working on the NewTCP research project at Swinburne University of Technology's Centre for Advanced Internet Architectures, Melbourne, Australia β€” which was made possible in part by a grant from the Cisco University Research Program Fund at Community Foundation Silicon Valley. more details are available at:

http://caia.swin.edu.au/urp/newtcp/

work on SIFTR v1.2.x was sponsored by the FreeBSD Foundation as part of the "Enhancing the FreeBSD TCP Implementation" project 2008-2009. more details are available at:

https://www.freebsdfoundation.org/

http://caia.swin.edu.au/freebsd/etcp09/

πŸŽ€ AUTHORS πŸŽ€

SIFTR was written by Lawrence Stewart <lstewart@FreeBSD.org> and James Healy <jimmy@deefa.com>. πŸ‘‘

this manual page was written by Lawrence Stewart <lstewart@FreeBSD.org>.

πŸ’€ BUGS πŸ’€

okay so here are the current known limitations and any relevant workarounds β€” outlined below, bestie, no cap 🫢

  • The internal queue used to pass information between the threads of operation is currently unbounded. This lets SIFTR cope with bursty network traffic, but sustained high packet-per-second traffic can cause exhaustion of kernel memory if the processing thread cannot keep up with the packet rate. πŸ’€
  • If you're using SIFTR on a machine that's also running other modules utilising the pfil(9) framework β€” e.g. dummynet(4), ipfw(8), pf(4) β€” the order in which you load the modules is important. You should kldload the other modules first, because this ensures TCP packets undergo any necessary manipulations before SIFTR β€œsees” and processes them. ✨
  • There is a known, harmless lock order reversal warning between the pfil(9) mutex and the tcbinfo TCP lock, reported by witness(4) when SIFTR is enabled in a kernel compiled with witness(4) support. It's giving spooky warning, but it's harmless, fr fr. πŸ™ˆ
  • There is no way to filter which TCP flows you wish to capture data for. Post processing is required to separate out data belonging to particular flows of interest. So yes, you're gonna be doing some sorting later, bestie. πŸŽ€
  • The module does not detect deletion of the log file path. New log messages will simply be lost if the log file being used by SIFTR is deleted whilst the module is set to use the file. Switching to a new log file using the net.inet.siftr.logfile variable will create the new file and allow log messages to begin being written to disk again. The new log file path must differ from the path to the deleted file. 🫠
  • The hash table used within the code is sized to hold 65536 flows. This is not a hard limit, because chaining is used to handle collisions within the hash table structure. However, we suspect β€” based on analogies with other hash table performance data β€” that the hash table look up performance (and therefore the module's packet processing performance) will degrade in an exponential manner as the number of unique flows handled in a module enable/disable cycle approaches and surpasses 65536. πŸ“‰
  • There is no garbage collection performed on the flow hash table. The only way currently to flush it is to disable SIFTR. That's the whole vibe: no auto-clean, only off/on. 🧹
  • The PPL variable applies to packets that make it into the processing thread, not total packets received in the hook function. Packets are skipped before the PPL variable is applied, which means there may be a slight discrepancy in the triggering of log messages. For example, if PPL was set to 10, and the 8th packet since the last log message is skipped, the 11th packet will actually trigger the log message to be generated. This is discussed in greater depth in CAIA technical report 070824A. 🧚
  • At the time of writing, there was no simple way to hook into the TCP layer to intercept packets. SIFTR's use of IP layer hook points means all IP traffic will be processed by the SIFTR pfil(9) hook function, which introduces minor, but nonetheless unnecessary packet delay and processing overhead on the system for non-TCP packets as well. Hooking in at the IP layer is also not ideal from the data gathering point of view. Packets traversing up the stack will be intercepted and cause a log message generation BEFORE they have been processed by the TCP layer, which means we cannot observe the cause-and-affect relationship between inbound events and the corresponding TCP control block as precisely as could be. Ideally, SIFTR should intercept packets after they have been processed by the TCP layer β€” i.e. intercept packets coming up the stack after they have been processed by tcp_input(), and intercept packets coming down the stack after they have been processed by tcp_output(). The current code still gives satisfactory granularity though, as inbound events tend to trigger outbound events, allowing the cause-and-effect to be observed indirectly by capturing the state on outbound events as well. πŸ¦‹
  • The β€œinflight bytes” value logged by SIFTR does not take into account bytes that have been SACK'ed by the receiving host. So yeah, that number is not the whole story. πŸ’…

mwah πŸ’‹ huge shoutout to the Debian girlies β€” this page is dated May 29, 2023, and it's SIFTR(4), periodt. πŸŽ€

πŸ“¦ where this page comes from