5
\$\begingroup\$

I have a bit of code that came from Egg Head Cafe a long while ago and it's been working great. But I ran the entire site through Redgate's Profiler. and it came up as the biggest hot spot in my code. (Honestly it ran so hot the rest of my site hardly spiked.) The point of it is to capture traffic into my site and filter out crawler traffic if it's needing to be blocked. It's worked greatly for years and I'm wanting to reuse it, but hoping it can be optimized a bit.

Starts out in the Global.asax:

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

This moves into the Logger class. Not the real name, just changed for the post.

public class Logger
{
    private static string _conn = ConfigurationManager.AppSettings["MyDatabase"];
    private static bool _denyBots = false;

    private static void DenyAccess(HttpApplication app)
    {
        app.Response.StatusCode = 0x191;
        app.Response.StatusDescription = "Access Denied";
        app.Response.Write("401 Access Denied");
        app.CompleteRequest();
    }


    public static bool IsCrawler(HttpRequest request)
    {
        bool isCrawler = request.Browser.Crawler;
        if (!isCrawler)
        {
            Regex regEx = new Regex("Slurp|slurp|ask|Ask|Teoma|teoma");//shortened
            isCrawler = regEx.Match(request.UserAgent).Success;
        }
        return isCrawler;
    }

    public static void LogRequest(HttpApplication app)
    {
        HttpRequest request = app.Request;

        bool isCrawler = IsCrawler(request);
        string userAgent = request.UserAgent;
        string requestPath = request.Url.AbsoluteUri;
        string referer = (request.UrlReferrer != null) ? request.UrlReferrer.AbsoluteUri : "";
        string userIp = request.UserHostAddress;
        string isCrawlerStr = isCrawler.ToString();

        object[] parms = new object[] { userIp, userAgent, requestPath, referer, isCrawlerStr };
        try
        {
            ThreadUtil.FireAndForget(new ThreadUtil.InsertOrUpdateDelegate(ThreadUtil.InsertLog), 
                new object[] { _conn, "insertRequest", parms });
        }
        catch (Exception ex)
        {
            app.Response.Write(ex.Message);
        }

        if (isCrawler && _denyBots)
            DenyAccess(app);

    }
}

And the actual threading code:

public class ThreadUtil
{
    private static AsyncCallback callback = new AsyncCallback(ThreadUtil.EndWrapperInvoke);
    private static DelegateWrapper wrapperInstance = new DelegateWrapper(ThreadUtil.InvokeWrappedDelegate);

    private static void EndWrapperInvoke(IAsyncResult ar)
    {
        wrapperInstance.EndInvoke(ar);
        ar.AsyncWaitHandle.Close();
    }

    public static void FireAndForget(Delegate d, params object[] args)
    {
        wrapperInstance.BeginInvoke(d, args, callback, null);
    }

    private static void InvokeWrappedDelegate(Delegate d, object[] args)
    {
        d.DynamicInvoke(args);
    }

    public static void InsertLog(string conn, string proc, object[] parms)
    {
        SqlHelper.ExecuteNonQuery(conn, proc, parms);
    }

    private delegate void DelegateWrapper(Delegate d, object[] args);

    public delegate void InsertOrUpdateDelegate(string conn, string proc, object[] parms);
}

The stored procedure is going to be replaced with just a parameterized SQL insert. Maybe this is fine and it's just the profiler having issues with it as it was a couple years ago. Liek I said it's worked fine for me this long, but it just seems like it can be better. Also the title might be terrible, I suck at titling.

Edit: Thinking about it this morning I'm thinking maybe the Application_PreRequestHandlerExecute is blocking causing a wait before the new thread is fired off which might be why the profilier had such an issue with it? Maybe someone could chime in on that. Also note that the code that was profilied was running under a URL rewriter so all requests are being handled by ASP.NET so each actual page being loaded could cause this code to execute anywhere from once to 30 times or more if there are many images or scripts loading on the page.

Edit: Ran it through ANTS again and found the following hot spots:

public static void LogRequest(HttpApplication app)
{
    ...
    bool isCrawler = IsCrawler(request);
    string requestPath = request.Url.AbsoluteUri;
    ...
    string userIp = request.UserHostAddress;
    ...
    ThreadUtil.FireAndForget(new ThreadUtil.InsertOrUpdateDelegate(ThreadUtil.InsertLog),
                    new object[] { _conn, "insertRequest", parms });
    ...
}

public static void FireAndForget(Delegate d, params object[] args)
{
    wrapperInstance.BeginInvoke(d, args, callback, null);
}

The two main offenders are string requestPath = request.Url.AbsoluteUri; and wrapperInstance.BeginInvoke(d, args, callback, null);

