Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Intermittent NRE in SelectExpression.Tags #15710

Closed
petli opened this issue May 14, 2019 · 2 comments
Closed

Intermittent NRE in SelectExpression.Tags #15710

petli opened this issue May 14, 2019 · 2 comments
Assignees
Labels
closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. customer-reported poachable type-bug
Milestone

Comments

@petli
Copy link

petli commented May 14, 2019

About every 15-20 executions of the unit test suite of our .NET Core 2.2 project we get a NullReferenceException that always end with this stacktrace:

Result StackTrace:  
at Microsoft.EntityFrameworkCore.Query.Expressions.SelectExpression.get_Tags()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateTagsHeaderComment()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateSql(IReadOnlyDictionary`2 parameterValues)
   at Microsoft.EntityFrameworkCore.Query.Internal.ShaperCommandContext.GetRelationalCommand(IReadOnlyDictionary`2 parameters)
...
Result Message: System.NullReferenceException : Object reference not set to an instance of an object.

The stack trace leading up to that point comes from various types of EF queries: sync and async, projections, includes, singletons, toarray. There's no pattern that we can see. (A few stack traces are included at the end of the issue). So far we haven't been able to create a small test program that provokes the NRE.

Based on the stack trace we think this is a result of #11575 interacting with #12069, if somehow two threads can end up working with the same SelectExpression object in DefaultQuerySqlGenerator, where one is is accessing SelectExpression.Tags while the other is calling SelectExpression.DetachContext. This happens in quick succession here:
https://github.com/aspnet/EntityFrameworkCore/blob/2daec6ae17d415af47a606feb0d9f8cfe21296b8/src/EFCore.Relational/Query/Sql/DefaultQuerySqlGenerator.cs#L154

I haven't been able to figure out from the EF Core code if threads can access a single SelectExpression, but it is the only explanation I can see so far. If this is the case, a simple workaround that at least would stop the crash might be to change SelectExpression.Tags to store away the context locally, like this:

        public virtual IReadOnlyCollection<string> Tags
        {
            get
            {
                if (_tags == null)
                {
                    var context = _queryCompilationContext;
                    var annotations = context?.QueryAnnotations;
                    _tags = annotations != null
                        ? annotations
                            .OfType<TagResultOperator>()
                            .Select(tro => tro.Tag)
                            .Distinct()
                            .ToArray()
                        : Array.Empty<string>();
                }

                return _tags;
            }
        }

But I don't know EF Core enough to be prepared to offer this up as a PR, especially as we can't reliably reproduce it.

Fixing #11601 would probably also fix this issue, and possibly other ones that result from _queryCompilationContext no longer being readonly.

Steps to reproduce

Unfortunately we have so far only been able to reproduce this sporadically with our full test suite. Some quirks of that suite which may help provoke this behaviour is that a lot of tests are integration tests that all start doing similar queries. When run in parallel two threads might therefore end up running the same query at the same time, which is also the first time in the test run, triggering the bug as described above when both compiles the SQL query.

Further technical details

EF Core version: 2.2.4 and 3.0.0-preview5
Database Provider: Microsoft.EntityFrameworkCore.Sqlite in-memory
Operating system: Windows 10
IDE: Visual Studio Professional 2019 16.0.3 (also seen in VS 2017)

