How to identify Exchange 2010 Outlook Web Access logins from IIS logs

Summary:

• look for POST events in the IIS logs going to /owa/auth.owa


• Make sure you've configured your web server and firewall to log to a logging server. Incident response begins long before the incident.


• Even denied traffic on your firewall's external interface can be interesting.

I had an interesting bit of detective work a while back that I thought I would share with you. I had to sanitize the crap out of this story but hopefully it proves to be a good exercise in forensic work and scientific discovery.

Recently I was asked to look into a situation where some poor organization had been victimized over the web. Someone had visited their website and made threatening statements on an anonymous discussion form and they wanted to know if I could learn anything about the person who made the threats.

The first step in this (and probably any investigation) is to have a chat with your legal folks to make sure that it is OK to proceed. The person who made the threat was at a form that doesn't ask for a name so we need to ensure that there is no problem with trying to undo the anonymity. In this case the legal folks said we could go ahead because of the nature of the threat.

OK, so now we need more information about the source, and the first place I wanted to look was in the web logs. We know what time the posting was made and we know what page it was on so it was pretty easy to find the source IP address. This is where it really proves true that the first step in incident response happens long before the incident occurs. This organization has a process for saving web logs and a procedure that dictates how long the log files have to be saved. Going to the web logs, I ran a simple grep to find every IP address that had visited the victimized page: grep victim weblogfile.txt. I got back 42 results, and this is the relevant one...

192.168.1.1 - - [12/Jan/2010:23:26:09 -0600] "POST /security/victimizedpage.php
HTTP/1.1" 200 8106 "http://www.domain.com/security/victimizedpage.php"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; Trident/4.0; SLCC2; .NET CLR
2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0;
InfoPath.2)"

So now we know that we're looking for 192.168.1.1. Obviously I've cleaned up the log files a bit, in truth it was some IP address out on the Internet somewhere. Next up I looked for other activity from that IP address. I also weeded out some of the stuff I wasn't interested in because it was making the results too cluttered to understand: grep 192.168.1.1 weblogfile.txt grep -v .css grep -v .png grep -v .jpg

There were a couple interesting things I saw here. For one, the person that posted the threat had been visiting the organizations web page all day long. This wasn't just a quick visit, drop off a threatening message, and leave. The person had been on the main page for a while, then over to Human Resources and a few other spots on the website. This happened several times throughout the day, but the threat wasn't dropped off until 11:26pm. The other thing that was interesting about the output was that the person had stopped by the Outlook Web Access page a few times. Make a note to check on OWA logins.

This organization also configures their Cisco firewall to log web activity. I decided that it would be worthwhile to check that out as well. Looking through the Cisco logs I saw a lot of activity from that machine to servers that are not open to the public. The results were again interesting.

This snippet (which is repeated often) shows that the machine had been trying to connect to the ldap port on all of the organizations domain controllers, which are not open through the firewall:

Jan 12 00:03:21 fw.domain.com %ASA-4-106023: Deny udp src
outside:192.168.1.1/62539 dst inside:172.16.52.10/389 by access-group "110"
[0x0, 0x0]
Jan 12 00:03:21 fw.domain.com %ASA-4-106023: Deny udp src
outside:192.168.1.1/62544 dst inside:172.16.52.109/389 by access-group "110"
[0x0, 0x0]
Jan 12 00:03:21 fw.domain.com %ASA-4-106023: Deny udp src
outside:192.168.1.1/62545 dst inside:172.16.52.108/389 by access-group "110"
[0x0, 0x0]
Jan 12 00:03:22 fw.domain.com %ASA-4-106023: Deny udp src
outside:192.168.1.1/62546 dst inside:172.16.52.1/389 by access-group "110" [0x0,
0x0]

Examining the logs further show that the person had many denied connections to internal services, but there doesn't seem to be any evidence of a port scan going on. It is possible that we could be dealing with a rather advanced attacker that was able to learn quite a bit about the internal network. However, it seems more possible that this computer may be a member of the organization's domain and have some hard coded values. Let's check out those Outlook Web Access logs.

The logs for Outlook Web Access are just the IIS logs, but since you have to authenticate to use OWA, the username sometimes appears in the logs for files that are in the secure area. It seems that the most reliable way to find login events is to search for POST events to /owa/auth.owa. Here is my example: unzip -c Exchange\ Logs.zip grep '192.168.1.1 ' grep -e '^2010-01-12' grep 'POST /owa/auth.owa'

There are a couple things you want to watch out for when you run these greps. First of all, when you're chaining grep statements together like this you want to make sure that you put the most restrictive grep first. The grep that will produce the fewest results should go first because then there is less work for your other grep statements. That's why the IP address is the first thing we're grepping for. Next, if you have a source IP address with a small number in the last octet, make sure you include a space after it or write a regular expression. Without it I would see results from 192.168.1.1, and also .12, .13, 101, etc. Here is a sampling of what I got:

2010-01-12 04:46:59 134.29.1.200 POST /owa/auth.owa - 443 user1 24.197.202.23
Mozilla/4.0+(compatible;+MSIE+8.0;+Windows+NT+6.1;+Trident/4.0;+SLCC2;+.NET+CLR+2.0.50727;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729;+Media+Center+PC+6.0;+InfoPath.2)
2010-01-12 06:06:21 134.29.1.200 POST /owa/auth.owa - 443 user23
24.197.202.23
Mozilla/4.0+(compatible;+MSIE+7.0;+Windows+NT+6.0;+SLCC1;+.NET+CLR+2.0.50727;+.NET+CLR+3.0.04506;+Tablet+PC+2.0;+InfoPath.2)

Two user names appeared, user1 and user23. I talked to the HR department and found out that there was a reasonable explanation for why these two users might have the same IP address. So we're in good shape, we now have two people of interest that we should interview to know more. But we can take it a step further. Check out the user-agent string that user1's browser sent and compare that to the user-agent string that was used to make the treat in the first place. It seems that they match! So between these two users, I think we are more interested in user1 than user23.