Pages

Advertisement

Sunday, August 5, 2007

ASP.NET Request Logging with Asynchronous Fire And Forget Pattern

Shows how to perform high-speed ASP.NET Request logging to a database using the asynchronous Fire and Forget delegate wrapper patterns.

"My analyst told me (what) that I was right out of my head the way he described it (how) he said I'd be better dead than live I didn't listen to his jive I knew all along he was all wrong and I knew that he thought (what) I was crazy but I'm not oh no oh no oh no" -- Lambert, Hendricks and Ross

In wiring up a recent article about Request Logging to feature a couple of tricks I've learned in my short happy career as a .NET programmer, I revisited the Fire And Forget pattern and decided to add this into my code to make it even faster.

Fire And Forget using a "self completing delegate wrapper" is something I first came across on Mike Woodring's page, and I've written about it several times here.  Jon Skeet also has an implementation, which I think is even "cleaner", and in my last article I used Jon's code, so I continue with that.

But I also like to "package up" commonly used utilities so that everything I need is in one class library. In this particular case, I have found that the most common usage of the Fire and Forget pattern, at least for me, is to execute insert or update stored procs in SQL Server.

The idea is that anytime you have an operation for which no explicit return value is required, especially if that operation is time consuming, you want to turn it from a blocking call, where you are waiting for it to complete before your code logic can continue, into a non-blocking "fire and forget" call that gets handled immediately  on a background thread, thus freeing your code to sail right on so there aren't any delays at all.

In a high-volume web application, you can probably think of several candidates for this pattern.

In order to do this "Packaging" I went back to the old standby, the v2 SqlHelper class.  I use this for two reasons: first, it has overloads that accept a connection string, a stored procedure name and a simple object array of the stored proc's parameter values, making it a great candidate for a fixed delegate signature.  Second, the SqlHelper class caches SqlParameters statically when you use these overloads, making it another order of magnitude faster for quick database access. In sum, the SqlHelper class remains one of those little gems of best - practices code that cannot be beat.

I don't know about you, but 95% of my data access is with SQL Server on applications where that's very unlikely to change, so you are going to have a real fight on your hands trying to convince me to get all RDBMS agnostic and go for the new "provider model" approaches that everyone is evangelizing, at least as far as database work is concerned. Not that I am against it, I already have used Enterprise Library 3.1 in production code. It's just that I believe in keeping things simple when possible.

The debate raged again recently on some blogs with Frans Bouma bellowing how "stored procs are evil". No, they aren't evil. And you also have triggers, and user-defined functions, and now CLR-hosting of .NET code with stored procs. There's absolutely no way you are going to get this kind of useful, RDBMS-specific functionality in some generic "Sql in the mapping class" approach. Sorry!
To make this work, all I had to add to Jon's excellent ThreadUtil class was the following:

// This is the "genericized" insert or update pattern delegate we use:
        // Our target method only needs a connection string, a stored proc name, and an object array of the parameter values.
        public delegate void InsertOrUpdateDelegate(string connectionString, string storedProcName, object[] parms);
 
        // This is the target method of our delegate. It simply calls SqlHelper.ExecuteNonQuery.
        // Since the whole idea here is "fire and forget", we do not need or want any return value.
        public static void PerformInsertOrUpdate(string connectionString, string storedProcName, object[] parms)
        {
            SqlHelper.ExecuteNonQuery(connectionString, storedProcName, parms);
        }

As can be seen, I have an InsertOrUpdateDelegate delegate whose signature exactly matches the following PerformInsertOrUpdate method, which simply makes the Sqlhelper call.

This does not have to be database access - you can use the identical pattern to do HttpWebRequest calls, fileSystem writes, and so on. The key determinant is that you do not need a return value; you want to Fire and forget in a non-blocking "handoff" method call that gets handled on a background thread.

In order to use this in the sample Request Logger, all I need to do is this:

In Global.asax:


protected void Application_PreRequestHandlerExecute (object sender, EventArgs e)
        {
            RequestLogger.Logger.LogRequest(sender as HttpApplication);
        }
 
In the RequestLogger class:
 
public static void LogRequest(HttpApplication app)
        {
            HttpRequest request = app.Request;
            EnsureSwitches(app);
            if (!_loggingOn) return;
            bool isCrawler = IsCrawler(request);
            string userAgent = request.UserAgent;
            string requestPath = request.Url.AbsolutePath;
            string referer = request.UrlReferrer != null ? request.UrlReferrer.AbsolutePath : "";
            string userIp = request.UserHostAddress;
            string isCrawlerStr = isCrawler.ToString();
            object[] parms = new object[] {userAgent, requestPath,referer, userIp, isCrawlerStr};
             try
             {
               ThreadUtil.FireAndForget(
                      new ThreadUtil.InsertOrUpdateDelegate(ThreadUtil.PerformInsertOrUpdate),
                        _connectionString, "dbo.insertRequest", parms);
            }
            catch (Exception ex)
            {
                // this is just for quick debugging, can be commented out:
                app.Response.Write(ex.Message);
            }
          
            if (isCrawler && _denyBots)
                DenyAccess(app);
        }

