Global query filters raise a "An item with the same key has already been added" exception

[dapnet2018]

If an entity has Global Query Filters defined (e.g. in the OnModelCreating method of the DbContext executing modelBuilder.Entity().HasQueryFilter(...)) and the DbContext is using UseSecondLevelCache, then when trying to retrieve data from the DbContext an exception is thrown "An item with the same key has already been added".

Exception message: System.ArgumentException: An item with the same key has already been added.
Stack trace:
at System.ThrowHelper.ThrowArgumentException(ExceptionResource resource)
   at System.Collections.Generic.Dictionary`2.Insert(TKey key, TValue value, Boolean add)
   at System.Collections.Generic.Dictionary`2.Add(TKey key, TValue value)
   at Microsoft.EntityFrameworkCore.Query.QueryContext.AddParameter(String name, Object value)
   at lambda_method(Closure , QueryContext )
   at EntityFrameworkCore.Cacheable.CustomQueryCompiler.<>c__DisplayClass21_2`1.<CompileQueryCore>b__1(QueryContext qc) in C:\Users\Paul\Source\Repos\EntityFrameworkCore.Cacheable\EntityFrameworkCore.Cacheable\CustomQueryCompiler.cs:line 196
   at EntityFrameworkCore.Cacheable.CustomQueryCompiler.Execute[TResult](Expression query) in C:\Users\Paul\Source\Repos\EntityFrameworkCore.Cacheable\EntityFrameworkCore.Cacheable\CustomQueryCompiler.cs:line 120
   at Microsoft.EntityFrameworkCore.Query.Internal.EntityQueryProvider.Execute[TResult](Expression expression)
   at Remotion.Linq.QueryableBase`1.GetEnumerator()
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
   at EntityFrameworkCore.CacheableTests.GlobalQueryFilterTest.GlobalQueryFiltersWithCacheableEnabledAndUsingCacheQuery() in C:\Users\Paul\Source\Repos\EntityFrameworkCore.Cacheable\EntityFrameworkCore.CacheableTests\GlobalQueryFilterTest.cs:line 190
Result Message:	
Test method EntityFrameworkCore.CacheableTests.GlobalQueryFilterTest.GlobalQueryFiltersWithCacheableEnabledAndUsingCacheQuery threw exception: 
System.ArgumentException: An item with the same key has already been added.

Steps to reproduce

The below unit test shows the issue - it will error on line 103 "Assert.IsTrue(test1Context.Blogs.Count() == 3);"

This unit test is modelling a multi-tenant scenario, where each Entity has a MultiTenantId int property. The relevant MultiTenantID is passed to the DbContext in it's constructor and the Global Query Filter automatically applies a "MultiTenantID = X" predicate.

This unit test will succeed if the "optionsBuilder.UseSecondLevelCache();" is removed from the OnConfiguring method in the GlobalQueryFilterContext class

using System.ComponentModel.DataAnnotations;
using System.Linq;
using EntityFrameworkCore.Cacheable;
using EntityFrameworkCore.CacheableTests.Logging;
using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.Logging;
using Microsoft.VisualStudio.TestTools.UnitTesting;

namespace EntityFrameworkCore.CacheableTests.QuickTest
{
    [TestClass]
    public class ProofOfIssue
    {
        public class GlobalQueryFilterContext : DbContext
        {
            private readonly int _multiTenantId;

            public GlobalQueryFilterContext(int multiTenantId, DbContextOptions<GlobalQueryFilterContext> options)
                : base(options)
            {
                _multiTenantId = multiTenantId;
            }

            protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
            {
                optionsBuilder.UseSecondLevelCache();
            }

            #region Overrides of DbContext

            protected override void OnModelCreating(ModelBuilder modelBuilder)
            {
                base.OnModelCreating(modelBuilder);

                // Add global query filters to all entities
                modelBuilder.Entity<GlobalQueryFilterBlog>().HasQueryFilter(e => e.MultiTenantId == _multiTenantId);
            }

            #endregion

            public DbSet<GlobalQueryFilterBlog> Blogs { get; set; }
        }

        public class GlobalQueryFilterBlog
        {
            [Key]
            public int BlogId { get; set; }
            public int MultiTenantId { get; set; }
            public string Url { get; set; }
        }


        [TestMethod]
        public void QueryingWithGlobalQueryFilters()
        {

            MemoryCacheProvider.ClearCache();

            var loggerProvider = new DebugLoggerProvider();
            var loggerFactory = new LoggerFactory(new[] { loggerProvider });

            var options = new DbContextOptionsBuilder<GlobalQueryFilterContext>()
                .UseLoggerFactory(loggerFactory)
                .UseInMemoryDatabase(databaseName: "GlobalQueryFilterTest")
                .Options;

            // Multi Tenant
            const int firstMultiTenantId = 1;
            const int secondMultiTenantId = 2;

            // create test entries - this time don't disable the cacheable extension
            using (var init1Context = new GlobalQueryFilterContext(firstMultiTenantId, options))
            {
                init1Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 1, MultiTenantId = firstMultiTenantId, Url = "http://sample.com/cats" });

