I want to analyse in this post how Entity Framework really interact with the database. i.e. The queries that are really executed.

In previous post I created a database using Code First. These are two of my entities:

A food representation:

public class Food
{
    /// <summary>
    /// Gets or sets the food identifier.
    /// </summary>
    [Key]
    // NOTE: As the name is className + id, this property is not needed
    public int Id { get; set; }
 
    /// <summary>
    /// Gets or sets the food name.
    /// </summary>
    [MaxLength(200)]
    [Index(IsUnique = true)]
    public string Name { get; set; }
 
    /// <summary>
    /// Gets or sets the recipes needing this Food
    /// </summary>
    // NOTE: EF needs the virtual attribute to enable Lazy loading 
    public virtual List<Recipe> RecpiesNeedingThisFood { get; set; }
 
    /// <summary>
    /// Returns a <see cref="System.String" /> that represents this instance.
    /// </summary>
    public override string ToString()
    {
        return string.Format("{0} ({1})", this.Name, this.Id);
    }
}

An entry on my fridge representation: a food and an expire date of this food.

public class FridgeEntry
{
    /// <summary>
    /// Initializes a new instance of the <see cref="FridgeEntry"/> class.
    /// </summary>
    public FridgeEntry()
    {
        ExpireDate = DateTime.MaxValue;
    }
 
    public int Id { get; set; }
 
    [Required]
    // NOTE virtual is needed for lazy loading
    public virtual Food Food { get; set; }
 
    /// <summary>
    /// Gets or sets the expire date.
    /// </summary>
    public DateTime ExpireDate { get; set; }
 
 
    /// <summary>
    /// Returns a <see cref="System.String" /> that represents this instance.
    /// </summary>
    public override string ToString()
    {
        return string.Format("FoodId ({0}) - expire date: {1}", this.Id, this.ExpireDate);
    }
}

How to debug the queries and connections between EF and my database?

A new feature of EF6 is the possibility to log everything that Entity Framework is doing.

The context.Database has a Log property which is type Action<string> if this action is not null EF will call it always he connect to the database.

Define a logger, to analyse the Lazy loading a simple method writing in console the messages is enough:

private static void ConsoleLogger(string msg)
{
    msg = msg.Trim();
 
    if (!string.IsNullOrEmpty(msg))
    {
        Console.ForegroundColor = ConsoleColor.DarkGray;
        Console.WriteLine(DateTime.Now.TimeOfDay.ToString("g"));
        Console.ForegroundColor = ConsoleColor.DarkGreen;
        Console.WriteLine(msg);
 
        Console.ResetColor();
    }
}

Now we just have to define this  logger as the logger of the context.Database.

EF Lazy loading testing

We have already a way to see the connections between EF and the database, now let’s analyse it:

The content of my database:

My console application:

static void Main()
{
    using (FoodContext context = new FoodContext())
    {
        // Set the ConsoleLogger 
        context.Database.Log = ConsoleLogger;
 
        // Print all fridge entries
        foreach (var fridgeEntry in context.Fridge)
        {
            Console.WriteLine("-" + fridgeEntry);
        }
 
        // Print the Food represented by each food entry
        // NOTE: We need to add "ToList" to get all the items before trying the lazy loading of Food
        foreach (var fridgeEntry in context.Fridge.ToList())
        {
            Console.WriteLine("-" + fridgeEntry.Food);
        }
    }
 
    Console.ReadLine();
}

If I look at the code of my console application what I would expect is that EF gets the data from the table FoodEntry to print out each value and after that when I really want to print the Food of this entry then he gets the data of the Food table.

If I run the application this is the output:

The first part is related to the creation of the context and other stuff that EF needs to do before really doing what I ask him to do, this is also very interesting but not the focus of this post, I will just copy it:

The interesting part for this post:

EF recover all the food entries to print out the ID and expire date, now the second part, when I want information contained in the Food table:

EF has the Id of the required Food for each FoodEntry and uses a query with parameters to get the Food with each ID.

Before creating the query, EF looks for the required entity in the context, this is way he print the two entries of Eggs with just one query.

I just find out that I need something more in my FoodEntry I will add the FoodID (FK) to the entity, this information is already in the database but not accessible at the moment with my entities. This can be done very easy with the “ForeignKey” annotation:

public class FridgeEntry
{
    /// <summary>
    /// Initializes a new instance of the <see cref="FridgeEntry"/> class.
    /// </summary>
    public FridgeEntry()
    {
        ExpireDate = DateTime.MaxValue;
    }
 
    public int Id { get; set; }
 
    [ForeignKey("Food")]
    public int FoodId { get; set; }
 
    [Required]
    // NOTE virtual is needed for lazy loading
    public virtual Food Food { get; set; }
 
    /// <summary>
    /// Gets or sets the expire date.
    /// </summary>
    public DateTime ExpireDate { get; set; }
 
    /// <summary>
    /// Returns a <see cref="System.String" /> that represents this instance.
    /// </summary>
    public override string ToString()
    {
        return string.Format("FoodId ({0}) - expire date: {1}", this.FoodId, this.ExpireDate);
    }
}