As you can see in the ThreadUtil.FireAndForget(... call above, because of the nice "packaging", the FireAndForget call could  be made with a single line of code, assuming you wanted to define your object[] parameter array inline. For a high-volume web application where you want to log information about every request, this is the way to absolutely speed up the operation! On an "average" machine, this arrangement will reliably queue up 100,000 such inserts in as little as 2.6 seconds total. Assuming those 100,000 operations were queued up all at once, they might take another full minute to complete and get into the database, but that's not your problem because your code is already free to go on and finish its business without delay. The key thing to understand is that your FireAndForget utility is handling the EndInvoke call for you and closing the WaitHandle to prevent leaks.

You can download the sample project which includes a SQL Script to generate the database table and sproc, along with all related code. As would be expected, you'll need to create a database or using an existing one and run the SQL Script, then adjust your connection string in web.config to match your environment.

ASP.NET Request Logger and Crawler Killer

Shows a simplified way to log requests and deny requests that come from <enter annoying bot name here>. Can easily be turned on or off with a database entry and without causing app recycle.

If you have ever had a web site that gets visited in the middle of peak hours by a nasty crawler / bot that doesn't completely observe the robots standard, tying up lots of your pages and causing humongous database access, then you know that you absolutely have to have good metrics to help identify the problem.
This is a simple logging class that:
1) Grabs key information from each request and logs it into a SQL Server table.
2) Can be programmed to identify certain "nastybots" via their User-Agent string and reply with a 401  Access Denied.
3) Can easily be turned on and off by simply updating a row in a SQL Server Database table, which will NOT cause an application restart.
The basic concept here is to try and intercept a request before Page processing and any database access has begun. The easiest way to do that is to override the Application_PreRequestHandlerExecute event. This is most easily done in Global.asax, where you can simply make a static class method call, like so:

protected void Application_PreRequestHandlerExecute (object sender, EventArgs e)
        {
            RequestLogger.Logger.LogRequest(sender as HttpApplication);
        }

When this call is made to the LogRequest method, it checks two private fields, _loggingOn, and _denyBots, and behaves accordingly. If _loggingOn is true, it grabs the items we want from the Request object and writes a row into your Requests SQL Table. The list I have is short, but you can add many more items if your needs differ.
If _denyBots is true, it performs an advanced "IsCrawler" check using Regex test strings of your choosing, and will issue a 401 Access Denied response, which basically stops the bot dead in its tracks, preventing it from doing any damage. Not even a Page object is created. 
The class self-populates the values of the two state variables through a method that checks the Cache and reloads from the database every 10 minutes. So you can change the state in the database, and be guaranteed that ten minutes later it will check and change state without recycling your app, as rewriting the web.config or other file might do.
Here's the code for the logging class:



using System;
using System.Configuration;
using System.Data;
using System.Data.SqlClient;
using System.Text.RegularExpressions;
using System.Web;
using System.Web.Caching;
 
namespace RequestLogger
{
    public static class Logger
    {
        private static bool _loggingOn=true;
        private static bool _denyBots=false;
        private static string _connectionString = ConfigurationManager.AppSettings["connectionString"];
 
        public static void LogRequest(HttpApplication app)
        {
            HttpRequest request = app.Request;
            EnsureSwitches(app);
            if (!_loggingOn) return;
            bool isCrawler = IsCrawler(request);
            string userAgent = request.UserAgent;
            string requestPath = request.Url.AbsolutePath;
            string referer = request.UrlReferrer != null ? request.UrlReferrer.AbsolutePath : "";
            string userIp = request.UserHostAddress;
            string isCrawlerStr = isCrawler.ToString();
 
            SqlConnection cn = new SqlConnection(_connectionString);
            SqlCommand cmd = new SqlCommand("dbo.insertRequest", cn);
            cmd.CommandType = CommandType.StoredProcedure;
            try
            {
                cmd.Parameters.AddWithValue("@UserAgent", userAgent);
                cmd.Parameters.AddWithValue("@RequestPath", requestPath);
                cmd.Parameters.AddWithValue("@Referer", referer);
                cmd.Parameters.AddWithValue("@RemoteIp", userIp);
                cmd.Parameters.AddWithValue("@IsCrawler", isCrawlerStr);
                cn.Open();
                cmd.ExecuteNonQuery();
            }
            catch (SqlException ex)
            {
                // this is just for quick debugging, can be commented out:
                app.Response.Write(ex.Message);
            }
            finally
            {
                cn.Close();
                cmd.Dispose();
            }
            if (isCrawler && _denyBots)
                DenyAccess(app);
        }
 
