Efcore: [1.1.2 regression] The multi-part identifier "ts.Id" could not be bound

[fschlaef]

The following code :

context.TrainingSession.Select(ts => new {
    ts.Id,
    ts.Name,
    Trainees = ts.TraineeTrainingSession.Select(tts => new {
        tts.FirstName,
        tts.LastName,
        NumberOfDays = (ts.TimeSlot.Count() - traineeTimeSlotList.Where(ttsl=> ttsl.TraineeFk == tts.TraineeFk && ttsl.TrainingSessionFk == ts.Id).Count()) / 2.0
    }
}

Produces the following SQL :

SELECT [tts.TraineeFkNavigation].[lastName], [tts0].[trainee_fk], [tts.TraineeFkNavigation].[firstName], (
    SELECT COUNT(*)
    FROM [dbname].[TimeSlot] AS [t4]
    WHERE [ts].[id] = [t4].[trainingSession_fk]
)
FROM [dbname].[Trainee_TrainingSession] AS [tts0]
INNER JOIN [dbname].[Trainee] AS [tts.TraineeFkNavigation] ON [tts0].[trainee_fk] = [tts.TraineeFkNavigation].[id]
WHERE @_outer_Id1 = [tts0].[trainingSession_fk]

Of course, since [ts] does not exist, the exception is thrown :

System.Data.SqlClient.SqlException: The multi-part identifier "ts.Id" could not be bound
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData() at System.Data.SqlClient.SqlDataReader.get_MetaData() at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds) at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior) at Microsoft.EntityFrameworkCore.Storage.Internal.RelationalCommand.Execute(IRelationalConnection connection, String executeMethod, IReadOnlyDictionary2 parameterValues, Boolean closeConnection)
at Microsoft.EntityFrameworkCore.Storage.Internal.RelationalCommand.ExecuteReader(IRelationalConnection connection, IReadOnlyDictionary2 parameterValues) at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable.Enumerator.BufferlessMoveNext(Boolean buffer) at Microsoft.EntityFrameworkCore.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](Func2 operation, Func2 verifySucceeded, TState state) at Microsoft.EntityFrameworkCore.Query.QueryMethodProvider.<_ShapedQuery>d__31.MoveNext()
at System.Collections.Generic.EnumerableHelpers.ToArray[T](IEnumerable1 source, Int32& length) at System.Linq.Buffer1..ctor(IEnumerable1 source) at System.Linq.OrderedEnumerable1.d__3.MoveNext()
at System.Linq.Enumerable.SelectEnumerableIterator2.MoveNext() at System.Collections.Generic.List1..ctor(IEnumerable1 collection) at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source)
at lambda_method(Closure , TransparentIdentifier2 ) at System.Linq.Enumerable.SelectEnumerableIterator2.MoveNext()
at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.MoveNext() at System.Collections.Generic.List1..ctor(IEnumerable1 collection) at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source)
at Project.Controllers.TrainingSessionController.ListToTraineeList(Nullable1 startDate, Nullable1 endDate) in ProjectsrcProjectControllersTrainingSessionController.cs:line 324
at lambda_method(Closure , Object , Object[] )
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.d__25.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.d__22.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ResourceExecutedContext context)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.AspNetCore.Builder.RouterMiddleware.d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
at Project.Startup.<>c.<b__7_1>d.MoveNext() in ProjectsrcProjectStartup.cs:line 130
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.d__7.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.d__7.MoveNext()
ClientConnectionId:81ce5155-4141-42e5-bb30-9fcd2bee101e
Error Number:4104,State:1,Class:16

This issue seems related to #7033 and #7992

Interestingly, any access to any parent property (ts) from the child will throw the same "ts.Id" exception, even if there is no access to the Id property. In my case, access to "ts.TimeSlot" is enough to throw the exception.

Workaround

The workaround for this issue is to use navigation properties instead of direct parent access :

