Performance regression: DateTime.UtcNow and DateTimeOffset.UtcNow 2.5x slower

[adamsitnik]

DateTime.UtcNow and DateTimeOffset.UtcNow are 2.5x slower compared to 2.2

[Benchmark]
public DateTimeOffset GetUtcNow() => DateTimeOffset.UtcNow;

[Benchmark]
public DateTime GetUtcNow() => DateTime.UtcNow;

Repro

git clone https://github.com/dotnet/performance.git
cd performance
# if you don't have cli installed and want python script to download the latest cli for you
py .\scripts\benchmarks_ci.py -f netcoreapp2.2 netcoreapp3.0 --filter *GetUtcNow*
# if you do
dotnet run -p .\src\benchmarks\micro\MicroBenchmarks.csproj -c Release -f netcoreapp2.2 --filter *GetUtcNow* --runtimes netcoreapp2.2 netcoreapp3.0 --join

BenchmarkDotNet=v0.11.3.1003-nightly, OS=Windows 10.0.18362
Intel Xeon CPU E5-1650 v4 3.60GHz, 1 CPU, 12 logical and 6 physical cores
.NET Core SDK=3.0.100-preview8-013262
   [Host]     : .NET Core 2.2.6 (CoreCLR 4.6.27817.03, CoreFX 4.6.27818.02), 64bit RyuJIT
   Job-BYJCMJ : .NET Core 2.2.6 (CoreCLR 4.6.27817.03, CoreFX 4.6.27818.02), 64bit RyuJIT
   Job-JSSCYO : .NET Core 3.0.0-preview8-27916-02 (CoreCLR 4.700.19.36302, CoreFX 4.700.19.36514), 64bit RyuJIT

Type	Method	Toolchain	Mean
Perf_DateTime	GetUtcNow	netcoreapp2.2	25.12 ns
Perf_DateTime	GetUtcNow	netcoreapp3.0	70.91 ns
Perf_DateTimeOffset	GetUtcNow	netcoreapp2.2	38.19 ns
Perf_DateTimeOffset	GetUtcNow	netcoreapp3.0	91.96 ns

/cc @danmosemsft

[EgorBo]

I guess it's a cost of dotnet/coreclr#21420 (leap seconds support)

[adamsitnik]

/cc @billwert @DrewScoggins

[stephentoub]

I guess it's a cost of dotnet/coreclr#21420 (leap seconds support)

It is. You can see this pretty clearly by just setting s_systemSupportsLeapSeconds to false.

On my machine it ends up being true:

Method	Toolchain	Mean	Error	StdDev	Ratio
GetDateTimeOffsetUtcNow	netcoreapp2.1	32.22 ns	0.1057 ns	0.0989 ns	1.00
GetDateTimeOffsetUtcNow	netcoreapp3.0	71.98 ns	0.5065 ns	0.4490 ns	2.24

and when I set it to false:

Method	Toolchain	Mean	Error	StdDev	Ratio
GetDateTimeOffsetUtcNow	netcoreapp2.1	32.18 ns	0.0193 ns	0.0180 ns	1.00
GetDateTimeOffsetUtcNow	netcoreapp3.0	31.91 ns	0.0373 ns	0.0349 ns	0.99

I think that probably makes this "by design", but @tarekgh should comment.

[danmoseley]

Might be worth seeing whether we can reduce the cost though, if that wasn't already done at the time.

[tarekgh]

Yes this is expected because of the leap seconds support.

Might be worth seeing whether we can reduce the cost though, if that wasn't already done at the time.

I already looked at that before and what we have the best we can have now till we get more new Windows APIs which may help.

[danmoseley]

Fair enough.

[tarekgh]

@stephentoub also reminded me about, there is a way to disable the leap seconds handling on the machine. That should give the perf back if anyone really sensitive to that.

https://techcommunity.microsoft.com/t5/Networking-Blog/Leap-Seconds-for-the-IT-Pro-What-you-need-to-know/ba-p/339811

However, if you have a heterogenous time-sensitive environment you can revert to the prior operating system behavior and disable leap seconds across the board by adding the following registry key:

HKLM:\SYSTEM\CurrentControlSet\Control\LeapSecondInformation

 Type : "REG_DWORD"
Name : Enabled
Value : 0 Disables the system-wide setting
Value : 1 Enables the system-wide setting

[EgorBo]

@tarekgh maybe these two calls can be merged into a single internal call? https://github.com/dotnet/coreclr/blob/master/src/System.Private.CoreLib/shared/System/DateTime.Windows.cs#L21-L22

[tarekgh]

@EgorBo I don't think this will make much difference. The second call is inlined anyway.

https://github.com/dotnet/coreclr/blob/7f1dd83ddb159e2469b85145f228fa60ab3682e2/src/System.Private.CoreLib/shared/System/DateTime.Windows.cs#L67

[tarekgh]

I moved this to future milestone for now. feel free to bring it back if you feel otherwise.

[EgorBo]

Also, maybe it makes sense to introduce a COMPlus_LeapSecondsSupport env variable to be able to turn that behavior off for a specific app?

