Runtime: Perf: DateTime.Now 3x slower on Linux

[ianhays]

Perf test:

```c#
[Benchmark]
public void GetNow()
{
DateTime dt;
foreach (var iteration in Benchmark.Iterations)
using (iteration.StartMeasurement())
for (int i = 0; i < 10000; i++)
{
dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
}
}

Linux results:

```xml
        <performance runid="System.Runtime.Tests.Perf_DateTime.GetNow-Linux" etl="/home/ianha/uptonogood/results/System.Runtime.Tests.Perf_DateTime.GetNow-Linux.csv">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="65.38629999756813" />
            <iteration index="1" Duration="61.40879999101162" />
            <iteration index="2" Duration="64.916299998760223" />
            <iteration index="3" Duration="55.876999989151955" />
            <iteration index="4" Duration="55.115500003099442" />
            <iteration index="5" Duration="59.215800002217293" />
            <iteration index="6" Duration="55.531300008296967" />
            <iteration index="7" Duration="55.105000004172325" />
            <iteration index="8" Duration="56.883499994874" />
            <iteration index="9" Duration="56.871900007128716" />
            <iteration index="10" Duration="55.777700006961823" />
            <iteration index="11" Duration="54.972599998116493" />
            <iteration index="12" Duration="54.644500002264977" />
            <iteration index="13" Duration="91.604200005531311" />
            <iteration index="14" Duration="56.039199993014336" />
            <iteration index="15" Duration="59.405699998140335" />
            <iteration index="16" Duration="59.423000007867813" />
            <iteration index="17" Duration="60.069600000977516" />
          </iterations>
        </performance>

Windows results:

        <performance runid="System.Runtime.Tests.Perf_DateTime.GetNow-WindowsCore" etl="D:\git\corefx\bin\tests\Windows_NT.AnyCPU.Release\system.runtime.tests\dnxcore50\System.Runtime.Tests.Perf_DateTime.GetNow-WindowsCore.etl">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="20.669701876065005" />
            <iteration index="1" Duration="22.393721341775745" />
            <iteration index="2" Duration="20.51631631751502" />
            <iteration index="3" Duration="20.602132401387848" />
            <iteration index="4" Duration="19.901348566971251" />
            <iteration index="5" Duration="19.689801941610312" />
            <iteration index="6" Duration="19.730571709031551" />
            <iteration index="7" Duration="19.689801941610312" />
            <iteration index="8" Duration="19.4235154886627" />
            <iteration index="9" Duration="20.746394655340168" />
            <iteration index="10" Duration="19.552097062837674" />
            <iteration index="11" Duration="19.373622416643684" />
            <iteration index="12" Duration="19.429217554036313" />
            <iteration index="13" Duration="19.524442045775572" />
            <iteration index="14" Duration="19.493935996026721" />
            <iteration index="15" Duration="19.33256754595368" />
            <iteration index="16" Duration="19.180322400478303" />
            <iteration index="17" Duration="19.447179059963219" />
            <iteration index="18" Duration="19.438911065171396" />
            <iteration index="19" Duration="19.340550437476736" />
            <iteration index="20" Duration="19.799281596783544" />
            <iteration index="21" Duration="19.912752697718361" />
            <iteration index="22" Duration="19.690657251416269" />
            <iteration index="23" Duration="20.093223066793144" />
            <iteration index="24" Duration="20.79058566198546" />
            <iteration index="25" Duration="20.538269269203283" />
            <iteration index="26" Duration="19.73883970382326" />
            <iteration index="27" Duration="20.204128238309977" />
            <iteration index="28" Duration="19.688946631804129" />
            <iteration index="29" Duration="19.661291614742368" />
            <iteration index="30" Duration="19.702916691969449" />
            <iteration index="31" Duration="19.440906788052189" />
            <iteration index="32" Duration="19.573194704719981" />
            <iteration index="33" Duration="19.61653040155943" />
            <iteration index="34" Duration="20.462716903002956" />
            <iteration index="35" Duration="19.710044273686663" />
            <iteration index="36" Duration="19.620806950589667" />
            <iteration index="37" Duration="19.614534678678638" />
            <iteration index="38" Duration="19.191156324688109" />
            <iteration index="39" Duration="19.816957999441911" />
            <iteration index="40" Duration="23.061433197025508" />
            <iteration index="41" Duration="21.294363137743858" />
            <iteration index="42" Duration="21.79243854812853" />
            <iteration index="43" Duration="20.098069822360685" />
            <iteration index="44" Duration="20.516031214246368" />
            <iteration index="45" Duration="21.206551330990351" />
            <iteration index="46" Duration="20.443900087270094" />
            <iteration index="47" Duration="20.521448176351214" />
            <iteration index="48" Duration="20.199281482742435" />
            <iteration index="49" Duration="20.074121147791629" />
            <iteration index="50" Duration="19.988305063918688" />
          </iterations>
        </performance>