```csharp
NumberOfDays = tts.TrainingSessionFkNavigation.TimeSlot.Count() - traineeTimeSlotList.Where(ttsl=> ttsl.TraineeFk == tts.TraineeFk && ttsl.TrainingSessionFk == tts.TrainingSessionFkNavigation.Id).Count() / 2.0
````

This code worked fine in 1.0 because the properties were evaluated client-side, if I'm not mistaken.

I don't know if I did something wrong here, but since this issue is supposedly fixed I though I'd better open an issue.

Further technical details

EF Core version: 1.1.2
Database Provider: Microsoft.EntityFrameworkCore.SqlServer
Operating system: Windows 7
IDE: Visual Studio 2017

[fschlaef]

I've pieced together a standalone repro. I am by no means an expert, so this is probably not the minimal amount of code required to trigger this bug, but it works.

This bug looks related to how Count() and ToList() interacts. This bug also triggers for Any(), but not Max() or Min() (at least not in this code).

class Program
    {
        static void Main(string[] args)
        {
            using (var context = new MyContext())
            {
                context.Database.EnsureDeleted();
                context.Database.EnsureCreated();

                context.TrainingSession.Add(new TrainingSession
                {
                    Name = "Test"
                });

                context.Trainee.Add(new Trainee
                {
                    FirstName = "Trainee",
                    LastName = "Test"
                });

                context.SaveChanges();

                context.TraineeTrainingSession.Add(new TraineeTrainingSession
                {
                    TraineeFk = context.Trainee.First().Id,
                    TrainingSessionFk = context.TrainingSession.First().Id
                });

                context.TimeSlot.Add(new TimeSlot
                {
                    TrainingSessionFk = context.TrainingSession.First().Id
                });

                context.SaveChanges();

                // Count() but no ToList() on subobject
                var workingQuery = context.TrainingSession.Select(ts => new {
                    ts.Id,
                    ts.Name,
                    Trainees = ts.TraineeTrainingSession.Select(tts => new {
                        TimeSlot = ts.TimeSlot.Count(),
                        SessionId = ts.Id
                    })
                }).ToList();

                // No Count() but ToList() on subobject
                var alsoWorkingQuery = context.TrainingSession.Select(ts => new {
                    ts.Id,
                    ts.Name,
                    Trainees = ts.TraineeTrainingSession.Select(tts => new {
                        TimeSlot = ts.TimeSlot,
                        SessionId = ts.Id
                    }).ToList()
                }).ToList();

                // Count and ToList(), throws exception
                var nonWorkingQuery = context.TrainingSession.Select(ts => new {
                    ts.Id,
                    ts.Name,
                    Trainees = ts.TraineeTrainingSession.Select(tts => new {
                        TimeSlot = ts.TimeSlot.Count(),
                        SessionId = ts.Id
                    }).ToList()
                }).ToList();          
            }
        }
    }

    public class MyContext : DbContext
    {
        public virtual DbSet<TrainingSession> TrainingSession { get; set; }
        public virtual DbSet<TimeSlot> TimeSlot { get; set; }
        public virtual DbSet<TraineeTrainingSession> TraineeTrainingSession { get; set; }
        public virtual DbSet<Trainee> Trainee { get; set; }

        protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        {
            optionsBuilder.UseSqlServer(@"Server=.;Database=Repro8862;Trusted_Connection=True;MultipleActiveResultSets=true");
        }
    }

    public class Customer
    {
        public int Id { get; set; }
    }

    public partial class TrainingSession
    {
        public TrainingSession()
        {
            TimeSlot = new HashSet<TimeSlot>();
            TraineeTrainingSession = new HashSet<TraineeTrainingSession>();
        }

        public int Id { get; set; }
        public string Name { get; set; }

        public virtual ICollection<TimeSlot> TimeSlot { get; set; }
        public virtual ICollection<TraineeTrainingSession> TraineeTrainingSession { get; set; }
    }

    public partial class TimeSlot
    {
        public TimeSlot()
        {
        }

        public int Id { get; set; }
        public int TrainingSessionFk { get; set; }

        public virtual TrainingSession TrainingSessionFkNavigation { get; set; }
    }

    public partial class Trainee
    {
        public Trainee()
        {
            TraineeTrainingSession = new HashSet<TraineeTrainingSession>();
        }

        public int Id { get; set; }
        public string FirstName { get; set; }
        public string LastName { get; set; }

        public virtual ICollection<TraineeTrainingSession> TraineeTrainingSession { get; set; }
    }

    public partial class TraineeTrainingSession
    {
        public int Id { get; set; }
        public int TraineeFk { get; set; }
        public int TrainingSessionFk { get; set; }

        public virtual Trainee TraineeFkNavigation { get; set; }
        public virtual TrainingSession TrainingSessionFkNavigation { get; set; }
    }

Edit : my .csproj, for reference :

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>netcoreapp1.1</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.EntityFrameworkCore" Version="1.1.2" />
    <PackageReference Include="Microsoft.EntityFrameworkCore.SqlServer" Version="1.1.2" />
  </ItemGroup>

</Project>

Edit 2 : Out of curiosity, I tested on 2.0.0-preview1 and the issue seems fixed.

[smitpatel]

I tried running above repro code. No exceptions. All query passed. EFCore.SqlServer version 1.1.2

[fschlaef]

I ran the repro on another server, exception still thrown.

I tested against SQL Server 2016 (13.0.4422) and SQL Server 2014 (12.0.5540) with exception thrown both times.

Any idea on what I should test on / what to change ?

Edit : Note : my Visual Studio, Windows and SQL Server are all in French.

[smitpatel]

I am using Win10 Creators update
SQL Server 2016 SP1 (13.0.4001)
Though none of those should matter. EF doesn't produce query based on the SqlServer/OS version.

Try following steps

• Verify that you are using 1.1.2 packages only. You may end up with different package based on variety of nuget caches etc.
• Enable debug level logging and post log output for the query which is failing.

[fschlaef]

My dependency list contains soms packages lower than 1.1.2, but apparently they are in the highest possible version.
EF DLLs are all 1.1.2 as confirmed by inspecting what gets published. .NET Core App is also 1.1.2

I attached the dependency list and a complete debug log of the request. The log is from the original software (the one the repro I posted is based on), I simply copy-pasted the same faulty request into a "Crash" function in a random controller.

8862log.txt

EDIT : On the original software, Microsoft.Extensions.Caching.Memory is in version 1.1.2, Microsoft.Extensions.DependencyInjection is in 1.1.1 and Microsoft.Extensions.Logging is in 1.1.2, but that changes nothing. But why does packages get installed in lower versions ?

[smitpatel]

This is regression
The query worked in 1.0.0
It threw exception in 1.1.0 ( #7033)
It worked in 1.1.1 (due to #7033 being fixed. Which brought in another issue #7714)
It fails in 1.1.2 (due to fix applied for #7714)

Simplified repro:
```C#
using System;
using System.Collections.Generic;
using System.Linq;
using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.Logging;