                init1Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 2, MultiTenantId = firstMultiTenantId, Url = "http://sample.com/catfish" });

                init1Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 3, MultiTenantId = firstMultiTenantId, Url = "http://sample.com/dogs" });
                init1Context.SaveChanges();
            }

            using (var init2Context = new GlobalQueryFilterContext(secondMultiTenantId, options))
            {
                init2Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 4, MultiTenantId = secondMultiTenantId, Url = "http://sample.com/clowns" });

                init2Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 5, MultiTenantId = secondMultiTenantId, Url = "http://sample.com/clownfish" });

                init2Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 6, MultiTenantId = secondMultiTenantId, Url = "http://sample.com/circus" });

                init2Context.Blogs.Add(new GlobalQueryFilterBlog
                { BlogId = 7, MultiTenantId = secondMultiTenantId, Url = "http://sample.com/circustent" });
                init2Context.SaveChanges();
            }

            using (var test1Context = new GlobalQueryFilterContext(firstMultiTenantId, options))
            {
                Assert.IsTrue(test1Context.Blogs.Count() == 3);

                Assert.IsTrue(test1Context.Blogs.ToList().All(b => b.MultiTenantId == firstMultiTenantId));
            }

            using (var test2Context = new GlobalQueryFilterContext(secondMultiTenantId, options))
            {
                Assert.IsTrue(test2Context.Blogs.Count() == 4);

                Assert.IsTrue(test2Context.Blogs.ToList().All(b => b.MultiTenantId == secondMultiTenantId));
            }

        }
    }
}

Further technical details

EntityFrameworkCore.Cacheable version: 2.0.0 (and also latest Master branch code from GitHub)
EF Core version: 2.2.0
IDE: Visual Studio 2017 15.9.6

[SteffenMangold]

hi @dapnet2018,
I'm sorry I can't reproduce your exception.
Is copied your unit test and got the correct result.

EntityFrameworkCore.Cacheable/EntityFrameworkCore.CacheableTests/CacheableExpressionTests.cs

Lines 361 to 406 in bbf8ee7

	public void GlobalQueryFilterTest()
	{
	MemoryCacheProvider.ClearCache();
	var loggerProvider = new DebugLoggerProvider();
	var loggerFactory = new LoggerFactory(new[] { loggerProvider });
	var options = new DbContextOptionsBuilder<BloggingContext>()
	.UseLoggerFactory(loggerFactory)
	.UseInMemoryDatabase(databaseName: "GlobalQueryFilterTest")
	.Options;
	// create test entries
	using (var initContext = new BloggingContext(options))
	{
	initContext.Blogs.Add(new Blog { BlogId = 1, Url = "http://sample.com/cats" });
	initContext.Blogs.Add(new Blog { BlogId = 2, Url = "http://sample.com/catfish" });
	initContext.Blogs.Add(new Blog { BlogId = 3, Url = "http://sample.com/dogs" });
	initContext.SaveChanges();
	}
	using (var constantContext = new BloggingContext(options, minBlogId: 2))
	{
	// shoud not hit cache, because no Cacheable call
	var rawResult = constantContext.Blogs
	.Count();
	// shoud not hit cache, because first execution
	var result = constantContext.Blogs
	.Cacheable(TimeSpan.FromMinutes(5))
	.Count();
	// shoud hit cache, because second execution
	var cachedResult = constantContext.Blogs
	.Cacheable(TimeSpan.FromMinutes(5))
	.Count();
	Assert.AreEqual(result, cachedResult);
	}
	// find "cache hit" log entries
	var logs = loggerProvider.Entries.Where(e => e.EventId == CacheableEventId.CacheHit);
	// cache should hit one time
	Assert.IsTrue(logs.Count() == 1);
	}

Could you test it on you system?

[dapnet2018]

Thank you @SteffenMangold for taking the time to look into this issue - I really appreciate it.

I couldn't recreate the issue using your updated unit tests either at first, but I have been able to recreate the issue with two minor changes:

The first change is that the first time the BloggingContext is instantiated, the minBlogId value needs to be passed even though it's not needed yet to ensure that in the OnModelCreating method the global query filter is applied. OnModelCreating is only called the very first time the context is created.

So in CacheableExpressionTests.cs, line 374 should change from:

using (var initContext = new BloggingContext(options))

to:

using (var initContext = new BloggingContext(options, minBlogId: 2))