        private static void EnsureSwitches(HttpApplication app)
        {
            if (app.Context.Cache["_loggingOn"] == null)
            {
                SqlConnection cn = new SqlConnection(_connectionString);
                SqlCommand cmd = new SqlCommand("dbo.GetRequestLogState", cn);
                cmd.CommandType = CommandType.StoredProcedure;
                cn.Open();
                SqlDataReader rdr = cmd.ExecuteReader(CommandBehavior.CloseConnection);
                if (rdr.HasRows)
                {
                    rdr.Read();
                    _loggingOn = rdr.GetBoolean(0);
                    _denyBots = rdr.GetBoolean(1);
                }
                rdr.Close();
                cmd.Dispose();
                app.Context.Cache.Insert("_loggingOn", _loggingOn, null, DateTime.Now.AddMinutes(10),
                                         Cache.NoSlidingExpiration);
                app.Context.Cache.Insert("_denyBots", _denyBots, null, DateTime.Now.AddMinutes(10),
                                         Cache.NoSlidingExpiration);
            }
            else
            {
                _loggingOn = (bool) app.Context.Cache["_loggingOn"];
                _denyBots = (bool) app.Context.Cache["_denyBots"];
            }
        }
 
        private static void DenyAccess(HttpApplication app)
        {
            app.Response.StatusCode = 401;
            app.Response.StatusDescription = "Access Denied";
            app.Response.Write("401 Access Denied");
            app.CompleteRequest();
        }
 
 
        public static bool IsCrawler(HttpRequest request)
        {
            // set next line to "bool isCrawler = false; to use this to deny certain bots
            bool isCrawler = request.Browser.Crawler;
            // Microsoft doesn't properly detect several crawlers
            if (!isCrawler)
            {
                // put any additional known crawlers in the Regex below
                // you can also use this list to deny certain bots instead, if desired:
                // just set bool isCrawler = false; for first line in method 
                // and only have the ones you want to deny in the following Regex list
                Regex regEx = new Regex("Slurp|slurp|ask|Ask|Teoma|teoma");
                isCrawler = regEx.Match(request.UserAgent).Success;
            }
            return isCrawler;
        }
    }
}

Fire and Forget Fun: RPC Pings, GET, POST and more.

I've covered the asynchronous Fire and Forget pattern several times here and now I want to show a final usage pattern.

Most blogging APIs include the RPC Ping API to ping various RPC servers that you've updated your content. However, this works for any content, not just blog posts or changes in your RSS feed. So, if you have a forums app on your site, you can use it to ask the servers to revisit for a new forum post. Same with a new article, and so on.

Manyy of these RPC ping services have directories that they update. Weblogs.com even has a "rolling update" of links and you can download xml files of the most recent ping updates. A lot of this is legitimately indexed - which can result in increased traffic to your site. Some of it is just mindlessly populated with search results and other more or less "made for Adsense" bogus content, too.
The problem that often occurs with these RPC servers -- and often with many other types of "notification" URLS, be they GET or POST - is that this is a blocking call and you don't know how long it will take to return. For that matter, it might even time out, and in either case you don't want your web pages sitting around waiting, because that creates a really lousy user experience, making it seem like it is your site that is at fault.

So it's FIRE and FORGET to the rescue, once again!  What I've done here is to wrap up four different utility methods in the Fire and Forget idiom, all in a nice self-contained class library, all static methods.

All of these methods return immediately; they are not blocking calls:

1) RequestURL - makes a Fire and Forget GET request to any url with optional "stuff" on the querystring.
2) PostToUrl  - makes a Fire and Forget HTTP FORM POST to any url with optional querystring. You supply the FORM values in a NameValueCollection.
3) DoPingOMatic - makes a call to the popular Pingomatic.com service with your title and URL. Pingomatic takes care of the rest with its list of RPC servers.
4) DoPings - makes calls to a list of known RPC servers (which you can override with your own in an appSettings section).


In the sample web project that comes with this I also illustrate how to call the Yahoo API to ping the yahoo crawler as it requires a RESTful call which uses my RequestURL method.  There is also a CHM Help file for the library included in the /doc folder for the SearchPinger project.

