Warning for EF generated queries that weren't in the Query Plan Cache (cold queries)

[RudeySH]

This might be out of scope, but it would be a great addition. MiniProfiler already warns about duplicate SQL queries, so a warning about queries not coming from the query plan caches fits right in.

https://docs.microsoft.com/en-us/ef/ef6/fundamentals/performance/perf-whitepaper#32-query-plan-caching

TL;DR: The first time a query is run it takes longer because EF hasn't cached it yet. There are also various reasons why a query might never be cached. Eventually cache entries will be evicted as wel.

If MiniProfiler could indicate which queries come from the cache, and which ones don't, that would be super helpful. When profiling, it is always useful to know if the query is cold (not in the cache yet). It would also help spot us find queries that never get cached, just like we can currently use MiniProfiler to spot duplicate queries.

[NickCraver]

Duplicate queries we can detect via content, so there's no knowledge of a duplicate when it happens, but after the fact. Do do this we'd have to record and flag it when it happens. That could potentially be an additional custom timing maybe, for the compile portion of it (if we could instrument such a thing), are there any hooks to get at it?

[NickCraver]

I worry about warning about something as "this isn't representative" unless we can tell that a) it would be cached, and b) this one wasn't. Without both, we'd indicate on the things that shouldn't ever be cached and that's incorrect noise - because it is representative. So IMO, there's only any value is:

1. We can determine it should be cached
2. We can determine it wasn't
3. There's measurable cost on the first run (e.g. the indicator is useful as to outlier-ness)

@ajcvickers Do you have any idea if this kind of this is exposed? That'd be a minimum to have some sort of indicator, but I'd also love to know if you think this is valuable to show either, or if the cost is negligible enough to not add code and UI for it.

[ajcvickers]

Adding @smitpatel and @roji.

1. I don't think we have any cases left where we don't cache the query at the EF level, but Smit and Shay will know better.
2. If we fail to cache something, then that seems like a bug.
3. Query compilation usually does have a measurable cost.

Stepping back, maybe the useful thing we could do here is somehow surface cache hits and misses. We have seen cases where bugs in EF or manually built expression tree queries can cause a new query that should use a cache entry to actually miss and create a new cache entry every time. Still not sure how to recognize this as different from the case where each query really is different and needs a new cache entry.

[roji]

EF Core doesn't cache the relational command when a parameterized array is used with Contains, and we generate a query with SQL IN with the array values expanded to constants (but note that we still cache at the first, query-cache level). Not sure if there are other cases.

EF will start surfacing cache hits and misses (both the first query cache and the second relational command cache) should get surfaced at part of dotnet/efcore#18016.

[NickCraver]

Thanks for the info!

@roji I see in that issue counters are being added (awesome), but is there a plan to have a query (as would be shown in MiniProfiler) that it was a cache miss?

[roji]

You're looking to get the queries (i.e. SQL) where there was a miss, right? There's no plans for anything like that AFAIK. One way to do this would be to add the cache hit/miss information to our DiagnosticSource logging (which already exists), and then something like MiniProfiler could aggregate it out and do whatever it wants with it - does that make sense?

[NickCraver]

Yep, absolutely - that's how it listens today :) If we could add that info to the concrete payload, it'd be trivial to observe. Should we open another issue to consider that, or add to the same?

[roji]

Definitely open another issue - dotnet/efcore#18016 is only about the perf counters. Hopefully it shouldn't be too hard to implement.

One slight complication is that query compilation actually has two caches - a query cache for one part of the compilation process, and a second, relational command cache for parts of the compilation which depend on parameter values (since parameter nullability can affect the SQL we generate). It's probably reasonable to say that a miss in either of these should count as a general cache miss, unless you want deep inside info, in which case you need both. EF Core should probably just expose both and let the consumers decide whatever they want.

[smitpatel]

For expression tree cache - we cache everything. There is no mechanism exist which would avoid putting the compiled delegate in cache. We had cases in past where people were seeing cache miss but they were really different expression trees from language perspective. And most cases resolution was to correct the manually built expression tree. There can always be case, if we extract parameters from the expression tree in certain way then it may make more expression trees look similar to cache. I believe that can only be detected via manual observation and we cannot say for sure that if something was not found in cache then it was issue rather than just a different true.

For relational command caching, as Shay said we don't cache Contains case and may be something more (as providers can also override). Generally this case is arising when we truly cannot cache. e.g. Contains case, the generated SQL is different most times. The only place where cache entry could be used is actually to store in cache based on the value passed to Contains (or similar for other constructs). See dotnet/efcore#17598

Apart from above unknowns, I doubt that we as EF Core can say to customers with confidence that we should have cached that but we did not. We can provide info on every cache miss if that is helpful.

[roji]

I doubt that we as EF Core can say to customers with confidence that we should have cached that but we did not.

Yeah, I agree - I think the intent here is just to surface whether the query was a miss or a hit (for both caches), nothing more.