[tarekgh]

Also, maybe it makes sense to introduce a COMPlus_LeapSecondsSupport env variable to be able to turn that behavior off for a specific app?

That is will not be good because if the system support leap seconds and we disable the handling in the framework, you will start seeing time difference between what we report and what the system report (when calling Now functionality). the framework has to comply with what the system is doing.

[adamsitnik]

Just to make sure I confirm that OSes other than Windows are not affected:

System.Tests.Perf_DateTime.GetUtcNow

conclusion	Base	Diff	Base/Diff	Modality	Base Runtime	Diff Runtime	Arch	Processor Name	Operating System
Same	20.13	20.02	1.01		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Xeon CPU E5-1650 v4 3.60GHz	ubuntu 18.04
Slower	23.90	68.20	0.35		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Xeon CPU E5-1650 v4 3.60GHz	Windows 10.0.18362
Same	38.28	37.29	1.03		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-01	64bit	Intel Xeon CPU E5-2673 v4 2.30GHz	ubuntu 16.04
Same	39.22	38.84	1.01		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-01	64bit	Intel Xeon CPU E5-2673 v4 2.30GHz	ubuntu 18.04
Same	34.76	34.66	1.00		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Core i7-5557U CPU 3.10GHz (Broadwell)	macOS Mojave 10.14.5
Slower	25.93	77.56	0.33		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Core i7-5557U CPU 3.10GHz (Broadwell)	Windows 10.0.18362
Slower	21.10	63.59	0.33		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Core i7-7700 CPU 3.60GHz (Kaby Lake)	Windows 10.0.18362
Slower	34.39	81.64	0.42		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	AMD Ryzen 7 1800X	Windows 10.0.18362
Slower	33.98	136.04	0.25	several?	.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	32bit	Intel Xeon CPU E5-1650 v4 3.60GHz	Windows 10.0.18362

System.Tests.Perf_DateTimeOffset.GetUtcNow

conclusion	Base	Diff	Base/Diff	Modality	Base Runtime	Diff Runtime	Arch	Processor Name	Operating System
Same	40.62	38.68	1.05		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Xeon CPU E5-1650 v4 3.60GHz	ubuntu 18.04
Slower	36.06	79.45	0.45		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Xeon CPU E5-1650 v4 3.60GHz	Windows 10.0.18362
Same	69.96	69.97	1.00		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-01	64bit	Intel Xeon CPU E5-2673 v4 2.30GHz	ubuntu 16.04
Faster	73.01	68.54	1.07		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-01	64bit	Intel Xeon CPU E5-2673 v4 2.30GHz	ubuntu 18.04
Same	59.95	57.15	1.05		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Core i7-5557U CPU 3.10GHz (Broadwell)	macOS Mojave 10.14.5
Slower	40.69	92.05	0.44		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Core i7-5557U CPU 3.10GHz (Broadwell)	Windows 10.0.18362
Slower	31.87	74.86	0.43		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	Intel Core i7-7700 CPU 3.60GHz (Kaby Lake)	Windows 10.0.18362
Slower	47.93	97.43	0.49		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	64bit	AMD Ryzen 7 1800X	Windows 10.0.18362
Slower	66.75	158.34	0.42		.NET Core 2.2.6	.NET Core 3.0.0-preview8-27919-09	32bit	Intel Xeon CPU E5-1650 v4 3.60GHz	Windows 10.0.18362

[adamsitnik]

@tarekgh I am currently profiling all the issues that I've reported in the last few weeks and I want to get a better understanding of how we've implemented leap second support. Please excuse me if my questions are dummy ;)

In the profiles for 3.0 the most expensive method is FileTimeToSystemTime which is a mapping from FileTime to SystemTime:

In 2.2 this method was not used.

From the callstack and the code I can see that:

1. The FileTime is obtained from a call to kernelbase!GetSystemTimePreciseAsFileTime which internally calls ntdll!RtlGetSystemTimePrecise
2. FileTime is mapped to SystemTime using kernelbase!FileTimeToSystemTime. This is very expensive
3. If systemTime.wSecond > 59 then it's the leap second case and few important fields are set to some certain values (this is fast)

My questions:

1. Why don't we just call ntdll!RtlGetSystemTimePrecise which presumably returns a SystemTime and would allow us to avoid the expensive mapping? Does the mapping itself contains the expensive leap second support logic?
2. Would calling GetSystemTime instead getting the FileTime and mapping it to a SystemTime reduce the time it takes to get it? I can see that today it's a fallback when the mapping fails.
3. Would it be possible to move the > 59 seconds check to managed code and move the edge case (user calls DateTime.UtcNow exactly when the leap second happens) from the hot path?

public static DateTime UtcNow
{
    get
    {
        long ticks = 0;
        ticks = GetSystemTimeAsFileTime();

        DateTime result = new DateTime(((ulong)(ticks + FileTimeOffset)) | KindUtc);
        
        int second = result.Second;
        if (second > 59)
        {
            result = result.AddSeconds(-second + 59);
        }
        
        return result;
    }
}