Hosting Article

ByAlexia Pamelov

best and affordable asp.net 5 hosting, best windows hosting, cheap and affordable asp.net hosting, cheap asp.net hosting, cheap windows hosting

Cheap Windows Hosting – Entity Framework and handling Exceptions

CheapWindowsHosting.com | Cheap and affordable windows hosting. In this tutorial we will learn about Logging database operations in Entity Framework and handling Exceptions.

Entity Framework (EF) is an object-relational mapper that enables .NET developers to work with relational data using domain-specific objects. It eliminates the need for most of the data-access code that developers usually need to write.

If you are using the EF6 and want to log the database operations, analyze them, then, this is the right place for you.

When I was developing one WebApi project, what I was searching for is an output each query performed by Entity framework should be logged with time. Also, exception if there is any. So, in this section, you will learn how to log commands and queries to the database generated by Entity framework.

There are two ways using code

• Simple Method

using (MyDatabaseEntities context = new MyDatabaseEntities())
     {
         context.Database.Log = s => System.Diagnostics.Debug.WriteLine(s);
          // query the database using EF here.
      }

This will log the database operations in the output window. What it does is it writes the operations performed byEntityFramework to the output window. It gives awesome traces.

Have a look :

• IDbCommandInterceptor

This uses the IDbCommandInterceptor Interface. This is in-built in Entity framework 6.

Note: This is available in Entityframework 6 and later.

Interface looks like this:

namespace System.Data.Entity.Infrastructure.Interception
{
  /// <summary>
  /// An object that implements this interface can be registered with 
  /// <see cref="T:System.Data.Entity.Infrastructure.Interception.DbInterception"/> to
  ///             receive notifications when Entity Framework executes commands.
  /// 
  /// </summary>
  /// 
  /// <remarks>
  /// Interceptors can also be registered in the config file of the application.
  ///             See http://go.microsoft.com/fwlink/?LinkId=260883 
  ///             for more information about Entity Framework configuration.
  /// 
  /// </remarks>
  public interface IDbCommandInterceptor : IDbInterceptor
  {
    /// <summary>
    /// This method is called before a call to 
    /// <see cref="M:System.Data.Common.DbCommand.ExecuteNonQuery"/> or
    ///             one of its async counterparts is made.
    /// 
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">
    /// Contextual information associated with the call.</param>
    void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext);

    /// <summary>
    /// This method is called after a call to 
    /// <see cref="M:System.Data.Common.DbCommand.ExecuteNonQuery"/>  or
    /// one of its async counterparts is made. 
    /// The result used by Entity Framework can be changed by setting
    /// <see cref=
    /// "P:System.Data.Entity.Infrastructure.Interception.DbCommandInterceptionContext`1.Result"/>.
    /// 
    /// </summary>
    /// 
    /// <remarks>
    /// For async operations this method is not called until after the async task has completed
    ///             or failed.
    /// 
    /// </remarks>
    /// <param name="command">The command being executed.</param>
    /// <param name=
    /// "interceptionContext">Contextual information associated with the call.</param>
    void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext);

    /// <summary>
    /// This method is called before a call to 
    /// <see cref="M:System.Data.Common.DbCommand.ExecuteReader(System.Data.CommandBehavior)"/> or
    /// one of its async counterparts is made.
    /// 
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">Contextual information associated with the call.
    /// </param>
    void ReaderExecuting(DbCommand command, 
  DbCommandInterceptionContext<DbDataReader> interceptionContext);

    /// <summary>
    /// This method is called after a call to 
    /// <see cref="M:System.Data.Common.DbCommand.ExecuteReader(System.Data.CommandBehavior)"/> or
    /// one of its async counterparts is made. 
    /// The result used by Entity Framework can be changed by setting
    /// <see cref=
    /// "P:System.Data.Entity.Infrastructure.Interception.DbCommandInterceptionContext`1.Result"/>.
    /// 
    /// </summary>
    /// 
    /// <remarks>
    /// For async operations this method is not called until after the async task has completed
    ///             or failed.
    /// 
    /// </remarks>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">
    /// Contextual information associated with the call.</param>
    void ReaderExecuted(DbCommand command, 
    	DbCommandInterceptionContext<DbDataReader> interceptionContext);

    /// <summary>
    /// This method is called before a call to 
    /// <see cref="M:System.Data.Common.DbCommand.ExecuteScalar"/> or
    ///             one of its async counterparts is made.
    /// 
    /// </summary>
    /// <param name="command">The command being executed.</param>
    /// <param name="interceptionContext">
    /// Contextual information associated with the call.</param>
    void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext);

    /// <summary>
    /// This method is called after a call to 
    /// <see cref="M:System.Data.Common.DbCommand.ExecuteScalar"/> or
    /// one of its async counterparts is made. 
    /// The result used by Entity Framework can be changed by setting
    /// <see cref=
    /// "P:System.Data.Entity.Infrastructure.Interception.DbCommandInterceptionContext`1.Result"/>.
    /// 
    /// </summary>
    /// 
    /// <remarks>
    /// For async operations this method is not called until after the async task has completed
    ///             or failed.
    /// 
    /// </remarks>
    /// <param name="command">The command being executed.
    /// </param><param name="interceptionContext">
    /// Contextual information associated with the call.</param>
    void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext);
  }
}

