Why are Time.realtimeSinceStartup and Time.realtimeSinceStartupAsDouble so slow when called repeatedly?

Question

I have the following Update() code which calculates the approximate number of loops per second:

[MethodImpl(MethodImplOptions.NoOptimization | MethodImplOptions.NoInlining)]
void Update()
{
    long loopCount = 0;
    long maxLoopCount = 500000000; // five hundred million
    double startingTime = Time.realtimeSinceStartupAsDouble;
    while(true)
    {
        loopCount++;
        if(loopCount >= maxLoopCount)
        {
            break;
        }
    }
    double endTime = Time.realtimeSinceStartupAsDouble;
    double elapsedTime = (endTime - startingTime);
    Debug.Log("elapsed time: " + elapsedTime);
    Debug.Log("loop count: " + loopCount);
    Debug.Log("approximate loops per second: " + (loopCount*(1/elapsedTime)));
}

Notice that I used the NoOptimization and NoInlining attributes, which means the loop is not optimized away by the compiler. I checked the debug log and below are the longest elapsed times logged in the console (the slowest loop performance):

elapsed time: 0.249041300000044
loop count: 500000000
approximate loops per second: 2007699124.60267

It can do 500 million loops in just a quarter of a second, which means it can do approximately 2 billion loope per second.

I have a second batch of code which also calculates the approximate number of loops per second, but I used Time.realtimeSinceStartupAsDouble in the loop:

[MethodImpl(MethodImplOptions.NoOptimization | MethodImplOptions.NoInlining)]
void Update()
{
    long loopCount = 0;
    double startingTime = Time.realtimeSinceStartupAsDouble;
    double endTime = startingTime + 1;
    while (true)
    {
        loopCount++;
        if (Time.realtimeSinceStartupAsDouble >= endTime)
        {
            break;
        }
    }
    double elapsedTime = (endTime - startingTime);
    Debug.Log("elapsed time: " + elapsedTime);
    Debug.Log("loop count: " + loopCount);
    Debug.Log("approximate loops per second: " + (loopCount * (1 / elapsedTime)));
}

I checked the debug log and below are the slowest loops logged in the console:

elapsed time: 1
loop count: 27078590
approximate loop per second: 27078590

It can only do 27 million loops per second, in contrast to 2 billion loops per second from earlier. The previous code is approximately 74x faster than the code with Time.realtimeSinceStartupAsDouble. After finding this, I did another test with Time.realtimeSinceStartup instead of the double version.

[MethodImpl(MethodImplOptions.NoOptimization | MethodImplOptions.NoInlining)]
void Update()
{
    long loopCount = 0;
    float startingTime = Time.realtimeSinceStartup;
    float endTime = startingTime + 1;
    while (true)
    {
        loopCount++;
        if (Time.realtimeSinceStartup >= endTime)
        {
            break;
        }
    }
    float elapsedTime = (endTime - startingTime);
    Debug.Log("elapsed time: " + elapsedTime);
    Debug.Log("loop count: " + loopCount);
    Debug.Log("approximate loops per second: " + (loopCount * (1 / elapsedTime)));
}

I checked the debug log and below are the slowest loops logged in the console.

elapsed time: 1
loop count: 24932097
approximate loop per second: 2.49321E+07

It can only do 24 million loops per second, similar to the Time.realtimeSinceStartupAsDouble version.

Does anyone know why it is so slow? Now I'm hesitant to use it inside a loop because it can make the loop significantly slower. What are the alternatives to these two that I can use to do timing inside a loop?

My specifications:

• Unity version: 2022.3.14f1
• Scripting Backend: Mono
• .NET version : .NET framework
• Managed Code Stripping: Disabled
• CPU: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80 Ghz
• OS: Windows 10 Home Single Language

Answer 1

High resolution timers on Windows have always been somewhat slow to query. I found a 20 year old Dr Dobbs article, that reports QueryPerformanceCounter() being around 88 times slower than GetTickCount(), which is remarkably similar to what you just measured.

Also note that doing 2 billion loop iterations per second means that each loop iteration is only taking 2-3 clock cycles on the CPU. Adding almost any work to that loop will make it significantly slower.