Some sample usage code:

// you would need all three of the below lines to ping everthing including Yahoo:
           SearchPinger.ThreadUtil.DoPingOMatic(txtTitle.Text, txtUrl.Text);
           SearchPinger.ThreadUtil.DoPings(txtTitle.Text, txtUrl.Text);
          // Yahoo'a API wants a RESTful call which is essentially an HTTP GET, so here you are:

SearchPinger.ThreadUtil.RequestUrl

("http://search.yahooapis.com/SiteExplorerService/V1/ping?sitemap="+txtUrl.Text);

     
          // Sample of a fire and forget form  post:
          NameValueCollection nvc = new NameValueCollection();
          nvc.Add("Test", "form1value_1234");
          nvc.Add("Test2", "form2value_5678");

string targetUrl =

HttpContext.Current.Request.Url.OriginalString.Replace

(HttpContext.Current.Request.Url.LocalPath, "");

          SearchPinger.ThreadUtil.PostToUrl( targetUrl+"/Receiver.aspx", nvc);

 


And here is the SearchPinger class:



using System;
using System.Collections.Specialized;
using System.Configuration;
using System.Diagnostics;
using System.Net;
using System.Text;
 
namespace SearchPinger
{
    /// <summary>
    /// Provides threadsafe, non-blocking methods to make httpRequests using the Fire and Forget pattern
    /// <b>Usage:</b>
    ///<example> SearchPinger.ThreadUtil.DoPingOMatic(txtTitle.Text, txtUrl.Text);</example>
    /// <example>SearchPinger.ThreadUtil.DoPings(txtTitle.Text, txtUrl.Text);</example>
    /// <example>SearchPinger.ThreadUtil.RequestUrl(txtUrl.Text);</example>
    /// </summary>
    public static class ThreadUtil
    {
        // RPC Ping specification xml template
 
        #region Delegates
 
        public delegate void PingDelegate(string title, string url, string rpcServer);
 
        public delegate void PingOMaticDelegate(string title, string url);
 
        public delegate void PostUrlDelegate(string url, NameValueCollection postData);
 
        public delegate void RequestUrlDelegate(string url);
 
        #endregion
 
        /// <summary>
        /// Callback used to call <code>EndInvoke</code> on the asynchronously
        /// invoked DelegateWrapper.
        /// </summary>
        private static AsyncCallback callback = EndWrapperInvoke;
 
        private static string pingoMatic =
            "http://pingomatic.com/ping/?title=blogname&blogurl=bloggurl&rssurl=&chk_weblogscom=on&chk_blogs=on&chk_technorati=on&chk_feedburner=on&chk_syndic8=on&chk_newsgator=on&chk_feedster=on&chk_myyahoo=on&chk_pubsubcom=on&chk_blogdigger=on&chk_blogrolling=on&chk_blogstreet=on&chk_moreover=on&chk_weblogalot=on&chk_icerocket=on&chk_newsisfree=on&chk_topicexchange=on";
 
        private static string template =
            "<?xml version=\"1.0\"?><methodCall><methodName>weblogUpdates.ping</methodName><params><param><value>blogname</value></param><param><value>blogurl</value></param></params></methodCall>";
 
        /// <summary>
        /// An instance of DelegateWrapper which calls InvokeWrappedDelegate,
        /// which in turn calls the DynamicInvoke method of the wrapped
        /// delegate.
        /// </summary>
        private static DelegateWrapper wrapperInstance = new DelegateWrapper(InvokeWrappedDelegate);
 
        /// <summary>
        /// Pings list of RPC servers, optionally loading alternate list from comma-delimited appSettings section "rpcServers"
        /// </summary>
        /// <param name="title">The title.</param>
        /// <param name="url">The URL.</param>
        public static void DoPings(string title, string url)
        {
            //http://search.yahooapis.com/SiteExplorerService/V1/ping?sitemap=http://www.yahoo.com
            string servers = ConfigurationManager.AppSettings["rpcServers"];
            if (servers == null)
                servers =
                    "http://rpc.weblogs.com/RPC2,http://blogsearch.google.com/ping/RPC2,http://api.feedster.com/ping,http://api.moreover.com/RPC2,http://api.moreover.com/ping,http://api.my.yahoo.com/RPC2,http://ping.bloggers.jp/rpc/,http://ping.feedburner.com,http://ping.syndic8.com/xmlrpc.php,http://rpc.pingomatic.com,http://rpc.technorati.com/rpc/ping,http://www.blogoon.net/ping/,http://www.blogpeople.net/servlet/weblogUpdates,http://www.newsisfree.com/xmlrpctest.php";
 
            string[] rpcServerArray = servers.Split(',');
            foreach (string s in rpcServerArray)
            {
                FireAndForget(new PingDelegate(PingIt),
                              new object[] {title, url, s});
            }
        }
 
