Troubleshooting Exchange with LogParser:IIS logs #1

This is the first part of a serie about troubleshooting Exchange using LogParser. I bet all of you know the situation, where users complain about connectivity issue. But how do you troubleshoot?

In this post I will cover how to parse IIS logs. There are a few great tools out there to parse those logs:

• Log Parser Studio 2.0
• Exchange ActiveSync troubleshoot script

But they have one big drawback in common:

You need to collect the logs from all servers into one place in order to parse them. If you have only 2-3 server that might me okay, but what when you have more than 10, 20 or 30 server? It also takes time to copy the logs depending on your settings what you are logging. Easily a log could be larger than 1GB.

Wouldn’t it be great to be able to parse the logs without the need of copying them?

Well here is the solution:

For this reason I wrote a script, which is able to get all Exchange server from AD and then parse the IIS logs directly from all the server. The script has the following parameters:

Parameter	Description
UserID	filter for a specific user. Cannot be combined with UserIDs,DeviceID or DeviceIDs
UserIDs	filter for multiple users. Cannot be combined with UserID,DeviceID or DeviceIDs
DeviceID	filter for a specific EAS device. Cannot be combined with UserID,UserIDS or DeviceIDs
DeviceIDs	filter for multiple EAS devices. Cannot be combined with UserID,UserIDS or DeviceID
StartDate	this is used for filtering the logfiles to be parsed. The format must be yyMMdd. If omitted current date will be used
EndDate	this is used for filtering the logfiles to be parsed. The format must be yyMMdd. If omitted current date will be used
LogParser	this is used for the path to LogParser.exe
ADSite	here you can define in which ADSite is searched for Exchange server. If omitted current AD site will be used
OutPath	where the output will be found. If omitted $env:temp will be used
LogFolders	which folders to parse. It must be an UNC path without the server name and could have multiple path comma deliminated
LogFolders2013	which folders to parse for Exchange 2013 server. It must be an UNC path without the server name and could have multiple path comma deliminated
EASReport	will generate a report based on the give script http://blogs.technet.com/b/exchange/archive/2012/01/31/a-script-to-troubleshoot-issues-with-exchange-activesync.aspx with some minor changes. Could be combined with UserID. Otherwise it will create a report for all devices
EASReportByDeviceType	will generate a report of Devicetypes
EASErrorReport	creates a report with all EAS errors. Could be combined with UserID
EASErrorReportByDeviceType	will generate a report of EAS errors grouped by DeviceType
HTTPReport	creates a report of all errors from the HTTPERR logs
ClientReport	creates a report of all clients and their hits. Note: It’s not the number of unique clients!
ClientBandwidth	creates several files, which could be used for bandwidth analysis. Note: Enhanced IIS logging must be enabled in order to get the transferred bytes (cs-bytes,sc-bytes)!
EASDetails	if used you will get much more details for EAS traffic. Good for troubleshooting EAS devices. Is set to $true by default when DeviceID or DeviceIDs are given
Localpath	if you have log files in a local folder.There is no filtering by date! All files will be analyzed!
SpecifiedServers	if you want to specify one or more server rather than retrieving from AD
AllextendedIISFields	enforce extended IIS log fields ‘[Bytes received]’,'[Bytes sent]’ and ‘Host’

Okay, this is a lot of parameters. I’m going to describe in this post how the script basically works and how to use this script to parse the logs for a single user/device or multiple users/devices.

Prerequisites

You will need the following in order to use the script successful:

• LogParser
• a server from where you will run the script. this server needs SMB access to all Exchange server as we will access the IIS logs via UNC path
• adjust the execution policy. Here is an example, which bypass the policy only for the running process:

  Set-ExecutionPolicy -Scope Process -ExecutionPolicy Bypass

• the script itself
• and of course permission to access the files on the servers via UNC path

How it works

The script uses this function to determine all the relevant Exchange servers from AD. Then it starts to build an array of paths, one path for each server. The default path for IIS logs is C:\inetpub\logs\LogFiles\. Exchange 2010 uses only one web side by default and the logs could be found in the subfolder W3SVC1. Due to the architectural change Exchange 2013 has by default an additional side and therefore an additional subfolder W3SVC2.

Just in case you change the default location for those folders you can define those paths for Exchange 2010 servers using the parameter LogFolders and for Exchange 2013 using the parameter LogFolders2013. Both parameters accept multiple paths comma seperated.

Now that we have all the paths we can filter the existing files. IIS logs have by default a filename format like u_exyyMMdd.log. The script uses this format to filter the files to be parsed. That’s why the parameters StartDate and EndDate have the format yyMMdd.

In case you have the files in a local folder you specify this folder with the parameter Localpath. If you use this parameter you won’t be ableto filter by StartDate and EndDate.

Next step would be to filter for one of the following objects:

• UserID,UserIDs when you provide one of this parameter (UserIDs must be comma seperated) the field cs-username is parsed. All matching entries will be returned. Normally it’s the samaccountname.
• DeviceID,DeviceIDs here you filter for one or multiple ActiveSync deviceids. The deviceid is different and you can extract it from the cs-uri-query. The script use the following function: EXTRACT_VALUE(cs-uri-query,’DeviceId’) AS EASDeviceId

If you query across multiple days you will get for each day a fil depending on your search criteria:

UserID	yyMMdd_Hits_by___.csv
UserIDs	yyMMdd_Hits_by___.csv
DeviceID	yyMMdd_Hits_by___.csv
DeviceIDs	yyMMdd_Hits_by___.csv

