Microsoft.Extensions.Caching.Memory.MemoryCache: Reduce DateTime.UtcNow calls

[NickCraver]

In a few Microsoft.Extensions.Caching.Memory.MemoryCache hot paths, we're doing a syscall to get the current time twice. It's far from ideal since the cost is a significant portion of the overall time. This is step 1, minor and non-breaking for a ~30% gain in performance. The current 2 time calls are:

• Once to see if the item we fetched is still valid (or if it has passed expiration)
• Once to see if we should kickoff a background task to start culling the cache

It turns out DateTime.UtcNow is quite expensive since .NET Core 3.x (details in #13091) - in doing benchmarks on memory cache (honestly more for allocation reasons), we noticed the overhead here.

Simple benchmarks (will PR to dotnet/performance) at: MemoryCacheTests.cs

BenchmarkDotNet=v0.12.1, OS=Windows 10.0.19041.264 (2004/?/20H1)
Intel Core i7-7700HQ CPU 2.80GHz (Kaby Lake), 1 CPU, 8 logical and 4 physical cores
.NET Core SDK=5.0.100-preview.4.20258.7
  [Host]     : .NET Core 5.0.0 (CoreCLR 5.0.20.25106, CoreFX 5.0.20.25106), X64 RyuJIT
  Job-PVKROK : .NET Core 5.0.0 (CoreCLR 5.0.20.25106, CoreFX 5.0.20.25106), X64 RyuJIT

PowerPlanMode=00000000-0000-0000-0000-000000000000  Arguments=/p:DebugType=portable  IterationTime=250.0000 ms
MaxIterationCount=20  MinIterationCount=15  WarmupCount=1

Before PR

Method	Mean	Error	StdDev	Median	Min	Max	Gen 0	Allocated
GetHit	290.1 ns	3.68 ns	3.26 ns	289.2 ns	285.9 ns	296.6 ns	-	-
GetMiss	243.4 ns	9.07 ns	10.08 ns	240.9 ns	230.3 ns	269.6 ns	-	-
SetOverride	661.3 ns	40.50 ns	46.64 ns	651.9 ns	583.2 ns	761.4 ns	0.1317	416 B

After PR

Method	Mean	Error	StdDev	Median	Min	Max	Gen 0	Allocated
GetHit	212.2 ns	4.33 ns	4.81 ns	213.2 ns	202.4 ns	220.8 ns	-	-
GetMiss	159.3 ns	9.28 ns	10.69 ns	154.0 ns	146.6 ns	177.3 ns	-	-
SetOverride	544.1 ns	14.39 ns	16.57 ns	541.7 ns	520.1 ns	571.1 ns	0.1319	416 B

This is a hopefully low-contention first pass at a cheap win in MemoryCache. A follow-up (I'll open a global issue) would be to not call StartScanForExpiredItems in the hot path, and instead move the cleanup process to a background timer. I'll fire up an issue to discuss those other follow-ups.

[NickCraver]

What's needed to poke the remaining builds here? Is it something someone can kick please?

[davidfowl]

That was easy 😄

[maryamariyan]

/azp run runtime

[azure-pipelines]

Azure Pipelines successfully started running 1 pipeline(s).

[ericstj]

LGTM. Thanks for the contribution!

[ericstj]

Actually, looks like a conflict came in. @NickCraver can you resolve, please?

[ericstj]

Nifty, GitHub web editor let me resolve this. Kudos github.

[ghost]

Hello @ericstj!

Because this pull request has the auto-merge label, I will be glad to assist with helping to merge this pull request once all check-in policies pass.

p.s. you can customize the way I help with merging this pull request, such as holding this pull request until a specific person approves. Simply @mention me (@msftbot) and give me an instruction to get started! Learn more here.

[benaadams]

Guessing that run isn't going to finish?

Azure Pipelines / runtime (Build iOS x86 Debug AllSubsets_Mono)
started 1d 1h 1m 42s ago