        /// <summary>
        /// Does the ping O matic call
        /// </summary>
        /// <param name="title">The title.</param>
        /// <param name="url">The URL.</param>
        public static void DoPingOMatic(string title, string url)
        {
            FireAndForget(new PingOMaticDelegate(PingOMatic),
                          new object[] {title, url});
        }
 
        /// <summary>
        /// Requests any URL, which can include a full querystring. Returns null.
        /// </summary>
        /// <param name="url">The URL.</param>
        public static void RequestUrl(string url)
        {
            FireAndForget(new RequestUrlDelegate(RequestAUrl), new object[] {url});
        }
 
        /// <summary>
        /// Posts NameValueCollection Data  to a URL. Url can also have a Querystring
        /// </summary>
        /// <param name="url">The URL.</param>
        /// <param name="postData">The post data.</param>
        public static void PostToUrl(string url, NameValueCollection postData)
        {
            FireAndForget(new PostUrlDelegate(PostToAUrl),
                          new object[] {url, postData});
        }
 
 
        private static void PostToAUrl(string url, NameValueCollection postData)
        {
            WebClient myWebClient = new WebClient();
            myWebClient.Headers.Add("Content-Type", "application/x-www-form-urlencoded");
            try
            {
                myWebClient.UploadValues(url, "POST", postData);
            }
            catch(Exception ex)
            {
                Debug.WriteLine("Post--" + ex.Message);
            }
            finally
            {
                myWebClient.Dispose();
            }
        }
 
 
        private static void RequestAUrl(string url)
        {
            WebClient reqWc = new WebClient();
            try
            {
             string s=   reqWc.DownloadString(url);
                System.Diagnostics.Debug.WriteLine(url + ": " + s);
            }
            catch (Exception ex)
            {
                Debug.WriteLine("pingomatic--" + ex.Message);
            }
            finally
            {
                reqWc.Dispose();
            }
        }
 
 
        private static void PingOMatic(string title, string url)
        {
            pingoMatic = pingoMatic.Replace("blogname", title).Replace("bloggurl", url);
            WebClient pingoWc = new WebClient();
            try
            {
                string pingoString = pingoWc.DownloadString(pingoMatic);
                Debug.WriteLine("pingomatic--" + pingoString);
            }
            catch (Exception ex)
            {
                Debug.WriteLine("pingomatic--" + ex.Message);
            }
            finally
            {
                pingoWc.Dispose();
            }
        }
 
        private static void PingIt(string title, string url, string rpcServer)
        {
            string postContent = template.Replace("blogname", title).Replace("blogurl", url);
            byte[] bytesToPost = Encoding.ASCII.GetBytes(postContent);
            WebClient wc = new WebClient();
            try
            {
                byte[] resultBytes = wc.UploadData(rpcServer, bytesToPost);
                wc.Dispose();
                string blah = Encoding.ASCII.GetString(resultBytes);
                Debug.WriteLine(rpcServer + "--" + blah);
            }
            catch (Exception ex)
            {
 
                Debug.WriteLine(rpcServer + "ERROR:  " + ex.Message);
            }
            finally
            {
                wc.Dispose();
            }
        }
 
        /// <summary>
        /// Executes the specified delegate with the specified arguments
        /// asynchronously on a thread pool thread.
        /// </summary>
        public static void FireAndForget(Delegate d, params object[] args)
        {
            // Invoke the wrapper asynchronously, which will then
            // execute the wrapped delegate synchronously (in the
            // thread pool thread)
            wrapperInstance.BeginInvoke(d, args, callback, null);
        }
 
        /// <summary>
        /// Invokes the wrapped delegate synchronously
        /// </summary>
        private static void InvokeWrappedDelegate(Delegate d, object[] args)
        {
            d.DynamicInvoke(args);
        }
 
        /// <summary>
        /// Calls EndInvoke on the wrapper and Close on the resulting WaitHandle
        /// to prevent resource leaks.
        /// </summary>
        private static void EndWrapperInvoke(IAsyncResult ar)
        {
            wrapperInstance.EndInvoke(ar);
            ar.AsyncWaitHandle.Close();
        }
 
        #region Nested type: DelegateWrapper
 
        /// <summary>    
        /// Delegate to wrap another delegate and its arguments
        /// </summary>
        private delegate void DelegateWrapper(Delegate d, object[] args);
 
        #endregion
    }
}