Slow loop performance with 3.0 preview1 on Windows

[OnurGumus]

Slow loop performance

I have the following code :

using System;
using System.Diagnostics;
using System.IO;

namespace ConsoleApp83
{
    class Program
    {
        static void Main(string[] args)
        {
            const int count = 1024 * 64;
            var buffer = new int[count];
            var rand = new Random();

            for (var i = 0; i < count; i++)
            {
                buffer[i] = rand.Next(count);
            }

            var sw = Stopwatch.StartNew();
            for (var j = 0; j < 10000; j++)
                for (var i = 0; i < buffer.Length; i++)
                {
                    buffer[i] *= 3;
                }
            Console.WriteLine(sw.Elapsed);
        }
    }
}

I ran above code on Windows 10 with .net core sdk 3.0 preview, and it runs in 1.56 seconds whereas on .net core 2.2, it runs within 0.54 seconds. Both compiled with release mode and 64 bit.

Here's my output for dotnet --info:

PS C:\> dotnet --info
.NET Core SDK (reflecting any global.json):
 Version:   3.0.100-preview-009812
 Commit:    e3abf6e935

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.17763
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\3.0.100-preview-009812\

Host (useful for support):
  Version: 3.0.0-preview-27122-01
  Commit:  00c5c8bc40

[karelz]

@OnurGumus Stowatch can be misleading and could hide many things.
I would recommend to change the perf test into BenchmarkDotNet: https://benchmarkdotnet.org, then compare. It will also rule out statistical annomalies and show you disassembly.

cc @adamsitnik

Tiered compilation is enabled by default. What happens if you disable it? (set COMPlus_TieredCompilation=0)

https://github.com/dotnet/coreclr/issues/19751

[OnurGumus]

@0xd4d
Yes when tiered compilation is off it is 3 times faster.

[OnurGumus]

I also tried with benchmarkdotnet, it is initially slow then the latter iterations were fast. Is this by design ?

-------------------- Histogram --------------------
[ 366.894 ms ;  576.481 ms) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 576.481 ms ;  786.068 ms) |
[ 786.068 ms ;  995.655 ms) |
[ 995.655 ms ; 1205.241 ms) |
[1205.241 ms ; 1414.828 ms) |
[1414.828 ms ; 1613.069 ms) |
[1613.069 ms ; 1822.656 ms) | @@@@@@@@@@@@@@@@@@@
[1822.656 ms ; 2032.010 ms) | @@
---------------------------------------------------

[OnurGumus]

@karelz info is provided.

[adamsitnik]

Hi @OnurGumus

Big thanks for your report!

In your benchmark we have a nested loop:

private int[] buffer;

[Benchmark]
public void InitializeNestedLoop()
{
    int[] local = buffer;

    for (var j = 0; j < 10000; j++) // the loop that I am talking about
        for (var i = 0; i < local.Length; i++)
            local[i] *= 3;
}

[GlobalSetup]
public void Setup()
{
    buffer = new int[1024 * 64];
    var rand = new Random();

    for (var i = 0; i < buffer.Length; i++)
        buffer[i] = rand.Next(1024 * 64);
}

On my PC, it takes on average 1.5s (1,484,491.56 us) to execute this benchmark.

Let's remove the nested loop:

[Benchmark]
public void Initialize()
{
    var local = buffer;

    for (var i = 0; i < buffer.Length; i++)
        local[i] *= 3;
}

If we remove the nested loop, and initialize the array only, takes 36.99 us. 1,484,491.56 us / 10000 is 148 us. Why the difference is so big?

Your micro-benchmark is an edge case for the current implementation of Tiered Jitting. The current condition for determining if the given method should be promoted from Tier 0 to Tier 1 and re-compiled using all optimizations known to JIT is following: method should be invoked more than 30 times and for longer than 100ms.

This method takes a lot of time to execute, and it's not executed more than 30 times so it never gets promoted to Tier 1.

The micro-benchmarks are important to us, but the most important are real-world code scenarios. Do you have any real-world example of a code that is affected by this behaviour?

We monitor the performance of various indexer setters in the dotnet/performance repo:

• Span benchmarks
• All collections
• All collections, reverse

/cc @kouvel

[OnurGumus]

@adamsitnik, thanks for the reply. I understand, but this is a generic nested loop. It doesn't look like an edge case to me. Perhaps you should not consider nested loops as edge cases, because they are very common everywhere. Correct me if I am wrong but just because a method is not called 30 times, doesn't mean that it is not doing CPU intensive work.

If it will work as you mentioned I believe this is not appropriate and you will hear a lot of complaints about it. I myself will probably turn off Tiered jitting for all production environments. I am 100% sure there are some libraries I use with these nested loops.

[OnurGumus]

As a side note adding [MethodImpl( MethodImplOptions.AggressiveOptimization)] fixes the issue. But again I can fix my code, but not the libraries I use.

[adamsitnik]

@OnurGumus I understand your concerns.

We have validated that Tiered Jitting does not regress TechEmpower benchmarks, MusicStore app, AllReady app and few other real-world scenarios.

@kouvel can say something more about the details for nested-loop scenarios

[kouvel]

There is a balance to be struck and it's not perfect yet. Depending on whether you care about startup perf or steady-state perf, even without tiering there are modes to choose from. For startup perf, generating ReadyToRun (R2R) with crossgen is helpful. For steady-state perf, disabling ReadyToRun and tiering may yield the best perf at the moment. Each of those modes currently compromises perf of the other category. Tiering allows getting good startup and steady-state perf, in the future hopefully without any special modes. Many of the netcoreapp libraries are pre-crossgenned with R2R (perhaps partially), so disabling tiering may result in a decrease in steady-state perf. Enabling tiering may run into this issue, which often occurs in benchmarks but is less impactful when it occurs in real-world apps. I'm currently working on adding a config to disable tier 0 JIT. For methods that don't have pregenerated code in the image, tier 0 uses a JIT that does few optimizations and the generated code is typically slower than R2R-pregenerated code. So when that method contains hot loops, the issue is more noticeable. Using the config to disable tier 0 JIT would cause such methods to be optimized at the cost of some startup perf, and it would still allow tiering-up methods that have pregenerated R2R code for steady-state perf. The issue should be fixed, but it's likely going to remain for some time.

Duplicate of https://github.com/dotnet/coreclr/issues/19751

[kouvel]

Closing as duplicate, feel free to reopen if you have any other info to add, or add it to the other issue

[OnurGumus]

@kouvel Is it possible if we re-open this issue and treat it strictly targeting to nested loops ? Or I can open a new issue like "Tiered JIT should handle nested loops properly". What do you think ?

[kouvel]

The issue isn't specific to nested loops, any long loop would run into the same problem. Removing the nesting helps in the benchmark above only because the total number of iterations is much less than before and BenchmarkDotNet's pilot and warmup phases allow enough calls to the method to cause tiering to occur before measurement begins. The issue would occur again if the single loop were modified to perform the same number of total iterations as before with the nested loop.