In my last post I introduced the concept of using white listing in order to review firewall logs. I discussed how this process can both simplify as well as expedite the log review process, by automating much of the up front work. In this post we will look at some actual examples, as well as start creating a firewall log parsing script.

The basics of grep

In order to show you the process of white listing your firewall logs, I am going to use grep. Grep is a standard Linux/UNIX tool, with free versions available for Windows (grab both the Binaries as well as the Dependencies). Grep is certainly not the most efficient tool for the job, but it is by far the simplest to learn. If you are a Perl, PHP, AWK&SED, SQL, etc. guru, by all means stick with your tool of choice. Simply mimic the process I’ve defined here using your appropriate command set.

Grep is a pattern-matching tool. It allows you to search one or more files looking for a specific pattern. When the pattern is found, the entire line is printed out. So for example the command:

grep 192.168.1.10 firewall.log

would produce all lines in the file “firewall.log” that contains the IP address “192.168.1.10”. Grep has a number of supported switches, but the only one we need for firewall log review is the “-v” switch. This switch tells grep to match all lines that DO NOT contain the specified pattern. So for example:

grep –v 192.168.1.10 firewall.log

would only print out lines that do not contain the specified IP address.

With grep, a period is actually a wild card character. So while I said the first grep command would match on the IP address 192.168.1.10, it could actually match on more than that. Grep interprets the string to read:

Match on: 192 <any single character> 168 <any single character> 1  <any single character> 10

If we want grep to match periods as periods, we have to preced them with a backslash character. So the proper syntax would actually be:

grep 192\.168\.1\.10 firewall.log

Finally, sometimes we want to match on multiple patterns that are strung together. For example what if we are only interested in 192.168.1.10 traffic when that’s the destination IP address? Depending on your firewall log format, the command may look something like this on a Linux or UNIX system:

grep ‘dst 192\.168\.1\.10’ firewall.log

On Windows, the command would look like this:

grep “dst 192\.168\.1\.10” firewall.log

Note the only difference is that Linux and UNIX uses single quotes, while Windows uses double quotes.

Logical AND’s and OR’s

Sometimes we need to match on multiple patterns within the same line. For example what if we only wish to see TCP/80 traffic to our Web server? In this case there are actually two patterns we wish to match on the same line. The problem is there may be other stuff in the middle we don’t care about.

To perform a logical AND, simply use the grep command twice on the same line. For example:

grep “dst 192\.168\.1\.10” firewall.log | grep “dst_port 80 ”

The pipe symbol simply lets you run the second grep command before execution ends. So the first grep command will grab all traffic going to 192.168.1.10 and then pass it to the second grep command. The second grep command then searches this output for all traffic headed to port 80. Look closely after the port number and you will see I included a space character. Without a space character, we could potentially match on port 800, 8080, etc.

Sometimes we may wish to match on either of two values. For example what if we wanted to see both HTTP and HTTPS traffic to our Web server? In this case we would need to do a logical AND combined with a logical OR. Here’s how to do that with grep:

grep ‘dst 192\.168\.1\.10’ firewall.log | grep ‘dst_port \(80 \|443 \)’

The first half of the command should look familiar, but the second half needs some explaining. We need to tell grep that the parenthesis characters are actual commands and not part of the string we wish to match. We do this by preceding them with a backslash character. The pipe character is what tells grep to process this command as a logical OR. Note the pipe also needs to be preceded by a backslash.

Sorting logs with grep

