Wednesday, April 04, 2007 4:00 AM bart

Extending IIS 7.0 - Part 1: A simple HTTP logging module

Note: This post is part of the follow-up for the Developer & IT Pro Days 2007 session entitled "Internet Information Services (IIS) 7.0 - End-to-End Overview of Microsoft's New Web Application Server". Attendees will be able to download the slides and will get the video recording of the entire session as well. Using these posts, attendees should be capable of reproducing the entire demo part of the session. Furthermore, others who didn't attend the session will be able to get a better idea of what IIS 7.0 provides by following the demo steps outlined in these posts. In order to implement the demos, one should have IIS 7.0 installed on Windows Vista (or Windows "Longhorn" Server).



One of the most exciting pillars of IIS 7.0 is its extensibility mechanism. In the dark ages of IIS 5.0 and IIS 6.0 (not to speak about the stone ages of IIS 4.0) the story around extensibility wasn't particularly good. As the matter in fact, there was the (difficult) world of ISAPI for unmanaged code developers, while managed code developers were rather limited in their extensibility capabilities, living in their ASP.NET stack.

Let's explain the extensibility pain in IIS 6.0 in some more detail, by looking at the HTTP pipeline:


What you're looking at is the pipeline that lives in a worker process of the web server. Requests come in at the very left bottom corner of the image, flowing through the unmanaged code stack on the left. Upon receival of a request, it passes the ISAPI filters, on to various "modules" for logging, custom errors, etc finally reaching the determine handler stage. In there, the extension of the request (more or less) is inspected to find out the party responsible for further request processing. Assume for now that the extension is .aspx, causing the web server to load the ISAPI for ASP.NET which is implemented in aspnet_isapi.dll (recall the aspnet_regiis.exe /i stuff used to register ASP.NET with the IIS server, which creates these mappings). Now we're on the right-hand side of the picture, having the request flow through a series of managed code HTTP modules (implementing IHttpModule) that have indicated their interest in certain events (like Begin_Request). Again, we reach a phase where the request is mapped on to an appropriate handler, which happens to be PageHandler in case of .aspx requests, effectively serving the request and generating a reponse. Finally, the response flows through the inverse path, back to managed code HTTP modules, on to the left-hand side again, flowing through module stuff in IIS and ISAPI filters.

So, what are our conclusions? A few observations:

  1. ASP.NET copies the concept of an HTTP pipeline (redundancy?) but makes it available to managed code developers.
  2. IIS doesn't know about managed code, aspnet_isapi.dll does. If a request is not mapped to the ASP.NET ISAPI dll, managed code is out of commission when extending the server.
  3. Two pipelines are chained serially.

IIS 7.0 gets rid of this problem by making managed code and unmanaged code extensibility both first class citizens in the web server. This is achieved by means of a so-called unified pipeline, as illustrated below:

In the center of the slide, you can see the unified pipeline implemented in the core IIS 7.0 web server engine. This pipeline has intrinsic knowledge of both native modules as well as managed code IHttpModule modules. At any stage of the pipeline, any kind of module can be invoked to do some processing (like logging, authentication and authorization assistance, caching, etc). Finally, when we reach the execute handler stage, mapping on an appropriate handler - native or managed - is performed in order to finalize the request processing. Notice that ASP.NET is no longer registered as a separate ISAPI with the web server, it has become an intimate friend of IIS 7.0 :-).


A simple logger

