We all want to investigate the content of the requests between the browser and the server at some point. The most common way to do this is to open up the developer tools of the browser and look at the requests and responses there. However, recently we came across a situation where we cannot use the developer tools as we were developing for third party embedded browser.

For this reason we created an IHttpModule that is able to log all requests coming to the server and responses generated from the server. It saves this in a format that should be compatible with Microsoft’s SvcTraceViewer. I’m saying ‘should’, as I haven’t actually tested it with this tool. Instead, I’ve been using one of my own tools for SVC messagelogs for a long time.

Anyway, you can easily adjust this to your own needs.

RawHttpLogModule.cs

The most important file contains two classes. The module that inherits IHttpModule and an OutputFilterStream that is used to create a copy of the outgoing response. Most of the code has been reused from other solutions found on stackoverflow and the asp.net forum. The comments contain links to the original sources and authors.

Add a new file named RawHttpLogModule.cs with the following content:

#define TRACE
using System;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Text;
using System.Text.RegularExpressions;
using System.Web;
using System.Xml.XPath;

namespace Common.Logging
{
    /// <summary>
    /// Inspired and modified based upon: http://stackoverflow.com/questions/1038466/logging-raw-http-request-response-in-asp-net-mvc-iis7
    /// </summary>
    public class RawHttpLogModule : IHttpModule
    {
        private static readonly TraceSource Source = new TraceSource(typeof(RawHttpLogModule).FullName);

        public void Init(HttpApplication context)
        {
            context.BeginRequest += new EventHandler(HandleBeginRequest);
            context.EndRequest += new EventHandler(HandleEndRequest);
        }

        void HandleBeginRequest(object sender, EventArgs e)
        {
            HttpApplication app = sender as HttpApplication;

            // There's a known issue with ASP.NET's [Web|Script]Resource.axd. Don't apply a filter for these requests. See:
            // - http://forums.asp.net/t/1043591.aspx?bug+WebResource+axd+not+working+with+Response+Filter+set
            // - http://stackoverflow.com/questions/29006331/override-webresource-javascript-method-webform-initcallback
            if (app.Request.AppRelativeCurrentExecutionFilePath.EndsWith(".axd", StringComparison.OrdinalIgnoreCase))
                return;

            OutputFilterStream filter = new OutputFilterStream(app.Response.Filter);
            app.Response.Filter = filter;

            StringBuilder request = new StringBuilder();
            request.Append(app.Request.HttpMethod + " " + app.Request.Url);
            request.Append("\n");
            foreach (string key in app.Request.Headers.Keys)
            {
                request.Append(key);
                request.Append(": ");
                request.Append(app.Request.Headers[key]);
                request.Append("\n");
            }
            request.Append("\n");

            byte[] bytes = app.Request.BinaryRead(app.Request.ContentLength);
            if (bytes.Count() > 0)
            {
                request.Append(Encoding.ASCII.GetString(bytes));
            }
            app.Request.InputStream.Position = 0;

            Guid requestActivityId = Guid.NewGuid();
            app.Context.Items.Add("MyRequestActivityId", requestActivityId);
            WriteTraceData(requestActivityId, app.Request.HttpMethod + " " + app.Request.Url, "TransportReceive", request.ToString());
        }

        void HandleEndRequest(object sender, EventArgs e)
        {
            HttpApplication app = sender as HttpApplication;
            Guid? requestActivityId = app.Context.Items["MyRequestActivityId"] as Guid?;
            if (app != null && app.Response != null && app.Response.Filter != null && app.Response.Filter is OutputFilterStream)
            {
                StringBuilder response = new StringBuilder();
                response.Append(app.Response.Status);
                response.Append("\n");
                foreach (string key in app.Response.Headers.Keys)
                {
                    response.Append(key);
                    response.Append(": ");
                    response.Append(app.Response.Headers[key]);
                    response.Append("\n");
                }
                response.Append("\n");
                response.Append(((OutputFilterStream)app.Response.Filter).ReadStream());
                WriteTraceData(requestActivityId ?? Guid.Empty, string.Empty, "TransportSend", response.ToString());
            }
        }

