Chapter 8. Logging, Monitoring, and Statistics

image with no caption

Exercising control over a network—whether for your home networking needs or in a professional context—is likely to be a main objective for anyone who reads this book. One necessary element of keeping control is having access to all relevant information about what happens in your network. Fortunately for us, PF (like most components of Unix-like systems) is able to generate log data for network activity.

PF offers a wealth of options for setting the logging detail level, processing log files, and extracting specific kinds of data. You can already do a lot with the tools that are in your base system, and several other tools are available via your package system to collect, study, and view log data in a number of useful ways. In this chapter, we take a closer look at PF logs in general and some of the tools you can use to extract and present information.

PF Logs: The Basics

The information that PF logs and the level of logging detail is up to you, as determined by your rule set. Basic logging is simple: For each rule that you want log data for, add the log keyword. When you load the rule set with log added to one or more rules, any packet that starts a connection matching the rule (blocked, passed, or matched) is copied to a pflog device. PF will also store certain additional data such as the timestamp, interface, whether the packet was blocked or passed, and the associated rule number from the loaded rule set.

PF log data is collected by the pflogd logging daemon, which is started by default when PF is enabled at system startup. The default location for storing the log data is /var/log/pflog. The log is written in a binary format intended to be read by tcpdump. We’ll discuss additional tools to extract and display information from your log file later. The log file format is a well documented and widely supported binary format.

To get started, here’s a basic log example. Start with the rules you want to log and add the log keyword:

block log
pass log quick proto { tcp, udp } to port ssh

Reload the rule set, and you should see the timestamp on your /var/log/pflog file change as the file starts growing. To see what is being stored there, use tcpdump with the -r option to read the file.

If logging has been going on for a while, entering the following on a command line can produce large amounts of output.

$ sudo tcpdump -n -ttt -r /var/log/pflog

For example, the following are just the first lines from a file several screens long, with almost all lines long enough to wrap:

