Windows Azure makes it pretty easy to enable IIS logging for your web roles and the logs will periodically be transfered to a storage account so you can analyze them. A typical IIS installation will include some essential fields and administrators can add others if needed. However, Windows Azure enables all of the fields by default. Logging some fields like the cookie content can dramatically increase the size of your logs. For example, the asp.net authentication cookie is around 260 bytes and the request verification is over 500. With those you are nearing 1K in log data per request! Even if you aren’t using forms authentication, smaller cookies like those from analytics providers can add up quickly. Removing unnecessary fields is a simple way to cut the size of your logs.
As an aside, not only are these cookies expensive to log, they add overhead to every request your users make. Moving all your static resources to a CDN with a different domain (or sub-domain) helps because the cookies won’t be sent for those requests. Plus your users get faster responses because they are being served by the closest edge node instead of your web server.
OK, back to logging. Since Azure logs the cookies by default, how do we go back to the IIS defaults which don’t include cookies? My initial solution was to programatically change the settings during the role startup. Here is the code to do that:
using (ServerManager server = new ServerManager()) { // get the site's web configuration string siteNameFromServiceModel = "Web"; string siteName = String.Format( "{0}_{1}", RoleEnvironment.CurrentRoleInstance.Id, siteNameFromServiceModel); var site = server.Sites[siteName]; // update the logging fields for the site site.LogFile.LogExtFileFlags = LogExtFileFlags.Date | LogExtFileFlags.Time | LogExtFileFlags.ClientIP | LogExtFileFlags.UserName | LogExtFileFlags.ServerIP | LogExtFileFlags.Method | LogExtFileFlags.UriStem | LogExtFileFlags.UriQuery | LogExtFileFlags.HttpStatus | LogExtFileFlags.Win32Status | LogExtFileFlags.ServerPort | LogExtFileFlags.UserAgent | LogExtFileFlags.HttpSubStatus | LogExtFileFlags.TimeTaken; server.CommitChanges(); }
The downside of this approach is that you have to run the role with elevated permissions and include a reference to Microsoft.Web.Administration.dll. With the introduction of startup tasks, we can change the IIS logging settings outside the role process. The task has to be run using elevated privileges, but the role can run with the standard set of permissions. Read the MSDN docs and Steve Marx’s post if you are not already familiar with startup tasks.
In my initial attempt I created a simple task that ran synchronously to change the server-wide logging defaults before the role entry point. However, the Azure site configuration overrides the defaults when creating the site. So we need to modify the site settings using a background task. Background scripts can run in parallel with the Azure site configuration so its important to loop until the site has been created. The site name Azure uses is a combination of the web project name and the role instance id so the site name can’t be hardcoded in our script. We’ll take advantage of the fact that a standard Azure web role only has a single site and just modify the settings for all sites. To change the logging fields we’ll be using IIS’s appcmd tool. Appcmd is similar to powershell in that you can pipe the output of one command to another using the /xml and /in command line switches. If a site is modified it will output the following line:
SITE object "SITE_1_NAME" changed SITE object "SITE_2_NAME" changed SITE object "SITE_3_NAME" changed
If the site hasn’t been created by the Azure config script, then the output will be blank. So our batch file will pipe the output of appcmd to the FIND command which will look for the “SITE object” string. If it isn’t found then we’ll sleep for 10 seconds and then retry. Here is the full batch file:
@ECHO OFF echo Configuring IIS logging rem The set of fields that will be logged by IIS rem The logfields variable should be on a single line SET logfields=Date,Time,ClientIP,UserName,ServerIP,Method,UriStem,UriQuery, TimeTaken,HttpStatus,Win32Status,ServerPort,UserAgent,HttpSubStatus rem The appcmd executable SET appcmd=%windir%\system32\inetsrv\appcmd rem Retrieve all the sites, /xml flag allows output to be piped to next command SET getallsites=%appcmd% list sites /xml rem Set the logging fields for each site in the xml input (triggered by /in flag) SET setlogging=%appcmd% set site /in /logFile.logExtFileFlags:%logfields% rem Look for the string that indicates logging fields were set SET checkforsuccess=find "SITE object" :configlogstart %getallsites% | %setlogging% | %checkforsuccess% IF NOT ERRORLEVEL 1 goto configlogdone echo No site found, waiting 10 secs before retry... TIMEOUT 10 > nul goto configlogstart :configlogdone echo Done configuring IIS logging
NOTE: I broke the “SET logfields…” line for readability but it should be a single line in your batch file
Here is the list of available fields in IIS logging (look at the logExtFileFlags section) if you’d like to deviate from the normal IIS defaults.
Thanks so much for this post. One thing:
needed to add ” to SET appcmd=%windir%system32inetsrvappcmd
Otherwise it works great!
I’m very happy to remove ‘cookies’ from my list of logged fields.
@Adam – fixed, thanks for catching that!
Thanks Joel, that was very useful and clear.
Do you know if it is possible to add my own custom fields to the logs, such as the value of a variable in my C# code? Thanks very much.
@Trevor, I wish it were easier to do this. I usually try to push custom info into analytics which is a little easier. I know of a couple of options, but haven’t experimented with either of these myself.
1. HttpResponse.AppendToLog – appends a value to the querystring logged which just seems messy, unless you don’t already use querystrings.
http://msdn.microsoft.com/en-us/library/system.web.httpresponse.appendtolog(v=vs.110).aspx
2. Advanced Logging Module – I know this module can be used to log a wide range of request related data, but am not sure if you can log something truly custom.
http://learn.iis.net/page.aspx/579/advanced-logging-for-iis—custom-logging/
Let me know if you find a better alternative!
Thanks for the reply Joel. I’ve just decided not to pursue it: I came up with more than one good reason to log what I need elsewhere so hopefully I’ll never have to solve that one!
Is it ok to put c# code in OnStart() method of webrole?
I’ve done so, but have no result.
@Alex, if you go with the programatic method you have to make sure the role is running with elevated permissions.
Back when I was using that method, you had to add the following entry under WebRole in your csdef file:
<Runtime executionContext="elevated" />
I stopped using the programatic method once startup tasks were introduced. One of the big benefits with startup tasks is that you don’t have to run everything in elevated permissions. I’d encourage you to try that approach!