[ianhays]

Posting results for DateTime.UtcNow.

Test:

```c#
[Benchmark]
public void GetUtcNow()
{
DateTime dt;
foreach (var iteration in Benchmark.Iterations)
using (iteration.StartMeasurement())
for (int i = 0; i < 10000; i++)
{
dt = DateTime.UtcNow; dt = DateTime.UtcNow; dt = DateTime.UtcNow;
dt = DateTime.UtcNow; dt = DateTime.UtcNow; dt = DateTime.UtcNow;
dt = DateTime.UtcNow; dt = DateTime.UtcNow; dt = DateTime.UtcNow;
}
}

Linux results:

```xml
      <test name="System.Runtime.Tests.Perf_DateTime.GetUtcNow" type="System.Runtime.Tests.Perf_DateTime" method="GetUtcNow" time="1.1753806" result="Pass">
        <traits>
          <trait name="Benchmark" value="true" />
        </traits>
        <performance runid="System.Runtime.Tests.dll-Linux" etl="/home/ianha/uptonogood/results/System.Runtime.Tests.dll-Linux.csv">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="50.062900006771088" />
            <iteration index="1" Duration="58.910099983215332" />
            <iteration index="2" Duration="50.4122000336647" />
            <iteration index="3" Duration="52.279699981212616" />
            <iteration index="4" Duration="70.724200010299683" />
            <iteration index="5" Duration="68.703700006008148" />
            <iteration index="6" Duration="49.003100037574768" />
            <iteration index="7" Duration="48.8779000043869" />
            <iteration index="8" Duration="48.577499985694885" />
            <iteration index="9" Duration="48.698800027370453" />
            <iteration index="10" Duration="50.401099979877472" />
            <iteration index="11" Duration="48.596700012683868" />
            <iteration index="12" Duration="48.456699967384338" />
            <iteration index="13" Duration="48.579199969768524" />
            <iteration index="14" Duration="49.266300022602081" />
            <iteration index="15" Duration="48.55460000038147" />
            <iteration index="16" Duration="48.653400003910065" />
            <iteration index="17" Duration="48.85809999704361" />
            <iteration index="18" Duration="48.60400003194809" />
            <iteration index="19" Duration="48.772899985313416" />
            <iteration index="20" Duration="81.28600001335144" />
          </iterations>
        </performance>
      </test>

Windows results:

