A Request Logger that Logs every request to site asynchronously

Question

I'm trying to log every request to my website (Asp.net mvc). for doing this, I Created a Global Filter Attribute that gather Information for log from current request. the main idea of doing this asynchronously is don't block my main application. and just log data silently. Every thing is going ok while I Set an Error logger to log errors when my action logger could not able to log a request.

code below is my filter

public class RequestLoggingAttribute : ActionFilterAttribute
{
    private readonly IActionLogService _actionLogService;
    public RequestLoggingAttribute(IActionLogService actionLogService)
    {
        _actionLogService = actionLogService;
    }

    public override void OnActionExecuting(ActionExecutingContext filterContext)
    {           
        //Run an async method here to log any data you need.
        Task.Run(() => GatherActionLog(filterContext)).ConfigureAwait(false); 

        base.OnActionExecuting(filterContext);           
    }

    private async Task GatherActionLog(ActionExecutingContext filterContext)
    {
        try
        {                                
            var httpContext = filterContext.RequestContext.HttpContext;
            var request = httpContext.Request;
            if (!request.Url.AbsoluteUri.Contains("elmah"))
            {
                var roles = ((ClaimsIdentity) httpContext.User.Identity).Claims
                    .Where(c => c.Type == ClaimTypes.Role)
                    .Select(c => c.Value).ToArray();

                var parameters = filterContext.ActionParameters.Select(x => new {x.Key, x.Value});
                var jsonParameters = Json.Encode(parameters);

                var actionLog = new ActionLog()
                {
                    Action = filterContext.ActionDescriptor.ActionName,
                    Controller = filterContext.ActionDescriptor.ControllerDescriptor.ControllerName,
                    DateTimeUTC = DateTime.UtcNow,
                    IpAddress = request.UserHostAddress,
                    UserName = httpContext.User.Identity.Name,
                    Request = request.Url.AbsoluteUri,
                    ComputerName = request.UserHostName,
                    UserRole = String.Join(",", roles),
                    UserAgent = request.UserAgent,
                    ClientLoggedInUser = request.LogonUserIdentity.Name,
                    HttpMethod = httpContext.Request.HttpMethod,
                    Parameters = jsonParameters,
                    BrowserName = request.Browser.Id,
                    BrowserVersion = request.Browser.Version
                };

                await _actionLogService.InsertAsync(actionLog);
            }
        }
        catch (Exception ex)
        {               
            Elmah.ErrorLog.GetDefault(filterContext.HttpContext.ApplicationInstance.Context).Log(new Elmah.Error(ex));

        }                       
    }
}

There are two errors with this approach in my Elmah's error list. as below:

First:

A second operation started on this context before a previous asynchronous operation completed. Use 'await' to ensure that any asynchronous operations have completed before calling another method on this context. Any instance members are not guaranteed to be thread safe.

Second:

Saving or accepting changes failed because more than one entity of type 'Domain.LogEntities.ActionLog' have the same primary key value. Ensure that explicitly set primary key values are unique. Ensure that database-generated primary keys are configured correctly in the database and in the Entity Framework model. Use the Entity Designer for Database First/Model First configuration. Use the 'HasDatabaseGeneratedOption" fluent API or 'DatabaseGeneratedAttribute' for Code First configuration.

Domain Class for ActionLog is as below:

public class ActionLog
{
    public Guid ActionLogId { get; set; }
    public string UserRole { get; set; }
    public string UserName { get; set; }
    public string ClientLoggedInUser { get; set; }
    public string UserFullName { get; set; }
    public DateTime DateTimeUTC { get; set; }
    public string Action { get; set; }
    public string Controller { get; set; }
    public string Request { get; set; }
    public string ComputerName { get; set; }
    public string IpAddress { get; set; }
    public string HttpMethod { get; set; }
    public string Parameters { get; set; }
    public string UserAgent { get; set; }   
    public string BrowserName { get; set; }
    public string BrowserVersion { get; set; }               
}

If it matters I used two database, One for my main application and second for logging (error and Request logging). so I have two Entity Framework DbContext in my DAL layer. one DbContext for application and second for logger. But I use a BaseRepository that accepts DbContext to work with. my call to BaseRepository is as below:

public class GenericRepository<T> : BaseRepository<T, ApplicationDbContext> where T : class
{
    public GenericRepository(ApplicationDbContext db)
        :base(db)
    {
    }

}

public class LoggerRepository<T> : BaseRepository<T, LoggerDbContext> where T : class
{
    public LoggerRepository(LoggerDbContext db)
        :base(db)
    {

    }
}

1) Is there a better way to this!? (I Don't want to change whole my code,just the better way that fits this approach)

2) How can I prevent the errors above?

Thank you

Answer 1

You can use Net.CrossCutting.RequestLogger nuget package. It helps you that logs each HTTP request includes response to the storage (DB or File for example).

Answer 2

Wish I had enough "Reputation" to add this to the comments. Anyway, ActionFilters are supposed to finish their jobs before the HTTP pipeline can move the request to the controller. Please have a look at this post.

You could send your logging details to a MQ (e.g., MSMQ running in a separate process) and let MQ talks to the DB so that your main application is not blocked.