Additional stack traces

   at Microsoft.EntityFrameworkCore.Query.Expressions.SelectExpression.get_Tags()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateTagsHeaderComment()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateSql(IReadOnlyDictionary`2 parameterValues)
   at Microsoft.EntityFrameworkCore.Query.Internal.ShaperCommandContext.GetRelationalCommand(IReadOnlyDictionary`2 parameters)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.BufferlessMoveNext(DbContext _, Boolean buffer, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.MoveNext(CancellationToken cancellationToken)
   at System.Linq.AsyncEnumerable.SingleOrDefault_[TSource](IAsyncEnumerable`1 source, CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\Single.cs:line 159
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.TaskResultAsyncEnumerable`1.Enumerator.MoveNext(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.ExecuteSingletonAsyncQuery[TResult](QueryContext queryContext, Func`2 compiledQuery, IDiagnosticsLogger`1 logger, Type contextType)

Result Message: 
System.AggregateException : One or more errors occurred. (Object reference not set to an instance of an object.)
---- System.NullReferenceException : Object reference not set to an instance of an object.
   at Microsoft.EntityFrameworkCore.Query.Expressions.SelectExpression.get_Tags()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateTagsHeaderComment()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateSql(IReadOnlyDictionary`2 parameterValues)
   at Microsoft.EntityFrameworkCore.Query.Internal.ShaperCommandContext.GetRelationalCommand(IReadOnlyDictionary`2 parameters)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.BufferlessMoveNext(DbContext _, Boolean buffer, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.MoveNext(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryBuffer.IncludeCollectionAsync[TEntity,TRelated,TElement](Int32 includeId, INavigation navigation, INavigation inverseNavigation, IEntityType targetEntityType, IClrCollectionAccessor clrCollectionAccessor, IClrPropertySetter inverseClrPropertySetter, Boolean tracking, TEntity entity, Func`1 relatedEntitiesFactory, Func`3 joinPredicate, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.IncludeCompiler.IncludeLoadTreeNodeBase._AwaitMany(IReadOnlyList`1 taskFactories)
   at Microsoft.EntityFrameworkCore.Query.Internal.IncludeCompiler._IncludeAsync[TEntity](QueryContext queryContext, TEntity entity, Object[] included, Func`5 fixup, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.TaskLiftingExpressionVisitor._ExecuteAsync[T](IReadOnlyList`1 taskFactories, Func`2 selector)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.AsyncSelectEnumerable`2.AsyncSelectEnumerator.MoveNext(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryBuffer.IncludeCollectionAsync[TEntity,TRelated,TElement](Int32 includeId, INavigation navigation, INavigation inverseNavigation, IEntityType targetEntityType, IClrCollectionAccessor clrCollectionAccessor, IClrPropertySetter inverseClrPropertySetter, Boolean tracking, TEntity entity, Func`1 relatedEntitiesFactory, Func`3 joinPredicate, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.IncludeCompiler._IncludeAsync[TEntity](QueryContext queryContext, TEntity entity, Object[] included, Func`5 fixup, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.TaskLiftingExpressionVisitor._ExecuteAsync[T](IReadOnlyList`1 taskFactories, Func`2 selector)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.AsyncSelectEnumerable`2.AsyncSelectEnumerator.MoveNext(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryBuffer.IncludeCollectionAsync[TEntity,TRelated,TElement](Int32 includeId, INavigation navigation, INavigation inverseNavigation, IEntityType targetEntityType, IClrCollectionAccessor clrCollectionAccessor, IClrPropertySetter inverseClrPropertySetter, Boolean tracking, TEntity entity, Func`1 relatedEntitiesFactory, Func`3 joinPredicate, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.IncludeCompiler.IncludeLoadTreeNodeBase._AwaitMany(IReadOnlyList`1 taskFactories)
   at Microsoft.EntityFrameworkCore.Query.Internal.IncludeCompiler._IncludeAsync[TEntity](QueryContext queryContext, TEntity entity, Object[] included, Func`5 fixup, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.TaskLiftingExpressionVisitor._ExecuteAsync[T](IReadOnlyList`1 taskFactories, Func`2 selector)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.AsyncSelectEnumerable`2.AsyncSelectEnumerator.MoveNext(CancellationToken cancellationToken)
   at System.Linq.AsyncEnumerable.SingleOrDefault_[TSource](IAsyncEnumerable`1 source, CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\Single.cs:line 159
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.TaskResultAsyncEnumerable`1.Enumerator.MoveNext(CancellationToken cancellationToken)
   at System.Linq.AsyncEnumerable.SelectEnumerableAsyncIterator`2.MoveNextCore(CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\Select.cs:line 106
   at System.Linq.AsyncEnumerable.AsyncIterator`1.MoveNext(CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\AsyncIterator.cs:line 98
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.ExecuteSingletonAsyncQuery[TResult](QueryContext queryContext, Func`2 compiledQuery, IDiagnosticsLogger`1 logger, Type contextType)

Result Message: 
System.AggregateException : One or more errors occurred. (Object reference not set to an instance of an object.)
---- System.NullReferenceException : Object reference not set to an instance of an object.
Result StackTrace:  
at Microsoft.EntityFrameworkCore.Query.Expressions.SelectExpression.get_Tags()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateTagsHeaderComment()
   at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateSql(IReadOnlyDictionary`2 parameterValues)
   at Microsoft.EntityFrameworkCore.Query.Internal.ShaperCommandContext.GetRelationalCommand(IReadOnlyDictionary`2 parameters)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.MoveNext()
   at System.Linq.Enumerable.SelectEnumerableIterator`2.MoveNext()
   at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext()
   at System.Collections.Generic.LargeArrayBuilder`1.AddRange(IEnumerable`1 items)
   at System.Collections.Generic.EnumerableHelpers.ToArray[T](IEnumerable`1 source)
   at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)

Result Message: System.NullReferenceException : Object reference not set to an instance of an object.
@SimonCropp
Copy link
Contributor

just got the same exception on a CI server

Error Message:
System.NullReferenceException : Object reference not set to an instance of an object.
Stack Trace:
  at Microsoft.EntityFrameworkCore.Query.Expressions.SelectExpression.get_Tags()
at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateTagsHeaderComment()
at Microsoft.EntityFrameworkCore.Query.Sql.DefaultQuerySqlGenerator.GenerateSql(IReadOnlyDictionary`2 parameterValues)
at Microsoft.EntityFrameworkCore.Query.Internal.ShaperCommandContext.GetRelationalCommand(IReadOnlyDictionary`2 parameters)
at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer)
at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)
at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.MoveNext()
at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider._TrackEntities[TOut,TIn](IEnumerable`1 results, QueryContext queryContext, IList`1 entityTrackingInfos, IList`1 entityAccessors)+MoveNext()
at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext()

re-run with no code changes fixed it. first time i have seen it in months of using EF

packages:
image

@petli
Copy link
Author

petli commented Jun 28, 2019

Given the note in preview 6 about the query engine being rewritten (#12795) and that query tags doesn't work right now, it sounds like this specific issue might not exist in the rewritten code. So it can be moved out of the 3.0.0 milestone for now and my team can come back to see if anything like this remains when the new query code stabilises.

@smitpatel smitpatel added the closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. label Jul 1, 2019
@ajcvickers ajcvickers modified the milestones: 3.0.0, 3.0.0-preview7 Jul 2, 2019
@ajcvickers ajcvickers modified the milestones: 3.0.0-preview7, 3.0.0 Nov 11, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. customer-reported poachable type-bug
Projects
None yet
Development

No branches or pull requests

4 participants