        void WriteTraceData(Guid activityId, string url, string source, string data)
        {
            var template = @"<MessageLogTraceRecord Time=""{0}"" Source=""{1}"" xmlns=""http://schemas.microsoft.com/2004/06/ServiceModel/Management/MessageTrace"">
    <Addressing>
        <To><![CDATA[{2}]]></To>
        <Body><{3} /></Body>
        <ActivityId>{4}</ActivityId>
    </Addressing>
    <HttpRequest>
<![CDATA[
{5}
]]>
    </HttpRequest>
</MessageLogTraceRecord>";

            // Empty xml-tag is not allowed, so we set url to an underscore to indicate empty
            if (string.IsNullOrEmpty(url))
                url = "_";

            // Sanatize the ascii string, only allow 0x20-0x7E (space-~) and \r\n
            string asciiStr = Regex.Replace(data, @"[^\u0020-\u007E\u000A\u000D]", "?");

            // Format the XML
            var msg = string.Format(template,
                DateTime.Now.ToString("o"),
                source,
                url.Replace("]]>", "]]]]><![CDATA[>"),
                Regex.Replace(url, "[^\\w]", "_"),
                activityId,
                asciiStr.Replace("]]>", "]]]]><![CDATA[>"));

            // Log the message
            byte[] msgBytes = Encoding.ASCII.GetBytes(msg);
            using (var sr = new MemoryStream(msgBytes))
            {
                Guid oldGuid = Trace.CorrelationManager.ActivityId;
                Trace.CorrelationManager.ActivityId = activityId;
                Source.TraceData(TraceEventType.Information, 1, new XPathDocument(sr).CreateNavigator());
                Trace.CorrelationManager.ActivityId = oldGuid;
            }
        }

        public void Dispose()
        {
            //Does nothing
        }
    }

    /// <summary>
    /// A stream which keeps an in-memory copy as it passes the bytes through
    /// http://stackoverflow.com/questions/1038466/logging-raw-http-request-response-in-asp-net-mvc-iis7
    /// </summary>
    public class OutputFilterStream : Stream
    {
        private readonly Stream InnerStream;
        private readonly MemoryStream CopyStream;

        public OutputFilterStream(Stream inner)
        {
            this.InnerStream = inner;
            this.CopyStream = new MemoryStream();
        }

        public string ReadStream()
        {
            lock (this.InnerStream)
            {
                if (this.CopyStream.Length <= 0L ||
                    !this.CopyStream.CanRead ||
                    !this.CopyStream.CanSeek)
                {
                    return String.Empty;
                }

                long pos = this.CopyStream.Position;
                this.CopyStream.Position = 0L;
                try
                {
                    return new StreamReader(this.CopyStream).ReadToEnd();
                }
                finally
                {
                    try
                    {
                        this.CopyStream.Position = pos;
                    }
                    catch { }
                }
            }
        }


        public override bool CanRead
        {
            get { return this.InnerStream.CanRead; }
        }

        public override bool CanSeek
        {
            get { return this.InnerStream.CanSeek; }
        }

        public override bool CanWrite
        {
            get { return this.InnerStream.CanWrite; }
        }

        public override void Flush()
        {
            this.InnerStream.Flush();
        }

        public override long Length
        {
            get { return this.InnerStream.Length; }
        }

        public override long Position
        {
            get { return this.InnerStream.Position; }
            set { this.CopyStream.Position = this.InnerStream.Position = value; }
        }

        public override int Read(byte[] buffer, int offset, int count)
        {
            return this.InnerStream.Read(buffer, offset, count);
        }

        public override long Seek(long offset, SeekOrigin origin)
        {
            this.CopyStream.Seek(offset, origin);
            return this.InnerStream.Seek(offset, origin);
        }

        public override void SetLength(long value)
        {
            this.CopyStream.SetLength(value);
            this.InnerStream.SetLength(value);
        }

        public override void Write(byte[] buffer, int offset, int count)
        {
            this.CopyStream.Write(buffer, offset, count);
            this.InnerStream.Write(buffer, offset, count);
        }
    }
}

Note the #define TRACE on the first line of the file. This is intentional. The Source.TraceData method has a [Conditional("TRACE")] annotation, which means the method is only compiled and called when the TRACE constant is defined. In a webapplication, even when the TRACE constant is checked in the project properties, these methods are still filtered out. I’m not sure why and it seems like a bug.

Web.config

In the web.config file we’ll need to add the module and we’ll need to add the tracelistener, so that the output is actually saved to disk.

Within the configuration element, add or merge the following module:

  <system.webServer>
    <modules runAllManagedModulesForAllRequests="true">
      <add name="RawHttpLogModule" type="Common.Logging.RawHttpLogModule"/>
    </modules>
  </system.webServer>
  <system.diagnostics>
    <sources>
      <source name="Common.Logging.RawHttpLogModule" switchValue="Information">
        <listeners>
          <add name="messagelog" type="System.Diagnostics.XmlWriterTraceListener" initializeData="C:\Logfiles\MyMessageLog.svclog" traceOutputOptions="DateTime" />
        </listeners>
      </source>
    </sources>
    <trace autoflush="true"/>
  </system.diagnostics>

Read the .svclog file

All that remains is to start the application, create some requests and read the generated .svclog file. Here’s an example using my SvclogViewer tool:

Raw HTTP log in SvclogViewer

Hope this helps!

Advertisements