Automating Logging of Security Failures in ASP.NET MVC

There are three main reasons for logging and tracing in applications:

  1. You need to log errors
  2. You need to track performance
  3. You need to track unusual system behaviour

I’m sure you can think of other reasons, but these cover most scenarios and it’s the latter that we’ll look at today, on day 22 of our advent calendar.

The idea of tracking unusual behaviour isn’t one you most often think of when logging, but it can be useful for identifying things such as users consistently forgetting password (we’ve all done it), or more worryingly, an attempt to hack into your system. A string of security failures in quick succession could identify something like a bot attempting to break in. Not only is this an issue you need to address for security reasons, but it could also impact the performance of your application. There are two things you’d want to track:

  1. Authentication Failures. This needs to track both the creation of accounts (if that is a public feature of your site) as well as failed login attempts.
  2. Authorisation Failures. This shows attempts to access parts of a site that the user isn’t allowed to access, and could show an attempt to find an unsecured page.

The first of these is a manual affair, where you’d add logging code to your actions (or business logic methods) that deal with the account logic. For example, a typical LogOn action could be:

public ActionResult LogOn(LogOnModel model, string returnUrl)
  if (ModelState.IsValid)
    if (Membership.ValidateUser(model.UserName, model.Password))
      // snip - code if the validation passes
        "The user name or password provided is incorrect.");
      <strong>Gibraltar.Agent.Log.Warning("Account", "User Validation", "Account validation for user '{0}' failed", model.UserName);</strong>

  // If we got this far, something failed, redisplay form
  return View(model);

The important thing here is the logging added on failure. You’ll now see any security failures as warnings in your Gibraltar logs. You could of course, use Error instead of Warning if you wanted.

The second issue, that of authorisation, can be done automatically, but requires code to plug into the automatic authorization system. One way to do this would be to create a new filter attribute that just checks if authorisation is granted and logs it if not, but this would require two attributes: The Authorize attribute and the logging one. A simpler solution is to create a new attribute that does both. For example:

public class AuthorizeAndLog : AuthorizeAttribute
  protected override bool AuthorizeCore(HttpContextBase httpContext)
    var authorized = base.AuthorizeCore(httpContext);

    if (!authorized)
      var userName = httpContext.User.Identity.IsAuthenticated
                     ? "anonymous"
                     : httpContext.User.Identity.Name;

      Gibraltar.Agent.Log.Warning("Security", "Authorization",
                "Authorization failure for " + userName);

    return authorized;

Now, instead of using the Authorize attribute, you use AuthorizeAndLog. Eg:

public ActionResult About()
  return View();

[AuthorizeAndLog(Roles = "Admin")]
public ActionResult SecretStuff()
  return View();

This performs exactly the same action as Authorize, but additionally logs any failures. So with a small amount of code, you can track security failures at different points in your application. Easy, isn’t it?

Related Posts

Loupe 4.5 Released with New Log Viewer for Web

Rapidly diagnose each error in any .NET application with our new Web Log Viewer and Exception root cause analysis, new in Loupe 4.5. New integration with Azure Service Bus and Azure Search enables full Loupe functionality without any Virtual Servers in Azure. Read more

Cloudflare Vulnerability Does Not Affect Us

The recently reported Cloudflare vulnerability where fragments of secure, encrypted user data could be exposed to a third party does not affect Gibraltar Software even though we use Cloudflare because we only route static content through the Cloudflare proxy for acceleration. Read more

We're out of our Last Data Center

Back in January of 2016 we decided to completely transition out of our data centers and into the cloud. On Sunday we finally shut down the last cluster of our hardware. Read more for how we did it and whether we would do it all over again if we had... Read more

Rock solid centralized .NET logging

Unlimited applications, unlimited errors, starting at $25/month