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.

3 comments:

Bembeng Arifin said...

Hi,
I'm also interested in fire n forget pattern and I found your excellent article.
And the result is as expected, the code executes very fast since it will be asynchronous call without callback.

However, have u tried to observe the garbage collector when running this?

I created a simple console application which does a 1000 loop calling the method writing into a file with the code, you can see the result below :

Synchronous Call
Allocated bytes: 10,336,218
Relocated bytes: 40,036
Final Heap bytes: 2,008,143
Objects finalized: 0
Critical objects finalized: 0
Gen 0 collections: 4
Gen 1 collections: 0
Gen 2 collections: 0
Induced collections: 0
Gen 0 Heap bytes: 2,098,534
Gen 1 Heap bytes: 40,984
Gen 2 Heap bytes: 12
Large Object Heap bytes: 12,896
Handles created: 32
Handles destroyed: 0
Handles surviving: 32
Heap Dumps: 0
Comments: 0

Asynchronous Call
Allocated bytes: 8,769,664
Relocated bytes: 2,040,726
Final Heap bytes: 1,439,307
Objects finalized: 164
Critical objects finalized: 95
Gen 0 collections: 4
Gen 1 collections: 1
Gen 2 collections: 0
Induced collections: 0
Gen 0 Heap bytes: 2,141,790
Gen 1 Heap bytes: 1,042,836
Gen 2 Heap bytes: 856,124
Large Object Heap bytes: 18,096
Handles created: 1,269
Handles destroyed: 767
Handles surviving: 502
Heap Dumps: 0
Comments: 0

It seems that more objects in Gen 1 and 2 heap bytes when using Asynchronous call. Is this a normal behavior because there are other objects being used in the asynchronous call?
Correct me if I'm wrong, the objects will persist in the ASP.net worker process or the host application process until the host process is recycled or reach a max threshold.

Can you share your opinion on this?
Thanks.

S3 Technology Softwares said...

wow ur results are really incredible!
Every thing has a greater higher than sync.. process ...

And in async.. its creating 165 obj compared to sync with handles of 1,269 ..

Thats y using so much objects and bytes it makes ur job done quickly ..

Sudip Banerjee said...

Nice post. Web Design Company India