\$\endgroup\$
  • 1
    \$\begingroup\$ StatusCode = 0x191? You think in HEX? \$\endgroup\$ – Anton Gogolev Sep 8 '11 at 8:17
  • \$\begingroup\$ Haha. No that was part of the original code. I know nothing of hex in all honesty, I've just never had something that needed it. I'm sure I will at some point. \$\endgroup\$ – Tim Meers Sep 8 '11 at 10:45
  • 1
    \$\begingroup\$ Is the profiler eluding to the hot spot being within the ThreadUtil, the LogRequest or the regex within IsCrawler? Hopefully it gives you more granular detail. \$\endgroup\$ – Art Lucia Sep 13 '11 at 13:43
  • \$\begingroup\$ It was pointing to LogRequest(HttpApplication app). Thats as far as it dug into it from what I remember. \$\endgroup\$ – Tim Meers Sep 13 '11 at 19:28
  • \$\begingroup\$ What's your priority? Overall CPU load or time in the main page render thread? \$\endgroup\$ – Peter Taylor Sep 17 '11 at 9:39
5
\$\begingroup\$

The BeginInvoke() call is a hotspot because it will need a thread from the thread pool (and when there are too many used, it will wait for one to be available).

As a micro-optimization, try replacing that with ThreadPool.QueueUserWorkItem and measuring again, but in the end you're starting one (or more) sql insert query per request, that will use some resources no matter what is the async approach you use.

You could also use SqlCommand's BeginExecuteNonQuery / EndExecuteNonQuery to do your inserts async (instead of BeginInvoke / EndInvoke or the ThreadPool), but in the end the fastest solution involves not doing the insert to db per request, just write the needed stuff to some kind of queue (preferably one faster than the db) and insert to the db at a later time.

\$\endgroup\$
  • 1
    \$\begingroup\$ I push messages to MSMQ and then I have a task that runs every 1 minute and does a bulk insert into the data base. This has worked very well for us. MSMQ pushes are extremly fast. I'm very fond of this approach when it's silly things like logging/tracking/analytics, especially when every ms counts. \$\endgroup\$ – DustinDavis Dec 19 '11 at 23:03
3
\$\begingroup\$

Looks sharp to me. I'd do a little bit of declarative intent:

public static class Logger
{
    private static readonly string _conn = ConfigurationManager.AppSettings["MyDatabase"];
    private const bool _denyBots = false;

    private static void DenyAccess(HttpApplication app)
    {
        app.Response.StatusCode = 0x191;
        app.Response.StatusDescription = "Access Denied";
        app.Response.Write("401 Access Denied");
        app.CompleteRequest();
    }


    public static bool IsCrawler(HttpRequest request)
    {
        bool isCrawler = request.Browser.Crawler;
        if (!isCrawler)
        {
            Regex regEx = new Regex("Slurp|slurp|ask|Ask|Teoma|teoma");//shortened
            isCrawler = regEx.Match(request.UserAgent).Success;
        }
        return isCrawler;
    }

    public static void LogRequest(HttpApplication app)
    {
        HttpRequest request = app.Request;

        bool isCrawler = IsCrawler(request);
        string userAgent = request.UserAgent;
        string requestPath = request.Url.AbsoluteUri;
        string referer = (request.UrlReferrer != null) ? request.UrlReferrer.AbsoluteUri : string.Empty;
        string userIp = request.UserHostAddress;
        string isCrawlerStr = isCrawler.ToString();

        object[] parms = new object[] { userIp, userAgent, requestPath, referer, isCrawlerStr };
        try
        {
            ThreadUtil.FireAndForget(
                new ThreadUtil.InsertOrUpdateDelegate(ThreadUtil.InsertLog),
                new object[] { _conn, "insertRequest", parms });
        }
        catch (Exception ex)
        {
            app.Response.Write(ex.Message);
        }

        if (isCrawler && _denyBots)
            DenyAccess(app);
    }
}

and

public static class ThreadUtil
{
    private static readonly AsyncCallback callback = EndWrapperInvoke;
    private static readonly DelegateWrapper wrapperInstance = InvokeWrappedDelegate;

    public delegate void InsertOrUpdateDelegate(string conn, string proc, object[] parms);

    private delegate void DelegateWrapper(Delegate d, object[] args);

    public static void FireAndForget(Delegate d, params object[] args)
    {
        wrapperInstance.BeginInvoke(d, args, callback, null);
    }

    public static void InsertLog(string conn, string proc, object[] parms)
    {
        SqlHelper.VinManager.ExecuteNonQuery(conn, proc, parms);
    }

    private static void EndWrapperInvoke(IAsyncResult ar)
    {
        wrapperInstance.EndInvoke(ar);
        ar.AsyncWaitHandle.Close();
    }

    private static void InvokeWrappedDelegate(Delegate d, object[] args)
    {
        d.DynamicInvoke(args);
    }
}
\$\endgroup\$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.