Time for the demo; let's create a simple logging module using managed code.

  1. Go to the desktop, right click and choose Add, New Shortcut. Specify explorer.exe, click Next, supply Windows Explorer as the name and click Finish. Now right click the newly created shortcut, choose Properties and go to Shortcut, Advanced... to enable Run as administrator:

    Hit OK twice.
  2. Open the Windows Explorer using the shortcut created in step 1, supply administrator credentials or give your consent and go to %SystemDrive%\inetpub\wwwroot and create a new subfolder called "devdays".
  3. Convert the folder to an IIS web application by opening the IIS Manager via WIN-R, inetmgr, OK and passing the security dialog. In IIS Manager, go to Web Sites, Default Web Site, right-click devdays and choose Convert to Application:


    In the dialog that appears, accept default values and hit OK:

  4. Launch Microsoft Visual Studio 2005 from the start menu and run it as an administrator too:

  5. Choose File, New, Web Site... and select the ASP.NET Web Site template from the dialog. Supply the local path to the inetpub\wwwroot\devdays folder created in step 2 and hit OK:

  6. Open Default.aspx in Design view and add the text "Hello DevDays!" to the page; boost the font to 36pt, make it bold and set the color to red:

  7. In Solution Explorer, right click on the devdays project and choose Add New Item... Select the HTML Page template, call it Static.htm and press OK:

  8. Copy the text from Default.aspx to the Static.htm designer view and change the color to blue:

  9. Go to the Solution Explorer, right click the devdays project and choose Start Options... In the dialog box, change the Server section to "Use custom server" and specify http://localhost/devdays for the Base URL. Disable the ASP.NET debugger under the Debuggers section. Click OK.

  10. Test the website by pressing CTRL-F5. Requests to both default.aspx and static.htm should be served fine by IIS 7.0:

  11. Close the browser and go back to Visual Studio 2005. On the devdays project, right click and choose Add New Item... This time, choose the Class template and specify HttpLogger.cs as its name:


    Press Yes to confirm putting the class file in a folder called App_Code automagically:

  12. In App_Code/HttpLogger.cs, get rid of the unneeded imports on top of the class file, so that only the following remains:
    using System; using System.Web;

  13. Next, implement the IHttpModule interface, like this:

  14. Get rid of the throw statement inside Dispose().
  15. In Init, register your interest in receiving events for the BeginRequest pipeline event, as follows:


    Press TAB twice to implement the handler method.
  16. Inside context_BeginRequest, add the following piece of code:
    HttpApplication app = sender as HttpApplication; if (app != null) { string path = app.Server.MapPath(String.Format("~/logs/{0:yyyyMMdd}.txt", DateTime.Now)); using (FileStream fs = File.Open(path, FileMode.OpenOrCreate | FileMode.Append, FileAccess.Write)) { using (StreamWriter sw = new StreamWriter(fs)) { sw.WriteLine("{0:HH:mm:ss} - {1}", DateTime.Now, app.Request.Url); } } }

    You'll need to import System.IO in order to have this piece of code compile. You can do so by clicking the red SmartTip that shows up when you click on e.g. FileStream:

    The piece of code shown above should be self-explanatory. However, a few little notes are well-placed:

    • The sender object parameter points to the HttpApplication object; it's a good style to use the as keyword and check for null in case something goes wrong (it shouldn't).
    • The string formatting using DateTime.Now uses MM for the 2-digits month representation; mm is used for minutes and thus not appropriate in here.
    • In order to point to the root location of the current application, ~ is used in the path. Thus, ~/logs will always refer to the logs folder directly underneath the application's root, even if you're making a request to e.g. http://localhost/devdays/subfolder/somefile.txt.
    • In case the log file doesn't exist yet, we'll create one; otherwise we'll append to the existing file.
    • Using blocks are used to dispose the resources correctly.
    • Inside the log file, we put the hour (using 24 hour notation by using HH instead of hh) as well as the request's URL. Additional information can be obtained via the Request object if you want to do so.
    • Notice that every request will cause the file to be opened and closed; more efficient alternatives might exist if you decide to create a production-ready logging mechanism. You might also consider to use a database engine to do the logging.
  17. Go to the solution explorer, right click the devdays project and choose Add New Item... once more. This time, we'll add a configuration file (web.config):

  18. In web.config, add the following to <system.web> like you used to do in the world of ASP.NET 2.0:
    <httpModules> <add name="Logger" type="HttpLogger" /> </httpModules>

    In here, the name is just a friendly name for our module, while the type points to the class implementing it. Since we're not using namespaces, the HttpLogger class name is sufficient; if we would use namespaces however, we'd have to specify the fully qualified type name including the entire namespace name.

  19. Hit CTRL-F5 to run the app without debugging; the following error message should appear in the browser:

    This message tells you that the use of the <system.Web>/<httpModules> section is deprecated when using the Integrated .NET mode that uses the integrated pipeline explained earlier in this post. This mode was chosen automatically when we converted the folder to an application in step 3, because DefaultAppPool was selected.
  20. First, we'll take a look at the old mechanism that mimicks the situation we were faced with in the IIS 6.0 ages, a.s.a. the Classic .NET mode in IIS 7.0 speak. In order to turn this mode on, we can do a couple of things. We could use the new appcmd.exe tool that comes with IIS 7.0 as explained in the browser window. Alternatively, you can use the IIS Manager too. Let's take the latter approach, so switch back to IIS Manager, right click the devdays application under Web Sites, Default Web Site and choose for Advanced Settings... this time:


    In the dialog's property grid, change the Application Pool setting:

    and select the Classic .NET AppPool like this:

    Notice that the properties below the dropdown list indicate that the Classic pipeline mode will be used (say, the serial chaining of the IIS pipeline and the ASP.NET pipeline). Hit OK twice.
  21. Go back to the browser and hit refresh. A File IO error will appear now:

    In order to fix this, go to the Windows Explorer instance you have running, open up the devdays folder and create a new folder called logs. Go to the properties of the folder by right clicking it, and select Security. Click Edit, Add, enter NETWORK SERVICE as the name of the user, click OK, and set the rights by clicking the Modify permission:

    Click OK twice.
  22. Go back to the browser and hit refresh. The request should be successful now. When you open the logs folder in Windows Explorer now, you should see a file named after the day/month/year you're running the demo, containing one line with the request information:

  23. Switch back to the browser and make a request to static.htm now; go back to the Windows Explorer window and observe that no line was added for the request to static.htm. This is because static files are served by IIS directly and in in Classic .NET Mode, our managed code logger module doesn't see the request at all. Only ASP.NET requests flow through the managed module at this time.
  24. Go back to IIS Manager and follow the same steps as outlined in step 20, now to switch the Application Pool for the devdays application back to the DefaultAppPool:

    Notice the pipeline mode now says Integrated. Click OK twice.
  25. When you hit refresh in the browser again, you'll see step 19's error message back. However, now we'll follow "step 1" as indicated in the error message, migrating our application to use the Integrated .NET mode. Again we could use appcmd.exe to do the migration (homework :-)), but we'll do it manually for now. To do so, go back to Visual Studio 2005 and open up the web.config file. Delete the section you've added in step 18 and add the following underneath <configuration>:
    <system.webServer> <modules> <add name="Logger" type="HttpLogger" /> </modules> </system.webServer>

    This configuration section tells the IIS 7.0 web server to load the managed-code module implemented in HttpLogger which it should find in the current application('s bin folder).

  26. Go back to IIS Manager and double-click the Modules icon in the devdays application features view:

    In here, you'll see our logging module being registered:

    This shows the configuration system of IIS 7.0 at work, as we'll outline in another post in this series coming up soon. Basically, the IIS Manager reflects the web.config settings. Alternatively, you could have added the module using the IIS Manager directly which would make the appropriate changes to web.config for you.

    (Optionally) Select Logger in the IIS Manager as shown above, click Remove in the Actions pane on the right and confirm by clicking Yes. Now choose Add Managed Module... from the Actions pane on the right and fill out the form like this:

    When you switch back to Visual Studio 2005, the IDE will tell that web.config was changed outside the editor (in this case, by IIS Manager):

  27. Go back to the browser and refresh the static.htm request. This time it should work fine. When you go back to the Windows Explorer window to take a look at the log text file, you'll see a line was added by the logger, this time for the static file request too:

You can download the sample code over here. Enjoy and stay tuned for the next parts in this series! | Digg It | Technorati | Blinklist | Furl | reddit | DotNetKicks

Filed under:


# Extending IIS 7.0 - Part 2: Developing an HTTP handler for image processing

Wednesday, April 04, 2007 4:12 AM by B# .NET Blog

Note: This post is part of the follow-up for the Developer &amp; IT Pro Days 2007 session entitled "Internet