$ sudo tcpdump -n -ttt -r /var/log/pflog
tcpdump: WARNING: snaplen raised from 96 to 116
Sep 13 13:00:30.556038 rule 10/(match) pass in on epic0: 194.54.107.19.
34834 > 194.54.103.66.113: S
3097635127:3097635127(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 0,[|tcp]> (DF)
Sep 13 13:00:30.556063 rule 10/(match) pass out on fxp0: 194.54.107.19.34834 >
 194.54.103.66.113: S
3097635127:3097635127(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 0,[|tcp]> (DF)
Sep 13 13:01:07.796096 rule 10/(match) pass in on epic0: 194.54.107.19.29572
 > 194.54.103.66.113: S
2345499144:2345499144(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 0,[|tcp]> (DF)
Sep 13 13:01:07.796120 rule 10/(match) pass out on fxp0: 194.54.107.19.29572 >
 194.54.103.66.113: S
2345499144:2345499144(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 0,[|tcp]> (DF)
Sep 13 13:01:15.096643 rule 10/(match) pass in on epic0: 194.54.107.19.29774
 > 194.54.103.65.53:
49442 [1au][|domain]
Sep 13 13:01:15.607619 rule 12/(match) pass in on epic0: 194.54.107.19.29774 >
 194.54.107.18.53:
34932 [1au][|domain]

The tcpdump program is very flexible, especially when it comes to output, and it offers a number of display choices. The format in this example follows from the options we fed to tcpdump. The program almost always displays the date and time the packet arrived (the -ttt option specifies this long format). Next, tcpdump lists the rule number in the loaded rule set, the interface on which the packet appeared, the source and target address and ports (the -n option tells tcpdump to display IP addresses, not hostnames), and the various packet properties.

Note

The rule numbers in your log files refer to the loaded, in-memory rule set. Your rule set goes through some automatic steps during the loading process, such as macro expansion and optimizations, which make it likely that the rule number as stored in the logs will not quite match what you would find by counting from the top of your pf.conf file. If it isn’t immediately obvious to you which rule matched, use pfctl -vvs rules and study the output.

In our tcpdump output example, we see that the tenth rule (rule 10) in the loaded rule set seems to be a catchall that matches both IDENT requests and domain name lookups. This is the kind of output you will find invaluable when debugging, and it is essential to have this kind of data available in order to stay on top of your network. With a little effort and careful reading of the tcpdump man pages, you should be able to extract useful information from your log data.

For a live display of the traffic you log, use tcpdump to read log information directly from the log device. To do so, use the -i option to specify which interface you want tcpdump to read from, as follows:

$ sudo tcpdump -nettti pflog0
tcpdump: WARNING: pflog0: no IPv4 address assigned
tcpdump: listening on pflog0, link-type PFLOG
Sep 13 15:26:52.122002 rule 17/(match) pass in on epic0: 91.143.126.48.46618 >
194.54.103.65.22: [|tcp] (DF)
Sep 13 15:28:02.771442 rule 12/(match) pass in on epic0: 194.54.107.19.8025 >
194.54.107.18.8025: udp 50
Sep 13 15:28:02.773958 rule 10/(match) pass in on epic0: 194.54.107.19.8025 >
194.54.103.65.8025: udp 50
Sep 13 15:29:27.882888 rule 10/(match) pass in on epic0: 194.54.107.19.29774 >
194.54.103.65.53:[|domain]
Sep 13 15:29:28.394320 rule 12/(match) pass in on epic0: 194.54.107.19.29774 >
194.54.107.18.53:[|domain]

This sequence begins with an SSH connection. The next two connections are spamd synchronizations, followed by two domain name lookups. If you were to leave this command running, the displayed lines would eventually scroll off the top of your screen, but you could redirect the data to a file or to a separate program for further processing.

Note

Sometimes you will be interested mainly in traffic between specific hosts, or traffic matching specific criteria. For these cases, tcpdump’s filtering features can be useful. See man tcpdump for details.

Logging All Packets: log (all)

For most debugging and lightweight monitoring purposes, logging the first packet in a connection provides enough information. However, sometimes you may want to log all packets that match certain rules. To do so, use the (all) logging option in the rules you want to monitor. After making this change to our minimal rule set, we have this:

block log (all)
pass log (all) quick proto tcp to port ssh keep state

This option makes the logs quite a bit more verbose. To illustrate just how much more data log (all) generates, we’ll use the following rule set fragment, which passes domain name lookups and network time synchronizations:

udp_services = "{ domain, ntp }"
pass log (all) inet proto udp to port $udp_services

With these rules in place, here’s an example of what happens when a Russian name server sends a domain name request to a server in our network:

$ sudo tcpdump -n -ttt -i pflog0 port domain
tcpdump: WARNING: pflog0: no IPv4 address assigned
tcpdump: listening on pflog0, link-type PFLOG
Sep 30 14:27:41.260190 212.5.66.14.53 > 194.54.107.19.53:[|domain]
Sep 30 14:27:41.260253 212.5.66.14.53 > 194.54.107.19.53:[|domain]
Sep 30 14:27:41.260267 212.5.66.14.53 > 194.54.107.19.53:[|domain]
Sep 30 14:27:41.260638 194.54.107.19.53 > 212.5.66.14.53:[|domain]
Sep 30 14:27:41.260798 194.54.107.19.53 > 212.5.66.14.53:[|domain]
Sep 30 14:27:41.260923 194.54.107.19.53 > 212.5.66.14.53:[|domain]

We now have six entries instead of just one.

Even with all but port domain filtered out by tcpdump, adding log (all) to one or more rules considerably increases the amount of data in your logs. If you need to log all traffic, but your gateway’s storage capacity is limited, you may find yourself shopping for additional storage. Also, recording and storing traffic logs with this level of detail is likely to have legal implications.

Logging to Several pflog Interfaces

PF versions older than OpenBSD 4.1 offered only one pflog interface. That changed with OpenBSD 4.1, when the pflog interface became a cloneable device, meaning that you can use ifconfig commands to create several pflog interfaces, in addition to the default pflog0. This makes it possible to record the log data for different parts of your rule set to separate pflog interfaces, and easier to process the resulting data separately if necessary.

The required changes to your setup are subtle but effective. To log to several interfaces, make sure that all the log interfaces your rule set uses are created. You don’t need to create the devices before the rule set is loaded; if your rule set logs to a nonexistent interface, the log data is simply discarded.

When tuning your setup to use several pflog interfaces, you will most likely add the required interfaces from the command line, like so:

$ sudo ifconfig create pflog1

Specify the log device when you add the log keyword to your rule set, as follows:

pass log (to pflog1) proto tcp to $emailserver port $email
pass log (to pflog1) proto tcp from $emailserver to port smtp

For a more permanent configuration on OpenBSD, create a hostname.pflog1 file containing only up, and similar hostname.pflogN files for any additional logging interfaces.

On FreeBSD, the configuration of the cloned pflog interfaces belongs in your rc.conf file, in the following form:

ifconfig_pflog1="up"

On NetBSD, cloning pflog interfaces is not an option as of this writing.

As you saw in Chapter 6, directing log information for different parts of your rule set to separate interfaces makes it possible to feed different parts of the log data PF produces to separate applications. This makes it easier to have programs like spamlogd process only the relevant information, while you feed other parts of your PF log data to other log-processing programs.

Logging to Syslog, Local or Remote

One way to avoid storing PF log data on the gateway itself is to instruct your gateway to log to another machine. If you already have a centralized logging infrastructure in place, this is a fairly logical thing to do, even if PF’s ordinary logging mechanisms were not really designed with traditional syslog-style logging in mind.

As any old BSD hand will tell you, the traditional syslog system log facility is a bit naïve about managing the data it receives over UDP from other hosts, with denial-of-service attacks involving full disks one frequently mentioned danger. There is also the ever-present risk that log information will be lost under high load on either individual systems or the network. Therefore, consider setting up remote logging only if all hosts involved communicate over a well-secured network. On most BSDs, syslogd is not set up by default to accept log data from other hosts. (See the syslogd man page for information about how to enable listening for log data from remote hosts if you plan to use remote syslog logging.)

If you would still like to do your PF logging via syslog, the following is a short recipe for how to accomplish this. In ordinary PF setups, pflogd copies the log data to the log file. When you primarily want to store the log data on a remote system, you should disable pflog’s data accumulation by changing its log file to /dev/null, via the daemon’s startup options in rc.conf.local (on OpenBSD), like so:

pflogd_flags="-f /dev/null"

On FreeBSD and NetBSD, change the pflog_logfile= line in rc.conf as follows, and then kill and restart the pflogd process with its new parameters:

pflog_logfile="/dev/null"

Next, make sure that the log data, now no longer collected by pflogd, is transmitted in a meaningful way to your log-processing system instead. This step has two parts: First, set up your system logger to transmit data to the log processing system, and then use tcpdump with logger to convert the data and inject it into the syslog system.

To set up syslogd to process the data, choose your log facility, log level, and action and put the resulting line in /etc/syslog.conf. These concepts are very well explained in man syslog.conf, which is required reading if you want to understand system logs. The action part is usually a file in a local filesystem. For example, if you have already set up the system logger at loghost.example.com to receive your data, choosing log facility local2 with log level info, enter this line:

local2.info                 @loghost.example.com

Once you’ve made this change, restart syslogd to make it read the new settings.

Next, set tcpdump to convert the log data from the pflog device and feed it to logger, which will then send it to the system logger. Here, we reuse the tcpdump command from the basic examples earlier in this chapter, with some useful additions:

$ sudo nohup tcpdump -lnettti pflog0 | logger -t pf -p local2.info &

The nohup command makes sure the process keeps running even if it does not have a controlling terminal or it’s put in the background (as we do here with the trailing &). The -l option to the tcpdump commad specifies line-buffered output, which is useful for redirecting to other programs. The logger option adds the tag pf to identify the PF data in the stream and specifies log priority with the -p option as local2.info. The result is logged to the file you specify on the logging host, with entries that will look something like this:

pf: Sep 21 14:05:11.492590 rule 93/(match) pass in on ath0: 10.168.103.11.15842 >
82.117.50.17.80: [|tcp] (DF)
pf: Sep 21 14:05:11.492648 rule 93/(match) pass out on xl0: 194.54.107.19.15842 >
82.117.50.17.80: [|tcp] (DF)
pf: Sep 21 14:05:11.506289 rule 93/(match) pass in on ath0: 10.168.103.11.27984 >
82.117.50.17.80: [|tcp] (DF)
pf: Sep 21 14:05:11.506330 rule 93/(match) pass out on xl0: 194.54.107.19.27984 >
82.117.50.17.80: [|tcp] (DF)
pf: Sep 21 14:05:11.573561 rule 136/(match) pass in on ath0: 10.168.103.11.6430 >
10.168.103.1.53:[|domain]
pf: Sep 21 14:05:11.574276 rule 136/(match) pass out on xl0: 194.54.107.19.26281 >
209.62.178.21.53:[|domain]

This log fragment shows mainly web-browsing activities from a client in a NATed local network as seen from the gateway’s perspective, with accompanying domain name lookups.

Tracking Statistics for Each Rule with Labels

The sequential information you get from retrieving log data basically tracks packet movements over time. In other contexts, the sequence or history of connections is less important than aggregates, such as number of packets or bytes that have matched a rule since the counters were last cleared.

At the end of Chapter 2, you saw how to use pfctl -s info to view the global aggregate counters, along with other data. For a more detailed breakdown of the data, track traffic totals on a per-rule basis with a slightly different form of pfctl command, such as pfctl -vs rules, to display statistics along with the rule, as shown here:

$ pfctl -vs rules
pass inet proto tcp from any to 192.0.2.225 port = smtp flags S/SA keep state
 label "mail-in"
  [ Evaluations: 1664158   Packets: 1601986   Bytes: 763762591   States: 0     ]
  [ Inserted: uid 0 pid 24490 ]
pass inet proto tcp from 192.0.2.225 to any port = smtp flags S/SA keep state
 label "mail-out"
  [ Evaluations: 2814933   Packets: 2711211   Bytes: 492510664   States: 0     ]
  [ Inserted: uid 0 pid 24490 ]

The format of this output is easy to read, and obviously designed for contexts where you want to get an idea of what is going on at a glance. If you specify even more verbose output with pfctl -vvs rules, you will see essentially the same display, with rule numbers added. On the other hand, the output from this command is not very well suited for feeding to a script or other program for further processing. To extract these statistics and a few more items in a slightly more script-friendly format (and make your own decisions about which rules are worth tracking), use rule labels.

Labels do more than identify rules for processing specific kinds of traffic; they also make it easier to extract the traffic statistics. By attaching labels to rules, you can store certain extra data about parts of your rule set. For example, you could use labeling to measure bandwidth use for accounting purposes.

In the following example, we attach the labels mail-in and mail-out to our pass rules for incoming and outgoing mail traffic, respectively.

pass log proto { tcp, udp } to $emailserver port smtp label "mail-in"
pass log proto { tcp, udp } from $emailserver to port smtp label "mail-out"

Once you have loaded the rule set with labels, check the data using pfctl -vsl:

$ sudo pfctl -vsl
    ❶     ❷      ❸       ❹       ❺      ❻        ❼      ❽
mail-in 1664158 1601986 763762591 887895 682427415 714091 81335176
mail-out 2814933 2711211 492510664 1407278 239776267 1303933 252734397

This output contains the following information:

❶ The label

❷ The number of times the rule has been evaluated

❸ The total number of packets passed

❹ The total number of bytes passed

❺ The number of packets passed in

❻ The number of bytes passed in

❼ The number of packets passed out

❽ The number of bytes passed out

The format of this list makes it very well suited for parsing by scripts and applications.

The labels accumulate data from the time the rule set is loaded until their counters are reset. And, in many contexts, it makes sense to set up a cron job that reads label values at fixed intervals, and then puts those values into permanent storage.

If you choose to run the data collection at fixed intervals, consider collecting the data using pfctl -vszl. The z option resets the counters once pfctl has read them, with the result that your data collector will then be fetching periodic data, accumulated since the command or the script was last run.

Note

Rules with macros and lists expand to several distinct rules. If your rule set contains rules with lists and macros that have a label attached, the in-memory result will be a number of rules, each with a separate, identically named label attached to it. While this may lead to confusing sudo pfctl -vsl output, it shouldn’t be a problem as long as the application or script that receives the data can interpret the data correctly by adding up the totals for the identical labels.

..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset
3.145.191.134