James Healy and Lawrence Stewart Centre for Advanced Internet Architectures, Swinburne University of Technology, Melbourne, Australia CRICOS number 00111D 18th December, 2007 ---------------------------------------------- OVERVIEW ---------------------------------------------- SIFTR (Statistical Information For TCP Research) v1.1.5 is a FreebSD 6/7 kernel module that 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 researchers of TCP behaviour. Whilst it was developed for and has been heavily tested on FreeBSD 6.2 and 7.0, it has received some testing on FreeBSD 5.4. SIFTR has been found to work as expected on this additional FreeBSD version, but extensive testing is still required. SIFTR hooks into the network stack using the PFIL (man 9 pfil) interface. In its current incarnation, it hooks into the AF_INET (IPv4) PFIL filtering point, which means it sees packets at the IP layer of the network stack. This means that TCP packets inbound to the stack are intercepted before they have been processed by the TCP layer. Packets outbound from the stack are intercepted after they have been processed by the TCP layer. The diagram below illustrates how SIFTR inserts itself into the stack. ---------------------------------- Upper Layers ---------------------------------- ^ | | | | | | v TCP in TCP out ---------------------------------- ^ | |________ _________| | | | v --------- | SIFTR | --------- ^ | ________| |__________ | | | v IPv4 in IPv4 out ---------------------------------- ^ | | | | v Layer 2 in Layer 2 out ---------------------------------- Physical Layer ---------------------------------- An in depth look at the software's capabilities has been documented in CAIA technical report 070824A. Information about obtaining the report is detailed in the "Related Reading" section of this file. ----------------------- LICENCE ----------------------- The SIFTR code is released under a BSD licence. It leverages the kernio code written by Pawel Jakub Dawidek and some of the hash code written by Tobias Weingartner. The original kernio source is also released under a BSD licence, as is the hash code. Refer to licence headers in each source file for further details. ----------------------- USAGE ----------------------- Make sure you have the FreeBSD system sources installed under /usr/src These can be installed using sysinstall if they are not currently installed. To build the module, simply run: make To load the compiled module into the running kernel, run the following command as root: kldload ./siftr.ko To unload the module from the running kernel, run the following as root: kldunload siftr To delete all artifacts created by compiling the module, run: make clean ----------------------- CONFIGURATION ----------------------- SIFTR utilises the FreeBSD sysctl interface to export its configuration variables to user-space. SIFTR provides 3 sysctl configuration variables. The names of the 3 variables and their default values on load are: net.inet.siftr.enabled=0 net.inet.siftr.ppl=1 net.inet.siftr.logfile=/var/log/siftr.log The net.inet.siftr.enabled variable 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. To enable the module's operations, run the following command as root: sysctl net.inet.siftr.enabled=1 The net.inet.siftr.ppl variable 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. To change the granularity of log messages such that 1 log message is generated for every 10 TCP packets per connection, run the following command as root: sysctl net.inet.siftr.ppl=10 The net.inet.siftr.logfile variable 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. To change the log file location to /tmp/siftr.log, run the following command as root: sysctl net.inet.siftr.logfile=/tmp/siftr.log ---------------------------------------------- IMPORTANT BEHAVIOURS AND TRIGGERS ---------------------------------------------- At first glance, you might mistakenly think that SIFTR extracts information from individual TCP packets. This 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 the PPL set to 1, we are in effect 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. The 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. SIFTR allows you to correlate and observe the cause-and-affect relationship between what you see on the wire (captured using a tool like tcpdump) and changes in the TCP control block corresponding to the flow of interest. It is therefore useful to use SIFTR and a tool like tcpdump to gather the necessary data to piece together the complete picture. Use of either tool on its own will not be able to provide all of the necessary data. SIFTR was designed to minimise the delay introduced to packets traversing the network stack. This design called for a highly optimised and minimal hook function that extracted the minimal details necessary whilst holding the packet up, and passing these details to another thread for actual processing and logging. 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 must wait before it can obtain it. To minimise delay, the SIFTR hook function will only attempt to acquire the lock once, and if it fails, it will drop the details and they will never make it to the log file. SIFTR refers to this outcome as a ``skipped packet'', because the details triggered by the packet will not be processed. Note that SIFTR always ensures that packets are allowed to continue through the stack, even if they could not successfully trigger a SIFTR log message. SIFTR will therefore not introduce any packet loss for any IPv4 packets traversing the network stack. The behaviour of a log file path change whilst the module is enabled is as follows: 1. Attempt to open the new file path for writing. If this fails, the path change will fail and the existing path will continue to be used. 2. Assuming the new path is valid and opened successfully: i) Flush all pending log messages to the old file path ii) Close the old file path iii) Switch the active log file pointer to point at the new file path iv) Commence logging to the new file During the time between the flush of pending log messages to the old file and commencing logging to the new file, new log messages will still be generated and buffered. As soon as the new file path is ready for writing, the accumulated log messages will be written out to the file. The only other action to cause a flush of all buffered log messages to disk is unloading the module. Enabling SIFTR, processing some TCP packets and then disabling SIFTR will not cause a flush of all buffered log messages to disk. Therefore, the only way to ensure all messages have been flushed to the log file is to unload the module prior to processing the logfile. ---------------------------------------------- LOG FORMAT ---------------------------------------------- A typical SIFTR log file will contain 3 different types of log message. All messages are written in plain ASCII text. Note: The "\" present in the example log messages in this section indicates a line continuation and is not part of the actual log message The first type of log message is written to the file when the module is loaded into the running kernel. The text below shows an example module load log. The fields are tab delimited key-value pairs which describe some basic information about the system. module_load_time_secs=1187923474 module_load_time_usecs=587926 \ siftrver=1.1.5 hz=1000 tcp_rtt_scale=32 sysname=FreeBSD sysver=602000 Field descriptions are as follows: module_load_time_secs: Time at which the module was loaded, in seconds since the UNIX epoch module_load_time_usecs: Time at which the module was loaded, in microseconds since module_load_time_secs siftrver: Version of SIFTR hz: The tick rate of the kernel in ticks per second tcp_rtt_scale: The smoothed RTT estimate scaling factor sysname: Operating system name sysver: Operating system version 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. The fields are CSV formatted. o,1197862707.744560,172.16.10.2,51308,172.16.11.2,5000,1073725440,36236, 1073725440,98304,5243208,11,11,4,1448,5225,0,992,582,5243208,5240312,5243208, 0,34752 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, in seconds and microseconds since the UNIX epoch. 3: The IPv4 address of the local host, in dotted quad notation. 4: The TCP port that the local host is communicating via. 5: The IPv4 address of the foreign host, in dotted quad 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 bandwidth-controlled window for the flow, in bytes. 10: The current sending window for the flow, in bytes. The post scaled value is reported, except during the initial handshake (first few packets), during which time the unscaled 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 15: The maximum segment size for the flow, in bytes. 16: The current smoothed RTT estimate for the flow, in units of TCP_RTT_SCALE * HZ, where TCP_RTT_SCALE is a define found in tcp_var.h, and HZ is the kernel's tick timer. Divide by TCP_RTT_SCALE * HZ to get the RTT in secs. TCP_RTT_SCALE and HZ are reported in the SIFTR load log message. 17: SACK enabled indicator. 1 if SACK enabled, 0 otherwise. 18: The current state of the TCP flags for the flow. See tcp_var.h for information about the various flags. 19: The current retransmission timeout length for the flow, in units of HZ, where HZ is the kernel's tick timer. Divide by HZ to get the timeout length in seconds. HZ is reported in the SIFTR load log message. 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. The third type of log message is written to the file when the module is unloaded from the running kernel. The text below shows an example module unload log. The fields are tab delimited key-value pairs which provide statistics about SIFTR operations since the module was loaded. module_unload_time_secs=1181705834 module_unload_time_usecs=028359 \ num_inbound_tcp_pkts=1 num_outbound_tcp_pkts=2 total_tcp_pkts=3 \ num_inbound_skipped_pkts_malloc=0 num_outbound_skipped_pkts_malloc=0 \ num_inbound_skipped_pkts\_mtx=0 num_outbound_skipped_pkts\_mtx=0 \ num_inbound_skipped_pkts\_tcb=0 num_outbound_skipped_pkts\_tcb=0 \ num_inbound_skipped_pkts_icb=0 num_outbound_skipped_pkts_icb=0 \ total_skipped_tcp_pkts=0 flow_list=136.186.229.95:57056-136.186.229.17:22, The total number of data log messages found in the log file for a module load/unload cycle should equate to total_tcp_pkts - total_skipped_tcp_pkts. Field descriptions are as follows: module_unload_time_secs: Time at which the module was unloaded, in seconds since the UNIX epoch. module_unload_time_usecs: Time at which the module was unloaded, in microseconds since module_load_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: Number of outbound packets that were not processed because of failed malloc() calls. num_inbound_skipped_pkts_mtx: Number of inbound packets that were not processed because of failure to add the packet to the packet processing queue. num_outbound_skipped_pkts_mtx: Number of outbound packets that were not processed because of failure to add the packet to the packet processing queue. num_inbound_skipped_pkts_tcb: Number of inbound packets that were not processed because of failure to find the TCP control block associated with the packet. num_outbound_skipped_pkts_tcb: Number of outbound packets that were not processed because of failure to find the TCP control block associated with the packet. num_inbound_skipped_pkts_icb: Number of inbound packets that were not processed because of failure to find the IP control block associated with the packet. num_outbound_skipped_pkts_icb: Number of outbound packets that were not processed because of failure to find the IP control block associated with the packet. total_skipped_tcp_pkts: The summation of all skipped packet counters. flow_list: A CSV list of TCP flows that triggered SIFTR log messages to be generated since the module was loaded. Each flow entry in the CSV list is formatted as "ip1:port1-ip2:port2". The ordering of the flow endpoints is arbitrary. If there are no entries in the list (i.e. no data log messages were generated), the value will be blank. If there is at least one entry in the list, a trailing comma will always be present. ---------------------------------------------- KNOWN LIMITATIONS ---------------------------------------------- Current known limitations of the SIFTR software and any relevant workarounds are outlined below: 1. A shutdown or restart of the system will not cause buffered log messages to be written to disk. When the kernel is shutting down, it does not call the module's unload handler function until after all other house keeping has been performed, including shutting down the VFS (disk) subsystem. This means that log messages already written to the log file prior to the system shutdown/restart will remain intact, but buffered log messages will be lost. A workaround is to install a rc script in /usr/local/etc/rc.d to unload the module when the ``stop'' parameter is passed to the script (which occurs before the kernel house keeping is performed during the system shutdown/restart sequence). 2. If you wish to have the module autoload at startup, DO NOT use /boot/loader.conf or rc.conf to load the module. On load, the module attempts to create the default log file (/var/log/siftr.log), and therefore the underlying /var filesystem must be mounted and writable. The correct method for automatic loading of the module on startup is to create a script in /usr/local/etc/rc.d that will, when passed ``start'' as a parameter, load the module and set any necessary sysctl variables. The script should also unload the module when passed ``stop'' as a parameter to hande system shutdown properly (see 1. above). 3. 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. 4. The module does not handle IPv6 at all, including TCP carried within IPv6 packets. It would be relatively straight forward to patch the code to make this possible, but there is currently no simple workaround. 5. 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 lookup 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 load/unload cycle approaches and surpasses 65536. 6. The PPL variable applies to packets that make it into the processing thread, not total packets received in the hook function. Skipped packets actually get skipped in the hook function, 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. Information about obtaining the report is detailed in the "Related Reading" section of this file. 7. At the time of writing, there was no simple way to hook into the TCP layer to intercept packets. SIFTR's use of IPv4 layer hook points means all IPv4 traffic will also be processed by the SIFTR 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. 8. If using SIFTR on a machine that is also running other modules utilising the PFIL architecture (e.g. IPFW), the order in which you load the modules is important. You should kldload the other modules first, as this will ensure TCP packets undergo any necessary manipulations before SIFTR "sees" and processes them. 9. The "inflight bytes" value logged by SIFTR does not take into account bytes that have been SACKed by the receiveing host. ---------------------------------------------- RELATED READING ---------------------------------------------- This software was developed as part of the NewTCP research project at Swinburne University's Centre for Advanced Internet Architectures. More information on the project is available at: http://caia.swin.edu.au/urp/newtcp/ A number of software tools and technical reports related to SIFTR and/or experimental TCP research in general are available respectively at: http://caia.swin.edu.au/urp/newtcp/tools.html http://caia.swin.edu.au/urp/newtcp/papers.html At the time of writing, the following software tools may be of interest: Deterministic Packet Discard (DPD) At the time of writing, the following reports may be of interest: CAIA technical report 070824A: "Characterising the Behaviour and Performance of SIFTR v1.1.0" CAIA technical report 070717B: "Tuning and Testing the FreeBSD 6 TCP Stack" CAIA technical report 070622A: "An Introduction to FreeBSD 6 Kernel Hacking"