<test name="System.Runtime.Tests.Perf_DateTime.GetUtcNow" type="System.Runtime.Tests.Perf_DateTime" method="GetUtcNow" time="0.7958168" result="Pass">
        <traits>
          <trait name="Benchmark" value="true" />
        </traits>
        <performance runid="System.Runtime.Tests.Perf_DateTime.GetUtcNow-WindowsCore" etl="D:\git\corefx\bin\tests\Windows_NT.AnyCPU.Release\system.runtime.tests\dnxcore50\System.Runtime.Tests.Perf_DateTime.GetUtcNow-WindowsCore.etl">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="1.5837477544566809" />
            <iteration index="1" Duration="0.78403354181023133" />
            <iteration index="2" Duration="0.69023461989911539" />
            <iteration index="3" Duration="0.63321399867652417" />
            <iteration index="4" Duration="0.68909420747468175" />
            <iteration index="5" Duration="0.68795379505024812" />
            <iteration index="6" Duration="0.63292889557044418" />
            <iteration index="7" Duration="0.70563018762925367" />
            <iteration index="8" Duration="0.78061230453693042" />
            <iteration index="9" Duration="0.70363446588646639" />
            <iteration index="10" Duration="0.64974997883109609" />
            <iteration index="11" Duration="0.70591529073522" />
            <iteration index="12" Duration="0.72359168331433921" />
            <iteration index="13" Duration="0.64433301981489421" />
            <iteration index="14" Duration="0.70563018762914" />
            <iteration index="15" Duration="0.70591529073533366" />
            <iteration index="16" Duration="0.70591529073533366" />
            <iteration index="17" Duration="0.63292889557044418" />
            <iteration index="18" Duration="0.71389817770648278" />
            <iteration index="19" Duration="0.76521673680679214" />
            <iteration index="20" Duration="0.824233079772057" />
            <iteration index="21" Duration="0.69536647580912359" />
            <iteration index="22" Duration="0.68937931058076174" />
            <iteration index="23" Duration="0.71133224975153553" />
            <iteration index="24" Duration="0.74497441627283933" />
            <iteration index="25" Duration="0.63321399867663786" />
            <iteration index="26" Duration="0.746114828697273" />
            <iteration index="27" Duration="0.74611482869715928" />
            <iteration index="28" Duration="0.73499580755878924" />
            <iteration index="29" Duration="0.785459057340745" />
            <iteration index="30" Duration="0.64404791670881423" />
            <iteration index="31" Duration="0.63378420488879783" />
            <iteration index="32" Duration="0.71418328081267646" />
            <iteration index="33" Duration="0.72558740505712649" />
            <iteration index="34" Duration="0.70306425967419273" />
            <iteration index="35" Duration="0.63435441110107149" />
            <iteration index="36" Duration="0.70363446588646639" />
            <iteration index="37" Duration="0.70505998141698" />
            <iteration index="38" Duration="0.72273637399598556" />
            <iteration index="39" Duration="0.78888029461415954" />
            <iteration index="40" Duration="0.81539488348266786" />
            <iteration index="41" Duration="0.79258663499365412" />
            <iteration index="42" Duration="0.719315136722571" />
            <iteration index="43" Duration="0.64461812292108789" />
            <iteration index="44" Duration="0.70391956899254637" />
            <iteration index="45" Duration="0.71418328081256277" />
            <iteration index="46" Duration="0.70563018762925367" />
            <iteration index="47" Duration="0.63349910178260416" />
            <iteration index="48" Duration="0.70420467209862636" />
            <iteration index="49" Duration="0.78802498529580589" />
            <iteration index="50" Duration="0.70448977520470635" />
            <iteration index="51" Duration="0.63321399867663786" />
            <iteration index="52" Duration="0.70391956899254637" />
...

[ianhays]

@stephentoub

[stephentoub]

Interesting. This suggest that on Windows, DateTime.Now is 100x slower than DateTime.UtcNow (which makes some sense, given that Now is a wrapper for UtcNow that calls UtcNow and then does timezone translation), but that on Linux, DateTime.Now is approximately the same speed as DateTime.UtcNow...? If that's true, that begs two questions:

• Why is TimeZoneInfo.GetDateTimeNowUtcOffsetFromUtc apparently blazingly fast on Linux compared to on Windows?
• Why is DateTime.UtcNow ~70x slower on Linux compared to on Windows?

[eerhardt]

Do we have some sort of profiler trace for these runs? (Do we have a profiler at all on Linux?) I don't see one, but I'm assuming we do given @stephentoub's comments above.

[stephentoub]

given @stephentoub's comments above

My comments were simply based on the timings in Ian's data; I haven't profiled beyond that, but was planning to shortly.

Do we have a profiler at all on Linux?

I've been using oprofile. @brianrob and folks have also been working on bringing up support for perf_event, which I believe includes support for both managed and native frames, whereas oprofile is just native. @brianrob, are there instructions on the wiki somewhere for using perf_event to profile managed code on Linux?

[stephentoub]

@ianhays, I'm seeing very different results on my Linux machine, with DateTime.Now being 10x slower than DateTime.UtcNow (which makes sense). Do you know why your numbers show them being basically the same?

[ianhays]

Hmm, odd. I ran only that particular test, so there wouldnt have been any interference from other tests. I"ll toy around with the runner a bit and try writing a test in the old style and compare the results.

[ianhays]

Hmmm. I'm still getting the same thing. Would you mind posting your results? I'm getting similar numbers regardless of the method used. Perhaps the xunit runner is messing with my results somehow?

