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
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 :
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.
About the Author