[Wasm][AOT] Performance regression in List<string> foreach

[jeromelaban]

Description

A performance regression happened when using this repro (with -O=gsharedvt for mono-aot-cross):

var SUT = new List<object>();
SUT.AddRange(Enumerable.Range(1, 1000)
	.Select(i => (object)null));

var sw = Stopwatch.StartNew();

for (int i = 0; i < 5000; i++)
{
	int count = 0;
	foreach (var item in SUT)
	{
		count++;
	}
}

sw.Stop();
Console.WriteLine($"TestForeachListOfT: {sw.Elapsed}");

Some performance benchmarks:

With df6e956:
Result: TestForeachListOfT: 00:00:00.3979650

With a822d39:
Result: TestForeachListOfT: 00:00:00.1164150

With d07f911 and 337216a:
Result: TestForeachListOfT: 00:00:00.2462100

Configuration

Regression?

Yes

Other information

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[ghost]

Tagging subscribers to 'arch-wasm': @lewing
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Description

A performance regression happened when using this repro (with -O=gsharedvt for mono-aot-cross):

var SUT = new List<object>();
SUT.AddRange(Enumerable.Range(1, 1000)
	.Select(i => (object)null));

var sw = Stopwatch.StartNew();

for (int i = 0; i < 5000; i++)
{
	int count = 0;
	foreach (var item in SUT)
	{
		count++;
	}
}

sw.Stop();
Console.WriteLine($"TestForeachListOfT: {sw.Elapsed}");

Some performance benchmarks:

With df6e956:
Result: TestForeachListOfT: 00:00:00.3979650

With a822d39:
Result: TestForeachListOfT: 00:00:00.1164150

With d07f911 and 337216a:
Result: TestForeachListOfT: 00:00:00.2462100

Configuration

Regression?

Yes

Other information

Author:	jeromelaban
Assignees:	-
Labels:	arch-wasm, untriaged
Milestone:	-

[vargaz]

This should be fixed by
d4fc723

[jeromelaban]

Here's the perf numbers, with 881e902:

TestForeachListOfT: 00:00:00.3946000
dotnet.js:2298 TestForListOfT: 00:00:00.0623000
dotnet.js:2298 TestForArray: 00:00:00.0212000

Still with -O=gsharedvt, it looks like the situation has not improved.

[vargaz]

What is the issue here ? Is it that foreach on a list is slower than a for loop or a for loop on an array ?

[jeromelaban]

The issue is that the foreach loop is calling into interpreted code, where as the for loop is not. When the code in the method is AOTed, it's 3x faster than the interpreted one (see the flame chart for a822d39 above).

[jeromelaban]

Here's the full sample I'm running:

static void Main(string[] args)
{
	TestEnumeratorListOfT();
	TestForeachListOfT();
	TestForListOfT();
	TestForArray();
}

private static void TestForArray()
{
	var SUT = new List<object>();
	SUT.AddRange(Enumerable.Range(1, 1000)
		.Select(i => (object)null));
	var SUT2 = SUT.ToArray();

	var sw = Stopwatch.StartNew();

	for (int i = 0; i < 5000; i++)
	{
		int count = 0;
		foreach (var item in SUT2)
		{
			count++;
		}
	}

	sw.Stop();
	Console.WriteLine($"TestForArray: {sw.Elapsed}");
}


private static void TestForListOfT()
{
	var SUT = new List<object>();
	SUT.AddRange(Enumerable.Range(1, 1000)
		.Select(i => (object)null));

	var sw = Stopwatch.StartNew();

	for (int j = 0; j < 5000; j++)
	{
		int count = 0;
		for (int i = 0; i < SUT.Count; i++)
		{
			var r = SUT[i];
			count++;
		}
	}

	sw.Stop();
	Console.WriteLine($"TestForListOfT: {sw.Elapsed}");
}

private static void TestForeachListOfT()
{
	var SUT = new List<object>();
	SUT.AddRange(Enumerable.Range(1, 1000)
		.Select(i => (object)null));

	var sw = Stopwatch.StartNew();

	for (int i = 0; i < 5000; i++)
	{
		int count = 0;
		foreach (var item in SUT)
		{
			count++;
		}
	}

	sw.Stop();
	Console.WriteLine($"TestForeachListOfT: {sw.Elapsed}");
}

private static void TestEnumeratorListOfT()
{
	var SUT = new List<object>();
	SUT.AddRange(Enumerable.Range(1, 1000)
		.Select(i => (object)null));

	var sw = Stopwatch.StartNew();

	for (int i = 0; i < 5000; i++)
	{
		int count = 0;
		var enumerator = SUT.GetEnumerator();

		while (enumerator.MoveNext())
		{
			var r = enumerator.Current;
			count++;
		}
	}

	sw.Stop();
	Console.WriteLine($"TestEnumeratorListOfT: {sw.Elapsed}");
}

[jeromelaban]

I reran the sample above with e983168, and here are the results:

TestEnumeratorListOfT: 00:00:00.1430000
TestForeachListOfT: 00:00:00.3181000
TestForListOfT: 00:00:00.1434000
TestForArray: 00:00:00.0161000

Update:
Profiling of the TestForeachListOfT:

[jeromelaban]

This behavior was caused by a rogue MONO_INLINE_LIMIT=1 set for prior troubleshooting, which interferes with the ability of the AOT compiler to remove empty finally blocks.

Thanks @vargaz for the troubleshooting.