Xunit tests:

        [Fact]
        public void GetNow()
        {
            DateTime dt;
            Stopwatch watch = new Stopwatch();
            watch.Start();
            for (int i = 0; i < 10000; i++)
            {
                dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
                dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
                dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
            }
            watch.Stop();
            Console.WriteLine(watch.Elapsed);
        }

        [Fact]
        public void GetUtcNow()
        {
            DateTime dt;
            Stopwatch watch = new Stopwatch();
            watch.Start();
            for (int i = 0; i < 10000; i++)
            {
                dt = DateTime.UtcNow; dt = DateTime.UtcNow; dt = DateTime.UtcNow;
                dt = DateTime.UtcNow; dt = DateTime.UtcNow; dt = DateTime.UtcNow;
                dt = DateTime.UtcNow; dt = DateTime.UtcNow; dt = DateTime.UtcNow;
            }
            watch.Stop();
            Console.WriteLine(watch.Elapsed);
        }

LINUX results:
DateTime.Now: 00:00:00.0602122
DateTime.UtcNow: 00:00:00.0534786

I'm running the tests individually, so they arent being affected by other tests.

[stephentoub]

For UtcNow:

using System;
using System.Diagnostics;

class Program
{
    static void Main()
    {
        var sw = new Stopwatch();
        DateTime d;
        while (true)
        {
            sw.Restart();
            for (int i = 0; i < 10000; i++)
            {
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
                d = DateTime.UtcNow;
            }
            sw.Stop();
            Console.WriteLine(sw.Elapsed);
        }
    }
}

produces output:

stoub@SToubLinux1:~/coreclrfx$ ./corerun Repro.exe 
00:00:00.0966182
00:00:00.1084876
00:00:00.1166821
00:00:00.1050522
00:00:00.1074539
00:00:00.1039602
00:00:00.1234532
00:00:00.1090699
00:00:00.1185556
00:00:00.1042511
00:00:00.1159957
00:00:00.1104675
00:00:00.1171916
00:00:00.1074836
00:00:00.1230914
00:00:00.1153383
00:00:00.1078338
00:00:00.1047764
00:00:00.1144853
00:00:00.1104871
00:00:00.1050303
00:00:00.1080339
00:00:00.1072088
00:00:00.1140118
^C

For Now:

using System;
using System.Diagnostics;

class Program
{
    static void Main()
    {
        var sw = new Stopwatch();
        DateTime d;
        while (true)
        {
            sw.Restart();
            for (int i = 0; i < 10000; i++)
            {
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
                d = DateTime.Now;
            }
            sw.Stop();
            Console.WriteLine(sw.Elapsed);
        }
    }
}

produces output:

stoub@SToubLinux1:~/coreclrfx$ ./corerun Repro.exe 
00:00:01.3741200
00:00:01.3291032
00:00:01.3047975
00:00:01.2606674
00:00:01.2726876
00:00:01.3025091
00:00:01.2646156
^C

[ianhays]

I figured out the issue. I was setting the time for my Linux machine by modifying /etc/timezone. Setting it to anything else made no difference in the results.

However, when I changed time in a different way:

cd /etc/
rm localtime 
ln -s /usr/share/zoneinfo/US/Pacific localtime

I now get results more similar to yours.

DateTime.Now:

ianha@ianhaU:~/freshstart$ ./corerun sample.exe
00:00:00.8323172
00:00:00.7924459
00:00:00.7839924
00:00:00.7449180
00:00:00.7459969
00:00:00.8055782
00:00:00.7018272
00:00:00.7844741
00:00:00.7513392
00:00:00.7458387
00:00:00.7858744

DateTime.UtcNow

ianha@ianhaU:~/freshstart$ ./corerun sample.exe
00:00:00.0495377
00:00:00.0512952
00:00:00.0521436
00:00:00.0507401
00:00:00.0505466
00:00:00.0512000
00:00:00.0632518
00:00:00.0739951
00:00:00.0510759
00:00:00.0509278
00:00:00.0510857
00:00:00.0508260
00:00:00.0542516
00:00:00.0548994
00:00:00.0826587
00:00:00.0513705
00:00:00.0505477

So the reason they were the same time is because no conversion was happening in DateTime.Now. I guess the contents of /etc/timezone aren't relevant to how we read dates?

[eerhardt]

I guess the contents of /etc/timezone aren't relevant to how we read dates?

Here are the rules for how the "Local" time zone is calculated on Linux:

        /// <summary>
        /// Gets the tzfile raw data for the current 'local' time zone using the following rules.
        /// 1. Read the TZ environment variable.  If it is set, use it.
        /// 2. Look for the data in /etc/localtime.
        /// 3. Look for the data in GetTimeZoneDirectory()/localtime.
        /// 4. Use UTC if all else fails.
        /// </summary>