The second change is that doing a Count() does not seem to cause this issue, but a ToList() or some other query with a predicate does, so if you add the below somewhere within the using (var constantContext... block you should get the exception I'm experiencing:

var allItems = constantContext.Blogs.ToList();
Assert.AreEqual(2, allItems.Count);

For completeness, my updated version of the GlobalQueryFilterTest is as follows:

/// <summary>
/// Testing null parameter query .
/// </summary>
[TestMethod]
public void GlobalQueryFilterTest()
{
	MemoryCacheProvider.ClearCache();

	var loggerProvider = new DebugLoggerProvider();
	var loggerFactory = new LoggerFactory(new[] { loggerProvider });

	var options = new DbContextOptionsBuilder<BloggingContext>()
			.UseLoggerFactory(loggerFactory)
			.UseInMemoryDatabase(databaseName: "GlobalQueryFilterTest")
			.Options;

	// create test entries
	using (var initContext = new BloggingContext(options, minBlogId: 2))
	{
		initContext.Blogs.Add(new Blog { BlogId = 1, Url = "http://sample.com/cats" });
		initContext.Blogs.Add(new Blog { BlogId = 2, Url = "http://sample.com/catfish" });
		initContext.Blogs.Add(new Blog { BlogId = 3, Url = "http://sample.com/dogs" });
		initContext.SaveChanges();
	}

	using (var constantContext = new BloggingContext(options, minBlogId: 2))
	{

		var allItems = constantContext.Blogs.ToList();

		Assert.AreEqual(2, allItems.Count);

		// shoud not hit cache, because no Cacheable call
		var rawResult = constantContext.Blogs
				.Count();

		// shoud not hit cache, because first execution
		var result = constantContext.Blogs
				.Cacheable(TimeSpan.FromMinutes(5))
				.Count();

		// shoud hit cache, because second execution
		var cachedResult = constantContext.Blogs
				.Cacheable(TimeSpan.FromMinutes(5))
				.Count();

		Assert.AreEqual(result, cachedResult);

	}

	// find "cache hit" log entries
	var logs = loggerProvider.Entries.Where(e => e.EventId == CacheableEventId.CacheHit);

	// cache should hit one time
	Assert.IsTrue(logs.Count() == 1);
}

Thanks again for your assistance

[SteffenMangold]

Hi seem that this error is a parameter name collision related to the global filter.
Have a look here dotnet/efcore#9850
But this should be fixed and I don't really understand why it happens.

Maybe @smitpatel can support us with this.

[dapnet2018]

That does seem to be the issue. One further thing is that I encounter this exception only if my DbContext makes a call to UseSecondLevelCache() in the OnConfiguring method or as part of the DbContextOptionsBuilder passed to that method.

Any thoughts as to why that might be?

[SteffenMangold]

No, sadly not. But it is a parameter name collision like in the mentioned bug.
I just don't understand why my compiled ToList() raised this name collision then using a global filter.
The compiling of the query is exactly the same as in the original EF Core.

[smitpatel]

@dapnet2018 - Which line in GlobalQueryFilterTest throws that exception? There is no clash in external/internal parameter names here so related EF issue is not the cause. Something else in second level cache is causing this to happen. Perhaps incorrectly shared QueryContext.

Looking at the implementation, second level caching may not work properly with Query filters. QueryFilters have DbContext based property which can have different values for different execution. In order to use the query caching in EF Core, we compile the funcs inside compiled query to compute the value from current context and add it to parameters for the query. But the way second level cache is using cache key, it is looking at the external parameters but not query filter based parameters. (which it cannot see easily anyway). So if you run a query with second level cache, and run it in different context which has different values for filter properties, it will still give earlier result, which would be incorrect result.

[dapnet2018]

Hi @smitpatel, thanks for taking a look at this.

I don't think Steffen has updated the code yet, so you will need to use my adjusted version of the GlobalQueryFilterTest I posted above, and then it will error on this line :

var allItems = constantContext.Blogs.ToList();

The error is thrown in the CustomQueryCompiler in the Try..Catch lines 184 to 197.

However, based on what you've said I'm guessing I need to stop using the Second Level caching for any DbContexts where I'm also using Global Query Filters, as it sounds like it's not an easy fix to incorporate the Query Filter parameters into the cache key. Is that right?

[smitpatel]

This is the culprit for this exception:

EntityFrameworkCore.Cacheable/EntityFrameworkCore.Cacheable/CustomQueryCompiler.cs

Line 188 in bbf8ee7

var result = genericToListMethod.Invoke(compileFunction(qc), new object[] { compileFunction(qc) });

since CompileFunction is being called twice on same queryContext, first call will add parameters based on query filter on query context. Then second call will try to add same parameter causing exception. Perhaps should capture the result in local variable to enumerable only once.

Still cached results from second level cache will not reflect changed value in query filters if any.

[mguinness]

If it's the case that this library doesn't play well with Global Query Filters, it it possible to determine when filters have been defined for the query to skip the cache and log a warning?

[SiberaIndustries]

I get the same exception. I use a Global Query Filter to filter the results for single tenants in my app. Sadly, for me it looks like I have to remove these Extensions completely until this issue gets fixed.