Following up on Mark Hofman's earlier post ("What is your firewall log telling you"), here's some tips on how a Unix command line can be used to cut a big firewall log file down to size for quick analysis.

In the installation that I use as an example here, the firewall sits between the internal network and the Internet, and only allows the internal proxy server to talk to the Internet. PC's on the internal network must surf over the proxy, and are barred from making direct connections through the firewall. This doesn't mean though that the PC's won't try -- a lot of malware, chat software, file sharing tools, etc are proxy-aware, but frequently also try a "direct" connection first. Looking at the direct connections that internal PCs attempt to make is a good way to find out what's happening on the network...

Let's assume we have a Checkpointish log format like this:

time=2010-03-02 23:59:57 action=drop orig=192.168.1.103 i/f_dir=inbound i/f_name=eth1c0 has_accounting=0 product=VPN-1 & FireWall-1 policy_name=INTERNET src=1.2.3.4 s_port=37586 dst=3.4.5.6 service=3384 proto=tcp rule=16 xlatesrc=8.9.10.11 xlatesport=57517 xlatedport=0 NAT_rulenum=4 NAT_addtnl_rulenum=internal

Let's further assume that we have already checked the connections that the firewall accepts, and that we now only want to look at traffic the firewall blocked. The easiest way to accomplish this is by suppressing all log lines that contain the string "action=accept", as follows

| grep -v "action=accept"

Now is where things get interesting. To make sense of the huge volume of log lines, we have to somehow "boil them down" into the essentials. Piping a log line into a command like this

| cut -d" " -f14-16

will just give us the fields 14-16 of each log line, with "space" used as separator (-delimiter). Your log line format might vary of course, so just count and adapt. In the above example, fields 14-16 amount to "dst=3.4.5.6 service=443 proto=tcp", so this gives us the destinations that our internal PCs attempt to talk to. Applying this "cut" command to the entire log still will give us the same number of lines as we had in the original log, but adding a command like

| sort | uniq -c | sort -rn

combines and counts all identical entries (uniq -c), and then gives us those lines that have the highest counts (sort, -n: by number, -r : reverse order). The result on the firewall log that I used as example here was

36642 dst=194.186.121.68 service=80 proto=tcp
 8616 dst=62.105.135.101 service=80 proto=tcp
 2641 dst=192.168.0.1 service=657 proto=udp
[...]

Once at this stage, the next step is to find out what these destinations are, and which systems we have on the network that are trying to talk to them. In this example, a quick check of "whois" reveals that both the top two IP addresses are in Russia ... and the topmost address had 36642 connection attempts from our network in a single day. Hmmm.....

Extending our original "cut" command above into

| cut -d " " -f12,14-16

now also includes the "source address" (field 12) into the output. If we now filter (grep) the output to only contain the first of the above russian IPs, the entire command line becomes

cat logfile.20100302 | grep -v "action=accept" | cut -d" " -f12,14-16 | grep "194.186.121.68" | sort | uniq -c | sort -rn

36424 src=192.168.140.108 dst=194.186.121.68 service=80 proto=tcp
  218 src=192.168.143.19 dst=194.186.121.68 service=80 proto=tcp

which shows two clients on our internal network (192.168.x) that try to talk to this outside IP address.

Now, the next step is to isolate the process(es) on these two systems that initiate the connections. If the two clients run on Windows, the best bet here is to use "tcpview" from the SysInternals suite. Some patience is called for - since the connection gets dropped by our firewall, it will not be listed as an active (ESTABLISHED) connection. But watching tcpview should eventually show a process that tries to open an outbound connection ("SYN_SENT"). Once the process is known, the "What Does Your Firewall Log Tell You" portion of this investigation is over, and standard malware fighting procedures kick in. SysInternals "ProcessExplorer" is a good next step to learn more about the potentially malicious process.

What is your favorite way to quickly carve out interesting tidbits from huge firewall logs? Let us know!