[eerhardt]

@ianhays - I now get results more similar to yours.

So now if you compare DateTime.Now on Linux to Windows, how much slower is Linux than Windows?

[ianhays]

Linux DateTime.Now shows as being 35x slower than Windows DateTime.Now.
Linux DateTime.UtcNow shows as being 71x slower than Windows DateTime.UtcNow
Linux DateTime.Now shows as being 14x slower than Linux DateTime.UtcNow
Windows DateTime.Now shows as being 28x slower than Windows DateTime.UtcNow

Results:

Linux DateTime.Now:

<test name="System.Runtime.Tests.Perf_DateTime.GetNow" type="System.Runtime.Tests.Perf_DateTime" method="GetNow" time="2.3153404" result="Pass">
        <traits>
          <trait name="Benchmark" value="true" />
        </traits>
        <performance runid="System.Runtime.Tests.dll-Linux" etl="/home/ianha/freshstart/results/System.Runtime.Tests.dll-Linux.csv">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="710.902899980545" />
            <iteration index="1" Duration="783.28399991989136" />
            <iteration index="2" Duration="761.44449996948242" />
          </iterations>
        </performance>
      </test>

Windows DateTime.Now:

      <test name="System.Runtime.Tests.Perf_DateTime.GetNow" type="System.Runtime.Tests.Perf_DateTime" method="GetNow" time="1.0535026" result="Pass">
        <traits>
          <trait name="Benchmark" value="true" />
        </traits>
        <performance runid="System.Runtime.Tests.dll-WindowsCore" etl="D:\git\corefx\System.Runtime.Tests.dll-WindowsCore.etl">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="22.513451877304192" />
            <iteration index="1" Duration="23.771896987686091" />
            <iteration index="2" Duration="22.960493547689111" />
            <iteration index="3" Duration="20.919440411027495" />
            <iteration index="4" Duration="21.135263462354828" />
            <iteration index="5" Duration="20.797701384717243" />
            <iteration index="6" Duration="20.945954999896003" />
            <iteration index="7" Duration="21.480523323857483" />
            <iteration index="8" Duration="21.956360407959778" />
            <iteration index="9" Duration="21.527565336366138" />
            <iteration index="10" Duration="21.164914185390671" />
            <iteration index="11" Duration="21.444030126275038" />
            <iteration index="12" Duration="21.404115691419179" />
            <iteration index="13" Duration="21.22478583767429" />
            <iteration index="14" Duration="20.933695566333085" />
            <iteration index="15" Duration="21.317159244054778" />
            <iteration index="16" Duration="21.314023109887557" />

Linux DateTime.UtcNow:

      <test name="System.Runtime.Tests.Perf_DateTime.GetUtcNow" type="System.Runtime.Tests.Perf_DateTime" method="GetUtcNow" time="1.1731546" result="Pass">
        <traits>
          <trait name="Benchmark" value="true" />
        </traits>
        <performance runid="System.Runtime.Tests.dll-Linux" etl="/home/ianha/freshstart/results/System.Runtime.Tests.dll-Linux.csv">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="49.706000089645386" />
            <iteration index="1" Duration="49.630699992179871" />
            <iteration index="2" Duration="50.062600016593933" />
            <iteration index="3" Duration="50.529199957847595" />
            <iteration index="4" Duration="50.95930004119873" />
            <iteration index="5" Duration="55.71750009059906" />
            <iteration index="6" Duration="87.086899995803833" />
            <iteration index="7" Duration="52.98769998550415" />
            <iteration index="8" Duration="49.0903000831604" />
            <iteration index="9" Duration="49.87529993057251" />
            <iteration index="10" Duration="49.849799990653992" />
            <iteration index="11" Duration="50.230200052261353" />
            <iteration index="12" Duration="50.054800033569336" />
            <iteration index="13" Duration="91.4430000782013" />
            <iteration index="14" Duration="53.794600009918213" />
            <iteration index="15" Duration="52.5864999294281" />
            <iteration index="16" Duration="50.358999967575073" />
            <iteration index="17" Duration="50.162099957466125" />
            <iteration index="18" Duration="49.21780002117157" />
            <iteration index="19" Duration="95.615599989891052" />
          </iterations>
        </performance>
      </test>