The overhead from that timer query was about 0.000000037 seconds, which isn't all that expensive. You could call that function 450,000 times in a single 16ms (60 FPS) frame.

One way to work around that overhead if you want to use it to work out when a whole second has elapsed is to query the timer much less frequently. Something like this:

// Update is called once per frame
[MethodImpl(MethodImplOptions.NoOptimization | MethodImplOptions.NoInlining)]
void Update()
{
    long loopCount = 0;
    float startingTime = Time.realtimeSinceStartup;
    float endTime = startingTime + 1;
    while (true)
    {
        // Extra loop so that the timer function gets queried much less often
        for (int i = 0 ; i < 10000; i++)
        {
            // The work that you want to time goes here
            loopCount++;
        }
        if (Time.realtimeSinceStartup >= endTime)
        {
            break;
        }
    }
    // Use Time.realtimeSinceStartup and not endTime here, as we may go somewhat past endTime
    float elapsedTime = (Time.realtimeSinceStartup - startingTime);
    Debug.Log("elapsed time: " + elapsedTime);
    Debug.Log("loop count: " + loopCount);
    Debug.Log("approximate loop per second: " + (loopCount * (1 / elapsedTime)));
}

Answer 2

I would not use either of these Time properties for timing a loop.

For that, you should use a Stopwatch. It's designed expressly for the purpose of timing how long a particular block of code took to execute (whereas the realtimeSinceStartup... properties are designed to answer how long the game as a whole has been running).

Here's what a Stopwatch version of your function could look like:

void TimeLoopWithStopwatch()
{
    long loopCount = 0;
    var watch = System.Diagnostics.Stopwatch.StartNew();
    
    do 
    {
        loopCount++;
    } while (watch.ElapsedMilliseconds < 1000);
    // Can also initialize endTicks = System.Diagnostics.Stopwatch.Frequency * 1;
    // outside the loop, and compare watch.ElapsedTicks < endTicks, if you prefer.

    watch.Stop();

    double secondsElapsed = watch.Elapsed.TotalMilliseconds / 1000.0;
    Debug.Log($"elapsed time: {secondsElapsed}");
    Debug.Log($"loop count: {loopCount}");
    Debug.Log($"approximate loops per second: {loopCount/secondsElapsed}");
}

Under the hood, a Stopwatch just queries, stores, and subtracts a CPU performance counter, with some convenience methods to convert the result to familiar time units.

In my testing, this Stopwatch approach is measurably faster, though only by a hair if we work in milliseconds.

Timing Strategy	Loops per s	ns per loop	speedup vs double
Untimed Loop	532 Million	2	--
Stopwatch ticks	40 Million	25	+37%
Stopwatch milliseconds	33 Million	30	+14%
RealtimeSinceStartupAsDouble	28-30 Million	33-35	(baseline)
RealtimeSinceStartup	26 Million	38	-10%

This is consistent with Adam's calculation, finding about 37 ns cost per loop for the Unity methods. We can see that about 2 nanoseconds of that is the loop increment/branch (on average - modern processors do wacky things to reorder instructions and run multiple operations in parallel, which complicates the analysis of any one loop iteration, so we can only report on the amortized cost over many loops). The various timer methods add something around 20-40 nanoseconds, which is not a lot (on the order of a dozen cycles) - it just looks like a lot because the loop body is doing practically nothing otherwise. In more realistic code, we'd only be using these timing calls in between much more heavyweight operations, so their share of the frame budget quickly becomes negligible.

We can only speculate as to what exactly makes the Time.realtimeSinceStartup... properties slower than Stopwatch, as they're part of Unity's C++ internals, so we can't see their underlying code on the C# side. It could just be the overhead of floating point / unit conversions (note how we get the greatest speed-up when working in whole-numbered ticks). There could also be some marshalling overhead due to crossing the managed/unmanaged boundary in the Unity API, whereas the native C# approach with Stopwatch may allow the compiler to emit more efficient intrinsics.

Another potential contributing factor could be that your request to not optimize the method is preventing the function call for the property from being inlined away, adding an extra layer of function call overhead into every loop. I'd recommend using a volatile variable to keep your loop from being optimized away entirely, without disabling other optimizations within the method.