Let’s derive this interface to the DatabaseLogger class.

FYI, I have added my log information into database. You may insert into file, Excel, anything you want.

You need not worry about the methods Interface itself is very self explanatory. It has 6 methods, which you can see I have derived and check comments to understand each scenario.

//this file is used to log the database operations it checks
//the query execution time and than insert if it takes more than one second.
 //to disable it remove its registry from TeamPassDbContext default constructor
 public class DatabaseLogger : IDbCommandInterceptor
 {
     static readonly ConcurrentDictionary<DbCommand,
     DateTime> MStartTime = new ConcurrentDictionary<DbCommand, DateTime>();

     public void NonQueryExecuted(DbCommand command,
     DbCommandInterceptionContext<int> interceptionContext)
     {
         //executed state
         Log(command, interceptionContext);
     }

     public void NonQueryExecuting(DbCommand command,
     DbCommandInterceptionContext<int> interceptionContext)
     {
         //executing state
         OnStart(command);
     }

     public void ReaderExecuted(DbCommand command,
     DbCommandInterceptionContext<DbDataReader> interceptionContext)
     {
         //reader executed state
         Log(command,interceptionContext);
     }

     public void ReaderExecuting(DbCommand command,
     DbCommandInterceptionContext<DbDataReader> interceptionContext)
     {
         //reader executing state
         OnStart(command);
     }

     private static void Log<T>(DbCommand command,
     DbCommandInterceptionContext<T> interceptionContext)
     {
         DateTime startTime;
         TimeSpan duration;
         //Removing from dictionary and calculating time
         MStartTime.TryRemove(command, out startTime);
         if (startTime != default(DateTime))
         {
             duration = DateTime.Now - startTime;
         }
         else
             duration = TimeSpan.Zero;

         const int requestId = -1;

         var parameters = new StringBuilder();
         foreach (DbParameter param in command.Parameters)
         {
             parameters.AppendLine(param.ParameterName + " " +
             param.DbType + " = " + param.Value);
         }

         var message = interceptionContext.Exception == null ?
         $"Database call took {duration.TotalSeconds.ToString("N3")} sec.
         RequestId {requestId} \r\nCommand:\r\n{parameters + command.CommandText}" :
         $"EF Database call failed after {duration.TotalSeconds.ToString("N3")} sec.
         RequestId {requestId} \r\nCommand:\r\n{parameters.ToString() +
         command.CommandText}\r\nError:{interceptionContext.Exception} ";

         //Ignoring some queries which runs perfectly
         if (duration.TotalSeconds>1 || message.Contains("EF Database call failed after "))
         {
             //The time taken is more or it contains error so adding that to database
             using (DbContext dbContext = new DbContext())
             {
                 //using error model class
                 Error error = new Error
                 {
                     TotalSeconds = (decimal)duration.TotalSeconds,
                     Active = true,
                     CommandType = Convert.ToString(command.CommandType),
                     CreateDate = DateTime.Now,
                     Exception = Convert.ToString(interceptionContext.Exception),
                     FileName = "",
                     InnerException = interceptionContext.Exception == null ?
                     "" : Convert.ToString(interceptionContext.Exception.InnerException),
                     Parameters = parameters.ToString(),
                     Query = command.CommandText,
                     RequestId = 0
                 };
                 //Adding to database
                 dbContext.Errors.Add(error);
                 dbContext.SaveChanges();
             }

             //var errorFileUrl = ;
             //File.WriteAllLines(, message);
         }
     }

     public void ScalarExecuted
     (DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
     {
         //Log and calculate after executed
         Log(command, interceptionContext);
     }

     public void ScalarExecuting
     (DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
     {
         //adding to dictionary when executing
         OnStart(command);
     }
     private static void OnStart(DbCommand command)
     {
         //adding to dictionary when executing
         MStartTime.TryAdd(command, DateTime.Now);
     }
 }

Now, I am registering this class to dbcontext. What it does is, It tells entity framework to use this class for logging database operations.

public DbContext(): base("name=connectionstring")
       {
           //TODO remove this when don't need to log anything
           DbInterception.Add(new DatabaseLogger());
       }

Everything is set up now. You can make an Error model class like this. (This is the code-first model class.)

public class Error
  {
      [Key]
      [Required]
      public int ErrorId { get; set; }
      public string Query { get; set; }
      public string Parameters { get; set; }
      public string CommandType { get; set; }
      public decimal TotalSeconds { get; set; }
      public string Exception { get; set; }
      public string InnerException { get; set; }
      public int RequestId { get; set; }
      public string FileName { get; set; }
      public DateTime CreateDate { get; set; }
      public bool Active { get; set; }
  }

You can see the error logs here

Technically, there are many approaches to log your database operations. But, I think this should be centralized to reduce the load. That is why I used this approach.