Windows DateTime.UtcNow

      <test name="System.Runtime.Tests.Perf_DateTime.GetUtcNow" type="System.Runtime.Tests.Perf_DateTime" method="GetUtcNow" time="0.8070977" result="Pass">
        <traits>
          <trait name="Benchmark" value="true" />
        </traits>
        <performance runid="System.Runtime.Tests.dll-WindowsCore" etl="D:\git\corefx\System.Runtime.Tests.dll-WindowsCore.etl">
          <metrics>
            <Duration displayName="Duration" unit="msec" />
          </metrics>
          <iterations>
            <iteration index="0" Duration="1.385601095708239" />
            <iteration index="1" Duration="0.72786822990599376" />
            <iteration index="2" Duration="0.746399931803353" />
            <iteration index="3" Duration="0.63406930799487782" />
            <iteration index="4" Duration="0.76379122127616483" />
            <iteration index="5" Duration="0.6899495167930354" />
            <iteration index="6" Duration="0.68709848573189447" />
            <iteration index="7" Duration="0.6343544111009578" />
            <iteration index="8" Duration="0.7119024559636955" />
            <iteration index="9" Duration="0.68681338262581448" />
            <iteration index="10" Duration="0.71190245596358182" />
            <iteration index="11" Duration="0.6765496708056844" />
            <iteration index="12" Duration="0.68852400126240809" />
            <iteration index="13" Duration="0.69736219755202455" />
            <iteration index="14" Duration="0.65773286580224521" />
            <iteration index="15" Duration="0.71218755906988918" />
            <iteration index="16" Duration="0.82480328598433061" />
            <iteration index="17" Duration="0.91632138304657929" />
            <iteration index="18" Duration="0.68852400126240809" />
            <iteration index="19" Duration="0.63406930799487782" />
            <iteration index="20" Duration="0.79458235673632771" />
            <iteration index="21" Duration="0.68966441368695541" />
            <iteration index="22" Duration="0.68681338262581448" />
            <iteration index="23" Duration="0.63406930799487782" />
            <iteration index="24" Duration="0.68795379505024812" />

[eerhardt]

My naïve question: How are we ensuring hardware equivalence between Windows and Linux machines? Are they both physical machines with similar specs? Both VMs on the same physical machine?
Do other low-level .NET APIs have roughly the same perf aspects between the two machines?

[ianhays]

Until we get a dedicated set of perf testing machines (~November), I'll just be running the tests on my local machine: Windows 10 with a Ubuntu 14.04 VM running in HyperV. I expect a bit of overhead from the VM and take that into account when deciding when to open new issues for perf. I will generally only open an issue for a test if the difference Linux is twice as slow as Windows and I can replicate the results in several different forms.

I've posted all of the results on my private internal share if you'd like to get an idea of general outlook on perf. \bvtsrv2\Team\ianha\perf\results\10-6-2015\AllTests_10-6-2015.

Most low-level APIs are comparable between systems.

[mj1856]

Why is TimeZoneInfo.GetDateTimeNowUtcOffsetFromUtc apparently blazingly fast on Linux compared to on Windows?

That is interesting, because that method actually has a separate fast-path for Windows, so you would think the Unix version would be slower. It may be worth testing to see if disabling the fast-path helps. Perhaps it's not so fast anymore.

Why is DateTime.UtcNow ~70x slower on Linux compared to on Windows?

DateTime.UtcNow calls GetSystemTimeAsFileTime, which is native to Win32. We're emulating that for Linux using gettimeofday. I think that's here, assuming I'm understanding what the /src/pal subtree is for.

It would probably be much faster if we did #if in the DateTime.UtcNow implementation to make the appropriate native call per platform directly. There's no need to go through a FileTime translation when running on Linux/OSX.

Also, my understanding is that gettimeofday should be considered deprecated, replaced with clock_gettime(CLOCK_REALTIME). I'm not an expert in that area, but that's what I read.

[AlexGhiondea]

It sounds like there is some more performance investigation needed.

[tmds]

9x10000 calls on my linux machine (no VM):

• native gettimeofday/clock_gettime takes about 1.9ms.
• DateTime.UtcNow takes about 2.5ms.
• PInvoke clock_gettime shim (returning 100ns ticks as long) takes about 2.1ms.

[eerhardt]