The files contain the following fields:

Field	Description
TimeUTC	timestamp
ServerIP	server, which served the request
ClientIP	client’s IP
User	user logged in cs-username
Client	User-Agent used
Request	cs-uri-steam
DeviceId	extracted DeviceID
HttpStatus	HTTP status combined with substatus
Win32StatusDescription	sc-win32-status converted with LogParser function WIN32_ERROR_DESCRIPTION
Time taken in MS	time-taken
Bytes received	cs-bytes if you have it enabled
Bytes sent	sc-bytes if you have it enabled
Host	cs-host if you have it enabled
RequestDetails	cs-uri-query

The following fields will be available only when you use the parameter EASDetails when you query for UserID/UserIDs. For DeviceID/DeviceIDs it’s enabled by default.

Field	Description
EASCmd	EAS command, which was issued
EASError	EAS error, which was reported
EASSyncType	what kind of synctype was issued (First,Subsequent,Recovery,Invalid)
EASStatus	returned status
EASABQStatus	status like Blocked or Allowed
EASSyncKey	used SyncKey
EASFolderType	FolderType like CA, CO or EM, which was used. Note:Only the first FolderType in the request will be returned!
EASFilter	for how long the specific folder data are requested
EASServerChanges	changes issued from server side
EASClientChanges	changes issued from client side
EASProxy	in case a request was proxied, data either from or to
EASPolicyKey	policy key
EASMBXServer	mailbox server
EASHeartBeat	used heartbeat
EASFolderCount	foldercount, which were used
EASFolderId	FolderID
EASRPCCount	count of RPC requests
EASRPCLatency	latency of RPC
EASLdapCount	count of LDAP requests
EASLdapLatency	latency of LDAP
EASLog	the complete extraced issued request

Note: There is an update for Exchange ActiveSync related data. Please read the following post:

Get-IISStats: Updated version available

How it looks in action

Lets say you want to extract all request for user Trick on a specific date. You would run the following command:

.\Get-IISStats.ps1 -UserID trick -Outpath C:\Tenp\Output -StartDate 141020 -EndDate 141020

Within this AD-site (HQ-Site) the script found 2 Exchange server. One Exchange 2010 (EX01) and one Exchange 2013 (EX02). The output is in the folder C:\Temp\Output.

Now you can import the file in Excel and analyze the requests

Now parse for the same user, but with the parameter EASDetails

.\Get-IISStats.ps1 -UserID trick -Outpath C:\Temp\Output -StartDate 141020 -EndDate 141020 -EASDetails

When you now open the output in Excel you will find a lot more columns, which are related to the ActiveSync requests

And here an example parsing for multiple devices

.\Get-IISStats.psl -Outpath C:\Temp\Output -StartDate 141020 -EndDate 141020 -DeviceIDs 695e14e34d4441d58fc43753069ec1c,cfe371b100d443e996621d90
b0bea27b

Here is the output

Note: When you have multiple AD-Sites and you proxy requests to some of them it might makes sense to use the DeviceID/DeviceIDs as filter as in those sites in cs-username the proxying server is logged.

I also have to warn you about the network usage. LogParser is really fast and depending of the number of servers and log files you are parsing it will use most of the bandwidth. The maximum usage I have seen in an environment with over 20 CAS server was approx. 70%.

By default the script is doing a lookup for the fields (cs-bytes,sc-bytes,cs-host) in one of the files found. Those fields are not logged by default. the script reads only the first line starting with #Fields to detect if those fields are logged. When you now enable logging for those fields and restart IIS the script won’t detect those fields for this day. Then you can use the parameter AllextendedIISFields to enforce parsing of those values.

This is one option to enable logging of those extended fields:

Import-Module WebAdministration
$IISLogging = Get-WebConfiguration -filter /system.applicationhost/sites/sitedefaults/logfile
If (!($IISLogging.logExtFileFlags.Contains('BytesSent')) -or !($IISLogging.logExtFileFlags.Contains('BytesR')) -or !($IISLogging.logExtFileFlags.Contains('Host'))) {
 Write-Output "Checking for BytesSent....`n"
 If (!($IISLogging.logExtFileFlags.Contains('BytesSent'))) {
 Write-Output "Adding BytesSent to logging....`n"
 $IISLogging.logExtFileFlags = $IISLogging.logExtFileFlags + ",BytesSent"
 }
 Write-Output "Checking for BytesRecv....`n"
 If (!($IISLogging.logExtFileFlags.Contains('BytesRecv'))) {
 Write-Output "Adding BytesRecv to logging....`n"
 $IISLogging.logExtFileFlags = $IISLogging.logExtFileFlags + ",BytesRecv"
 }
 If (!($IISLogging.logExtFileFlags.Contains('Host'))) {
 Write-Output "Adding Host to logging....`n"
 $IISLogging.logExtFileFlags = $IISLogging.logExtFileFlags + ",Host"
 }
 Write-Output "Write logging settings....`n"
 $IISLogging | Set-WebConfiguration -filter /system.applicationhost/sites/sitedefaults/logfile
}
Else {
 Write-Output "IIS logging is okay!`n"
}

Review

In this post I covered how to extract all entries for one or multiple users or devices directly from the servers without the need of copying all the logs.

In #2 I will cover more the analytic and statistical part you can do with this script.

Happy parsing!