namespace ConsoleApp3
{
class Program
{
static void Main(string[] args)
{
using (var context = new MyContext())
{
context.Database.EnsureDeleted();
context.Database.EnsureCreated();

            context.Add(
                new Customer
                {
                    CustomerDetails = new List<CustomerDetail>
                    {
                        new CustomerDetail(),
                        new CustomerDetail()
                    },
                    Orders = new List<Order>
                    {
                        new Order(),
                        new Order()
                    }
                }
            );

            context.SaveChanges();

        }

        using (var context = new MyContext())
        {
            var query = context.Customers.Select(
                c => new
                {
                    c.Id,
                    Details = c.CustomerDetails.Select(
                        cd => new
                        {
                            OrderCount = c.Orders.Count(),
                            Id = c.Id
                        }).ToList()
                }).ToList();
        }
    }

}

public class MyContext : DbContext
{
    public virtual DbSet<Customer> Customers { get; set; }

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        optionsBuilder.UseSqlServer("Server=.;Database=Repro8862;Trusted_Connection=True;MultipleActiveResultSets=true")
            .EnableSensitiveDataLogging()
            .UseLoggerFactory(new LoggerFactory().AddConsole(LogLevel.Debug));
    }
}

public class Customer
{
    public int Id { get; set; }
    public IList<CustomerDetail> CustomerDetails { get; set; }
    public IList<Order> Orders { get; set; }
}

public class CustomerDetail
{
    public int Id { get; set; }
}

public class Order
{
    public int Id { get; set; }
}

}
```

Issue: Logic introduced in #7714 is incorrect for nested cases.
https://github.com/aspnet/EntityFramework/blob/rel/1.1.2/src/Microsoft.EntityFrameworkCore.Relational/Query/ExpressionVisitors/SqlTranslatingExpressionVisitor.cs#L733

As soon as you move to ParentQueryModelVisitor in recursive call, the value of CurrentQueryModelStreamedDataInfo is out of sync (& incorrect).

This works correctly in 2.0.0-preview1 package.

[smitpatel]

Clearing milestone so that we can consider if this is patch worthy or not.

[fschlaef]

Thanks for the in-depth investigation @smitpatel :+1:

[ajcvickers]

@smitpatel Does this, in your option, still meet the bar for a patch?

[smitpatel]

It is regression. So we should fix it. 😞

[Eilon]

This patch is approved for 1.1.x. Please follow the patch creation instructions that were sent by email, and submit a PR to the correct branch.