Efcore: System.InvalidProgramException thrown in production

[coffeymatt]

We had an outage of our identity server in production in Azure. The site is running the latest .NET Core 2.1 and the most up to date stable version of EF Core as of 05 June 2018.

The exception caught by application insights does not give us a clear root cause, but comes from inside entity framework and I'm posting the error here to see if anyone has any insight.

(Restarting our app restored the application).

Exception message:

Message | Connection id "0HLEA7A8JGC55", Request id "0HLEA7A8JGC55:00000004": An unhandled exception was thrown by the application. |  
-- | -- | --
Exception type | System.InvalidProgramException |  
Failed method | Microsoft.EntityFrameworkCore.Query.QueryCompilationContext.get_QueryAnnotations

Stack trace:

System.InvalidProgramException: Common Language Runtime detected an invalid program.
 at Microsoft.EntityFrameworkCore.Query.QueryCompilationContext.get_QueryAnnotations()
 at Microsoft.EntityFrameworkCore.Query.Internal.IncludeCompiler..ctor(QueryCompilationContext queryCompilationContext, IQuerySourceTracingExpressionVisitorFactory querySourceTracingExpressionVisitorFactory)
 at Microsoft.EntityFrameworkCore.Query.EntityQueryModelVisitor.OptimizeQueryModel(QueryModel queryModel, Boolean asyncQuery)
 at Microsoft.EntityFrameworkCore.Query.RelationalQueryModelVisitor.OptimizeQueryModel(QueryModel queryModel, Boolean asyncQuery)
 at Microsoft.EntityFrameworkCore.Query.EntityQueryModelVisitor.CreateAsyncQueryExecutor[TResult](QueryModel queryModel)
 at Microsoft.EntityFrameworkCore.Storage.Database.CompileAsyncQuery[TResult](QueryModel queryModel)
 at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.CompileAsyncQueryCore[TResult](Expression query, INodeTypeProvider nodeTypeProvider, IDatabase database)
 at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.<>c__DisplayClass24_0`1.<CompileAsyncQuery>b__0()
 at Microsoft.EntityFrameworkCore.Query.Internal.CompiledQueryCache.GetOrAddQueryCore[TFunc](Object cacheKey, Func`1 compiler)
 at Microsoft.EntityFrameworkCore.Query.Internal.CompiledQueryCache.GetOrAddAsyncQuery[TResult](Object cacheKey, Func`1 compiler)
 at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.CompileAsyncQuery[TResult](Expression query)
 at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.ExecuteAsync[TResult](Expression query, CancellationToken cancellationToken)
 at Microsoft.EntityFrameworkCore.Query.Internal.EntityQueryProvider.ExecuteAsync[TResult](Expression expression, CancellationToken cancellationToken)
 at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ExecuteAsync[TSource,TResult](MethodInfo operatorMethodInfo, IQueryable`1 source, Expression expression, CancellationToken cancellationToken)
 at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ExecuteAsync[TSource,TResult](MethodInfo operatorMethodInfo, IQueryable`1 source, LambdaExpression expression, CancellationToken cancellationToken)
 at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.FirstOrDefaultAsync[TSource](IQueryable`1 source, Expression`1 predicate, CancellationToken cancellationToken)
 at Microsoft.EntityFrameworkCore.Internal.EntityFinder`1.FindAsync(Object[] keyValues, CancellationToken cancellationToken)
 at Microsoft.EntityFrameworkCore.Internal.InternalDbSet`1.FindAsync(Object[] keyValues, CancellationToken cancellationToken)
 at Microsoft.AspNetCore.Identity.EntityFrameworkCore.UserStore`9.FindByIdAsync(String userId, CancellationToken cancellationToken)
 at Microsoft.AspNetCore.Identity.UserManager`1.FindByIdAsync(String userId)
 at Microsoft.AspNetCore.Identity.UserManager`1.GetUserAsync(ClaimsPrincipal principal)
 at Microsoft.AspNetCore.Identity.SignInManager`1.<ValidateSecurityStampAsync>d__32.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
 at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
 at Microsoft.AspNetCore.Identity.SecurityStampValidator`1.<ValidateAsync>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.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
 at Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler.<HandleAuthenticateAsync>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.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at Microsoft.AspNetCore.Authentication.AuthenticationHandler`1.<AuthenticateAsync>d__47.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
 at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at Microsoft.AspNetCore.Authentication.AuthenticationService.<AuthenticateAsync>d__10.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
 at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.<Invoke>d__6.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
 at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
 at Microsoft.AspNetCore.Server.IISIntegration.IISMiddleware.<Invoke>d__11.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
 at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
 at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.<Invoke>d__3.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
 at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame`1.<ProcessRequestsAsync>d__2.MoveNext()

Steps to reproduce

Issue occurred out of the blue and has been resolved by restart. Don't know how to reproduce. Identity server is currently operating as expected.

```

Further technical details

EF Core version: 2.1.0
Database Provider: Microsoft.EntityFrameworkCore.SqlServer
Operating system: Azure App Service

[flagbug]

This exact same is also something we're seeing very very sporadically (once every few months) with EF Core versions before 2.1.0 hosted on Azure App Service.

Sadly it's super hard to gain any more information for this because we have to immediately restart our instances so our users aren't impacted.

[jarz]

I've started seeing the InvalidProgramException today within my API that uses ASP.NET Core 2.1.0 & EF Core 2.1.0.

System.InvalidProgramException:
   at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue (Microsoft.EntityFrameworkCore, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at lambda_method (Anonymously Hosted DynamicMethods Assembly, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null)
   at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.UnbufferedEntityShaper`1.Shape (Microsoft.EntityFrameworkCore.Relational, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1+AsyncEnumerator+<BufferlessMoveNext>d__12.MoveNext (Microsoft.EntityFrameworkCore.Relational, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy+<ExecuteAsync>d__7`2.MoveNext (Microsoft.EntityFrameworkCore.SqlServer, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1+AsyncEnumerator+<MoveNext>d__11.MoveNext (Microsoft.EntityFrameworkCore.Relational, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Linq.AsyncEnumerable+<SingleOrDefault_>d__381`1.MoveNext (System.Interactive.Async, Version=3.0.3000.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider+TaskResultAsyncEnumerable`1+Enumerator+<MoveNext>d__3.MoveNext (Microsoft.EntityFrameworkCore, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider+ExceptionInterceptor`1+EnumeratorExceptionInterceptor+<MoveNext>d__5.MoveNext (Microsoft.EntityFrameworkCore, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler+<ExecuteSingletonAsyncQuery>d__21`1.MoveNext (Microsoft.EntityFrameworkCore, Version=2.1.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at OnlineOrdering.WebAPI.Services.UserService+<GetUser>d__8.MoveNext (OnlineOrdering.WebAPI, Version=1.0.0.0, Culture=neutral, PublicKeyToken=nullOnlineOrdering.WebAPI, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null: D:\a\1\s\OnlineOrdering.WebAPI\Services\UserService.csOnlineOrdering.WebAPI, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null: 33)

[ajcvickers]

@danmosemsft @karelz Can we get some guidance here? There is nothing special about the methods or stack traces here. For example, the property at the top of the stack trace in the first example is very simple code:
C# private readonly List<IQueryAnnotation> _queryAnnotations = new List<IQueryAnnotation>(); public virtual IReadOnlyCollection<IQueryAnnotation> QueryAnnotations => _queryAnnotations;
Also, the stack trace for the second case is very different. So based on these things I would be surprised if this is actually an EF issue.

So, couple of questions:

• Have you seen anything similar to this on your side?
• What's the best thing to ask for that will help get a root cause on this?

/cc @divega

[danmosemsft]

Can the customers attach before the issue and break on the exception (eg with SOS) and give us a full dumpfile at that point? It would need to include the Jitted code, ie., not just a minidump.

I assume that's the next step, if we can'get a repro -- @jkotas anything to add?

[flagbug]

@ajcvickers

So based on these things I would be surprised if this is actually an EF issue.

While I'm not saying that this is an EF Core issue, what I've noticed is that when our app fails with an InvalidProgramException, it's always somewhere in the EF code. The program also never recovers from this and the only way to mitigate it is to restart the Azure App Service instance.

@danmosemsft At least for me it's basically impossible to reproduce or catch this exception, since it happens sporadically every few weeks on a web app hosted on Azure App Service. Any ideas how I can give you more information?

[coffeymatt]

Same for me. Happy to help in any way I can, but the error is one of those tricky sporadic rare types. It's happened just the once in production so far for me.

[ajcvickers]

I found that the same issue has been reported on coreclr, which seems to be the appropriate place for it, so I have moved all the content here to that issue and I'm closing this one.