OK, so we have the basics, now let’s start applying them to reviewing a firewall log file. The first thing you need to do is get the log file into ASCII format. This is the native format for many firewalls, so no conversion may be required. If the log uses a proprietary format, the vendor usually supplies a tool to do the conversion. Personally I just send the logs to a SIM (http://www.chrisbrenton.org/2009/08/setting-up-a-security-information-management-system-sim-%E2%80%93-part-1/). From there you can simply copy them off to a working directory.

Next we need to open a text editor. While we can run our grep commands on the command line to test their accuracy, we want to place the commands in a shell script or batch file so they can be easily run later. For the rest of this post I will use single quotes, which is the syntax for both Linux and UNIX. Remember that your Windows version of grep may want to see double quotes instead.

The next step is to review the log file looking for traffic patterns you recognize. Let’s take an easy one like HTTP traffic to your Web server. Look closely at a log entry and identify what unique characteristics it has which tells you its HTTP traffic to your Web server. Most likely this will be the target IP address of your Web server, as well as a target port of TCP/80. Now simply create a grep command to copy these entries to a new file:

grep ‘dst 192\.168\.1\.10’ firewall.log | grep ‘dst_port 80 ’ > web_server_http.txt

Note that rather than print the output to the screen, we redirected it to a file with a descriptive name. That way the log entries are available for later review.

If our Web server is only offering HTTP, we should only see traffic headed to port TCP/80. Any other port connect attempts can be considered suspect traffic, and may be part of a scan or probe. With port TCP/80 traffic in it’s own file, we now simply redirect everything else to another file:

grep ‘dst 192\.168\.1\.10’ firewall.log | grep –v ‘dst_port 80 ’ > web_server_scan.txt

This should account for all traffic headed to our Web server. Now we need to get all of this saved traffic out of the way so it will be easier to spot other entries. While we could try to delete them, it would be prudent to keep an unmodified version of the firewall log just in case we need to refer back to it. The easiest way to handle this conflict is to simply create a new temporary file.

grep –v ‘dst 192\.168\.1\.10’ firewall.log > temp1.txt

Now we simply open “temp1.txt” and look for the next pattern we recognize. Let’s say that’s inbound and outbound SMTP. That section of our script may look something like this:

grep ‘dst 192\.168\.1\.12’ temp1.txt | grep ‘dst_port 25 ’ > smtp_inbound.txt

grep ‘dst 192\.168\.1\.12’ temp1.txt | grep –v ‘dst_port 25 ’ > smtp_server_scan.txt

grep –v ‘dst 192\.168\.1\.12’ temp1.txt > temp2.txt

grep ‘src 192\.168\.1\.12’ temp2.txt | grep ‘dst_port 25 ’ > smtp_outbound.txt

grep ‘src 192\.168\.1\.12’ temp2.txt | grep –v ‘dst_port 25 ’ > smtp_server_compromise.txt

grep –v ‘src 192\.168\.1\.12’ temp2.txt > temp3.txt

SMTP is a bidirectional service, so the first three lines take care of inbound traffic, while the last three look at outbound. Note that in line five we expect to see the server only communicating out on TCP/25. Any other port attempts may indicate the system has been compromised and is now calling home. Obviously it would be a good idea to do the same for the Web server:

grep ‘src 192\.168\.1\.10’ temp3.txt  > web_server_compromise.txt

grep –v ‘src 192\.168\.1\.10’ temp3.txt > temp4.txt

Closing out your script

Now simply repeat this process until you are left with a temp file that has log entries you don’t expect to see. It is now time to start closing out our script. First, rename your last temporary file to something that will catch your attention. On Windows the command would be:

ren temp23.txt interesting_stuff.txt

On Linux or UNIX the command would be:

mv temp23.txt interesting_stuff.txt

This interesting file will probably be the first file you are going to want to review, as it will contain all of the unexpected patterns. Now that all the normal traffic flow is out of the way, it should take substantially less time to spot anything you truly need to worry about.

One nice thing about the temp files is that they can aid in troubleshooting. For example if grep moves 1.5 MB of log entries into a new file, I should expect to see the next temp file shrink by 1.5 MB as well. If not, something is wrong in my script. Also, if you notice that all of your temp files after “temp12.txt” have a zero file length, chances are you have a syntax error just after you created “temp12.txt”.

Once your script is vetted and working however, you may not want to have the temp files in your working directory. That way it is easier to focus in on the sorted files during a review. When you reach this point, simply have the last line of your script delete the temp files. On Windows the syntax would be:

del /q temp*.txt

and on UNIX or Linux the command would be:

rm –f temp*.txt

Automating the process

Once you have a working script, it is now time to automate the process. If you are running Linux or UNIX, simply setup the script to run via cron. If you need help with configuring a cron job there are some excellent help pages. The equivalent on Windows is called a Scheduled Task, and Microsoft has some excellent help in the knowledgebase.

Final thoughts

I mentioned in my last post that I like to look for error packets. I will typically do this right at the beginning of my script. Also, it is not uncommon for systems to call home in order to check for patches. I usually put these exceptions at the beginning of my script as well. Something like:

grep ‘dst 1\.2\.3\.[60-61] ‘ firewall.log > server_patching.txt

grep ‘dst 10\.20\.30\.[1-8] ‘ firewall.log >> server_patching.txt

The first command grabs all traffic headed to 1.2.3.60 or 1.2.3.61. The second looks for traffic headed to 10.20.30.1 – 10.20.30.8. Be very careful in specifying multiple systems! This is a great way to miss something interesting in your log files. You should only use this syntax to describe known patch server. Never specify all the subnets for a particular company. For example if you filter out all Microsoft IPs this way, than a single owned system on their network could control bots on your network and you would never know it.

This syntax is also handy when writing filters for outbound log entries. For example assume that we use 192.168.1.0 – 192.168.1.24 for internal addressing. To grab all outbound HTTP traffic we could say:

grep ‘src 192\.168\.[1-24]\.[0-255] ‘ temp15.txt | grep ‘dst_port 80 ’ > outbound_http.txt

As mentioned in the last post, we may wish to check outbound HTTP during non-business hours to see if we have any Malware calling home.

Don’t forget you can use grep as part of your review process as well. For example let’s say we are reviewing interesting_stuff.txt and spot a source IP (1.2.3.4) we know is hostile. We want to check the file to see if there are any other IP addresses we need to be concerned with. While we could keep paging through the file, a simpler solution would be to use grep:

grep –v 1\.2\.3\.4 interesting_stuff.txt

You review script has the potential to act as a mini-IDS system. By this I mean if you find a suspect pattern but figure out what’s going on, don’t be afraid to leverage your script to categorize this pattern in the future.

For example, let’s say we notice a number of systems on the Internet attempting to access port 5060, but we do not have this port open through our firewall. A quick Google search will tell us that this is SIP (http://en.wikipedia.org/wiki/Session_Initiation_Protocol) traffic. Why bother to look it up every time we see it however if our script can identify it for us? Now that we know 5060 is SIP, simply add the following lines to our script:

grep ‘dst_port 5060 ‘ temp.txt > sip_traffic.txt

We can do the same for any ports that are commonly being probed.

Exec Summary

What makes firewall log review so time consuming is that you need to sift through all of the normal traffic patterns in order to find the log entries that identify a true security issue. By white listing all expected traffic patterns, it becomes far simpler to find and review any unexpected entries within your logs. By further automating the process of sorting the logs, log review can be reduced to a quick activity that can easily be performed on a daily basis.

One of the most difficult and time consuming parts of maintaining a perimeter is reviewing firewall logs. It’s not uncommon for an organization to generate 50, 100, 500 MB or more worth of firewall log entries on a daily basis. The task is so daunting in fact, that many administrators choose to ignore their logs. In this series I’ll show you how to expedite the firewall log review process so that you can complete it faster than that morning cup of coffee.

Why firewall log review is important

I once took part in a panel discussion where one of my fellow SANS instructors announced to the crowd “the perimeter is dead and just short of useless”. I remember thinking I was glad I was not one of his students. I occasionally take on new clients and find that 7/10 times I can identify at least one compromised system they did not know about. In every case it has been the client’s own firewall logs that pointed me to the infected system.

In the old days firewall log review was all about checking your inbound drop entries to look for port scans. Today the focus is on outbound traffic. Specifically, you should be checking permitted patterns. With the plethora of non-signature Malware today it has become far too easy for an attacker to get malicious code onto a system. A properly configured perimeter will show you when a compromised system tries to call home. This is typically your best chance to identify when a system has become compromised.

What needs to be logged?

Dropped traffic does not have to be logged provided you are not blind to DoS flood attacks. For example if you are running a tool such as NTOP on your perimeter, collecting RMON or Netflow data, than it is OK not to log dropped packets as you can collect this information through other means.

When traffic is permitted across the perimeter however, you need to log it. This includes all permitted traffic, regardless of direction (egress as well as ingress). At a minimum we want to see header information for the first packet in a session. Anything beyond that can be considered a bonus.

Some kernel level rootkits do an excellent job of hiding themselves within the infected system. In fact many are so stealthy they cannot be detected by checking the system directly. One possible option is to pull the hard drive and check it from a known to be clean system. Obviously this is highly impractical whenever you have more than just a couple of systems.

A better option is to check the network for tell tale signs of the Malware calling home. Malware typically creates outbound sessions either to transfer a toolkit or check in for marching orders. The firewall is in an optimal position to potentially block, or at the very least log, both of these activity patterns. So by reviewing our firewall logs, we can quickly check every system on our network for indications of a compromise.

Malware can leverage any socket to call home, but most use TCP/80 (HTTP) or TCP/443 (HTTPS). This is because Malware authors know most firewall administrators do not log these outbound sessions because they are responsible for the greatest portion of perimeter traffic. So again, if we are going to permit the traffic to pass our perimeter, we must insure we are logging it.

Log review as a process

The mistake I see most administrators make is they perform a time linear analysis of their log entries looking for “the interesting stuff”. The problem is suspect traffic can be extremely difficult to detect this way as it will be mixed in with normal traffic flow. So the first thing we need to do is get the normal traffic out of the way.

Think of the rectangle in Figure #1 as representing your firewall log. Assume it contains a mixture of normal as well as suspect traffic patterns. Rather than immediately looking for the suspect patterns, let’s first get the normal patterns out of the way. For example HTTP headed to our Web server from the Internet is an expected pattern. If we pull all of these entries out of the log file, the log file becomes a little bit smaller. Inbound and outbound SMTP to our mail server is another expected pattern. Again, if we can remove these entries as well the firewall log file becomes even smaller.

Now we simply continue this process for every traffic pattern we expect to see crossing our perimeter. The more traffic patterns we recognize and move out of the way, the smaller the final log file becomes. What’s left is just the unexpected traffic patterns that require review time from a firewall administrator. I’ve seen sites that typically generate 250-300 MB worth of logs daily end up with a final file less that 100 KB in size. Needless to say 100 KB takes far less time to review that 300 MB.

Automate, automate, automate

If this seems like a lot of work, it only will be initially. What I do is create a batch file, shell script, or set of database queries to automate the process of parsing the firewall log. We can then run this process as a CRON job or scheduled task. This means that all of the hard work (breaking up the main log file into smaller files) can be done off hours. When you walk in the door in the morning, the log file will already be segregated. You can then immediately focus in on the suspect patterns.

Helpful tips

Here are some tips I’ve developed over the years:

• There is no “single right way” to segregate log entries. It is all about how you personally spot unsuspected patterns. You can sort by IP address, port number, or whatever info you have to work with in your logs.
• This is not about obsessively putting one log entry into every sort file. This process is about creating easier to spot patterns. For example a TCP reset in an HTTP stream could go in both an “error” file and an “HTTP” file. Each would make it easier to spot different types of patterns.
• Start by pulling our error packets (TCP resets, ICMP type 3’s & 11’s). They always indicate something is broke or someone did something unexpected.
• A smart attacker will never make your “top 5 communicators” list. I’ve seen infected systems make as few as four outbound connections in a day.
• Make a note of the average size of each of your sort files. A sharp spike in traffic may warrant further investigation.
• Sometimes it is helpful to parse the same pattern into two different files. For example I create an “outbound HTTP” file, and then parse out all of the traffic generate during non-business hours. This makes it much easier to find infected systems calling home.
• Whitelist know patch sites. For example systems may call home all night long to Microsoft and Adobe to check for updated patches. If you can parse out these entries, you’ll end up with far less noise in your final file.
• Some sites find it helpful to parse out users checking their personal email. This can be helpful information if data leakage occurs.
• I like to segregate traffic based on security zone. For example I would be far less concerned about SSH from the internal network to the DMZ, than I would about SSH headed to the Internet. If you are not sure why, read this.
• In an ideal world, ever traffic pattern you find will be described in your organization’s network usage policy. If its not, then further investigation may be required.
• Expect to tweak your script over time, as networks are an evolving entity.

Exec Summary

White listing expected traffic patterns in your firewall log can help to expedite the log review process. Similar traffic becomes grouped together, and can be more easily checked for suspect patterns. In part 2 of this series I’ll walk you through the process of creating your own script using a number of different firewall products.