Parse IIS logs to Analyze Exchange, Outlook Web Access and ActiveSync Activities

By Liisa Tallinn and Raido Karro

IIS log error responses in ti

Need to audit a specific user connecting to their mailbox? Troubleshoot why users can't sync their mobiles via ActiveSync? The answer to these and many other questions lie in the IIS logs of the Exchange server. These are, in most cases, typical IIS logs except the referrer field is missing.

How to parse the IIS logs

Extracting data from raw IIS files can be painful. The amount of information contained in a record is overwhelming and difficult to parse. The records are poor in separators, the fields are there or not depending on the version and/or setup of the IIS server. When taking a closer look at the URI query field in the raw record, a trained eye is likely to spot key-value pairs (KVPs). However, a closer look will reveal that those KVPs are mixed with random strings and some KVPs contain other KVPs. Like this:
User=User&DeviceId=7G6HGD8374HGGGFG&DeviceType=iPad&Cmd=Ping&Log=V141_LdapC1_Hb710_Rto1_Cpo9995_Fet710003_S1_Mbx:example.local_Throttle0_Budget:(D)Conn%3a1%2cHangingConn%3a0%2cAD%3a%24null%2f%24null%2f0%25%2cCAS%3a%24null%2f%24null%2f0%25%2cAB%3a%24null%2f%24null%2f0%25%2cRPC%3a%24null%2f%24null%2f0%25%2cFC%3a%24null%2f0%2cPolicy%3aDefaultThrottlingPolicy%6F22d60f00-3c27-4d21-9818-3260a74b0288%2cNorm_

Cmd=Sync&User=domain/user&DeviceId=androidc2023282223&DeviceType=Android&Log=V141_Fc1_Fid:12_Ty:Em_Filt5_St:S_Sk:871163472_Sst2_BR1_BPR0_LdapC1_RpcC20_Ers1_Pk4274541315_S1_As:AllowedG_Mbx:example.domain.local_Throttle0_Budget:(A)Conn%3a0%2cHangingConn%3a0%2cAD%3a%24null%2f%24null%2f0%25%2cCAS%3a%24null%2f%24null%2f1%25%2cAB%3a%24null%2f%24null%2f0%25%2cRPC%3a%24null%2f%24null%2f1%25%2cFC%3a%24null%2f0%2cPolicy%3aDefaultThrottlingPolicy%6F22d60f00-3c27-4d21-9818-3260a74b0288%2cNorm_
These sorts of URIs are quite a challenge for most parsers. Luckily, the more surprises in raw data, the more benefit from SpectX.  Here's  a full IIS/Exchange log pattern, including an XFF field, to be used with SpectX (copy from GitHub and paste into the SpectX parser window). Follow the steps below to match the pattern to your data.

First, make sure the client IP is useful

Before digging into IIS logs, it's worthwhile to take a closer look at the client IP address field. If a proxy or a load balancer has been set up in front of the mail server, the client IP field in the IIS logs simply “reveals” the IP of that proxy server.  If this is the case, enabling the X-Forwarded-For (XFF) header in the proxy or LoadBalancer is the way to start logging the data you need to analyze user activities. To do this:

1. Check the proxy or load balancer documentation for enabling XFF.
2. Once enabled, include the XFF header in the IIS logs - here's a good tutorial.

Process the IIS logs with SpectX

Once the logs are set, and the client IP is an external one, it’s SpectX’ turn to help you parse and query the logs. To do this:

1. Download SpectX
2. Create a datastore for the IIS log source. If they're in the IIS server, map the folder to your machine. 
3. Open the Input Data browser
4. Navigate to an IIS log file and click on 'Prepare Pattern'
5. Paste the IIS pattern for Exchange into the pattern editor. A sample of your data is displayed in the bottom section and the data should be highlighted to indicate successfully matched records.  If the pattern we've prepared doesn't light up the data, take a closer look at the fields in the raw data - there might be additional fields you need to comment out with '//' 
5. Click on Prepare Query

Queries

Finally, the fun bit. Here are a dozen sample questions-queries you could ask from the mail server to see what the users have been up to and if there are any anomalies in the activities.  Paste these queries at the end of the existing script. Use an asterisk in the file path to query multiple log files.

1. Activities of the user 'foo' during a specific time period
// Enter this line after the LIST and before the PARSE command to limit the search to recent files (see the screenshot below)
| filter(last_modified > now()[-14 day])

//Enter this line after the PARSE command
| filter(cs_username = '%foo%')
2. The number of successful and unsuccessful requests in hourly intervals. Press on 'Chart' to see the trends on a graph.
| select(date_time,all:count(sc_status),ok:count(sc_status < 400),error:count(sc_status >= 400))
| group(date_time[1 hour])
3. How many daily hits are there from the user 'bar'?
| select(time: date_time[1 d], Bar_hits:count(cs_username='bar'))
| group(time)
| sort(time) 
4. From how many IPs have the users connected to the server? Include a list of those IPs in an array. 
| filter(cs_username IS NOT NULL)
| group(lower(cs_username),c_ip)
| select(ip_count:count(*),username:lower(cs_username),IPs:ARRAY_AGG(c_ip))
| group(username)
| sort(ip_count DESC)
5. How many users have connected from a specific IP? Include the list of users (in an array) that have connected from those IPs.
| filter(cs_username != 'null')
| select(count:count(*),*)
| group(c_ip,lower(cs_username))
| select(users:ARRAY_AGG(cs_username),users_count:count(*),c_ip,cc(c_ip))
| group(c_ip)
| sort(users_count DESC)
| filter(users_count > 1)
6. What are the top devices of the users?
| select(*,parse("KVP{LD:key '=' LD:value ('&'| EOS)}:KVP", cs_uri_query))
| select(count(*),DeviceType:KVP[DeviceType])
| group(DeviceType)
| sort(count desc)
7. Users that are locked out or have their password expired
| filter(sc_win32_status = 1909L OR sc_win32_status = 1330L)
8. How many times has a user entered a wrong password or username? When did they do it for the first and last time? Aggregate (group) by the user and their user agent.
| filter(sc_win32_status = 1326L)
| select(count(*),c_ip,first_time:min(date_time),last_time:max(date_time),cs_username,cs_user_agent)
| group(cs_username,cs_user_agent)
| sort(count desc)
9. What are the top countries that the user IPs are coming from?
| select(count(*),cc(c_ip))
| group(cc)
| sort(count desc)
10. What are the hourly dynamics of hits compared to users from the US, Canada, and the UK?
| select(time: date_time[1 h], total:count(*),US:count(cc(c_ip)='US'), CA:count(cc(c_ip )='CA'), GB:count(cc(c_ip )= 'GB'))
| group(time)
| sort(time)
11? What are the top user agents?
| select(count(*),cs_user_agent )
| group(cs_user_agent)
12. Show the top list of URIs with error code 400 or higher
| filter(sc_status >= 400)
| select(count(*),cs_uri_stem,sc_status,*)
| group(cs_uri_stem,sc_status)
| sort(@1 DESC)
13. Amount of URIs returning an error code vs URIs returning an OK status code.
| select(date_time,all:count(sc_status),ok:count(sc_status < 400),error:count(sc_status >= 400))
| group(date_time[1 hour])

Conclusion

These queries are just the tip of the iceberg. SpectX gives you very advanced options for parsing the data and playing with the queries, including the ability to join the results with other sources e.g. a list of malicious IPs or TOR exit nodes. Got feedback or questions? Join the SpectX Slack community to ask advice from other SpectX users on getting the most out of the Exchange logs.f

Back to articles