I ran the following program on my machines:

```C#
using System;
using System.Diagnostics;

namespace TZPerfTest
{
class Program
{
static void Main(string[] args)
{
DateTime dt;
for (int i = 0; i < 20; i++)
{
Stopwatch watch = new Stopwatch();
watch.Start();
for (int j = 0; j < 10000; j++)
{
dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
dt = DateTime.Now; dt = DateTime.Now; dt = DateTime.Now;
}

            Console.Write(watch.ElapsedMilliseconds + "<br>");
        }
    }
}

}
```

With America/Chicago/Central Standard Time as the time zone:

(Note: Includes the change for https://github.com/dotnet/coreclr/pull/10507)

| Windows x64 | MacBook Pro | Ubuntu 14.04 VM |
| :-------------------------------------: | :-------------------------------------: | :-------------------------------------: |
22
21
20
19
20
19
20
20
20
22
20
20
20
22
19
20
21
20
20
19
| 147
144
138
146
141
137
142
146
138
141
142
146
144
140
137
138
138
141
140
140
| 162
168
156
156
156
156
163
157
160
156
156
156
157
186
158
156
157
158
156
156
|

I then changed my time zone to one with out any daylight savings adjustment rules export TZ=Zulu. Here are the results of the same program:

MacBook Pro | Ubuntu 14.04 VM |
| -------- | :-------------------------------------: |
9
8
7
7
8
7
8
9
8
8
8
7
7
7
7
7
7
8
7
7
| 11
11
11
11
11
11
10
11
11
11
11
11
11
11
11
11
11
11
11
11
|

So I'm pretty certain all the time being spent in DateTime.Now on Unix is trying to find the correct adjustment rule for the current time.

On Windows, we have an optimization for DateTime.Now, which we don't have on Unix. The exact same optimization won't work on Unix, but I think we can do something similar.

The idea is to cache the current AdjustmentRule for DateTime.Now, just like we do on Windows. Each time we get into this code path, we check if the cached rule is still valid for the DateTime. If it is, use it. If it isn't, throw it away and find the new valid one and cache it. 99.9% of the time, it will be valid. The only time it won't be valid is when a time zone offset change has occurred (i.e. Daylight Savings Time swtiched), since the time it was cached.

I have some other work I need to catch up on, but I'll come back to this idea and test it out if no one has picked it up in the meantime.

[eerhardt]

I spent some time in the last few days investigating this issue. I implemented the optimization I discussed above, but it didn't have any affect on the perf I was seeing.

Using America/Chicago time zone, I still saw:

MacBook Pro |
| -------- |
142
143
143
142
143
143
143
143
142
146
142
143
146
142
143
146
142
141
142

Which didn't affect it at all. So I decided it was time to profile the scenario (which I probably should have done in the beginning to start with).

Here is the trace log from running it on my ubuntu machine.
sampleTrace.trace.zip

Very quickly the issue shows itself:

So it looks like a lot of time is spent calling AdjustmentRule::Equals and TimeZoneInfo::GetPreviousAdjustmentRule. On Unix, there are many cases when determining if a time is daylight savings, we need to get the "previous rule".

So I made a simple change to GetPreviousRule to use object.ReferenceEquals and the time dropped dramatically.

MacBook Pro |
| -------- |
43
39
40
43
44
44
40
44
43
39
40
39
44
39
39
41
42
39
55

I plan on investigating a full fix tomorrow, but I wanted to get my investigation notes out here, in case someone else wants to look at the perf data, and do some investigation themselves.

[mazong1123]

I've also added a thought here may improve the perf in another perspective:
https://github.com/dotnet/coreclr/issues/5717#issuecomment-293535491

[eerhardt]

Using the above investigation data, I decided to try remembering the AdjustmentRule index whenever calling into GetPreviousAdjustmentRule. See https://github.com/eerhardt/coreclr/commit/1316543e5f1833cf6557db62f03658931e56c4cd.

Running the same micro-benchmark above on my MacBookPro using America/Chicago time zone produces the following:

MacBook Pro |
| -------- |
31
28
27
27
27
27
27
32
31
27
29
31
27
29
28
27
27
27
27
27

Which gets us into the range of Windows, which is between 19-22ms on both my machine and @ianhays's above.

See https://github.com/dotnet/coreclr/pull/10948. With that PR, I think we can declare this bug fixed since we are much closer to Windows perf.