Validate .tailcall improvements, identify further optimisations

[vzarytovskii]

This issue : #11907

Has a lot of great information about the issue resolved by: dotnet/runtime#56669

Validate and test the changes determine whether additional optimisations are necessary.

[vzarytovskii]

Some tests and comparisons of desktop compiler vs the one shipped in 6.0.100 and builds from main (.NET 7):

TL;DR: .NET7 is better than .NET6, but worse than full framework

VS2022 - FSC.exe

TIME:  0.4 Delta:  0.3 Mem:  95 G0:   3 G1:  3 G2:  3 [Import mscorlib and FSharp.Core.dll]
TIME:  0.4 Delta:  0.0 Mem:  99 G0:   0 G1:  0 G2:  0 [Parse inputs]
TIME:  0.4 Delta:  0.0 Mem:  99 G0:   0 G1:  0 G2:  0 [Import non-system references]
TIME:  0.4 Delta:  0.1 Mem: 112 G0:   0 G1:  0 G2:  0 [Typecheck]
TIME:  0.4 Delta:  0.0 Mem: 112 G0:   0 G1:  0 G2:  0 [Typechecked]
TIME:  0.4 Delta:  0.0 Mem: 112 G0:   0 G1:  0 G2:  0 [Write Interface File]
TIME:  0.4 Delta:  0.0 Mem: 112 G0:   0 G1:  0 G2:  0 [Write XML document signatures]
TIME:  0.4 Delta:  0.0 Mem: 112 G0:   0 G1:  0 G2:  0 [Write XML docs]
TIME:  0.5 Delta:  0.0 Mem: 122 G0:   0 G1:  0 G2:  0 [Encode Interface Data]
TIME:  0.5 Delta:  0.0 Mem: 123 G0:   0 G1:  0 G2:  0 [Optimizations]
TIME:  0.5 Delta:  0.0 Mem: 123 G0:   0 G1:  0 G2:  0 [Ending Optimizations]
TIME:  0.5 Delta:  0.0 Mem: 124 G0:   0 G1:  0 G2:  0 [Encoding OptData]
TIME:  0.5 Delta:  0.0 Mem: 126 G0:   0 G1:  0 G2:  0 [TAST -> IL]
ilwrite: TIME      0.000 (total)        0.500 (delta) - Write Started
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Preparation
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 1
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 2
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 3
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 4
ilwrite: TIME      0.000 (total)        0.000 (delta) - Finalize Module Generation Results
ilwrite: TIME      0.000 (total)        0.000 (delta) - Generated Tables and Code
ilwrite: TIME      0.000 (total)        0.000 (delta) - Layout Header of Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Build String/Blob Address Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Sort Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Header of tablebuf
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Tables to tablebuf
ilwrite: TIME      0.000 (total)        0.000 (delta) - Layout Metadata
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata Header
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata Strings
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata User Strings
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Blob Stream
ilwrite: TIME      0.000 (total)        0.000 (delta) - Fixup Metadata
ilwrite: TIME      0.000 (total)        0.000 (delta) - Generated IL and metadata
ilwrite: TIME      0.000 (total)        0.000 (delta) - Layout image
ilwrite: TIME      0.000 (total)        0.000 (delta) - Writing Image
ilwrite: TIME      0.000 (total)        0.000 (delta) - Finalize PDB
ilwrite: TIME      0.000 (total)        0.000 (delta) - Signing Image
TIME:  0.5 Delta:  0.0 Mem: 128 G0:   0 G1:  0 G2:  0 [Write .NET Binary]
STATS: #ByteArrayFile = 3, #MemoryMappedFileOpen = 24, #MemoryMappedFileClosed = 0, #RawMemoryFile = 0, #WeakByteArrayFile = 0

VS2022 - fscAnyCpu.exe

TIME:  0.4 Delta:  0.3 Mem: 122 G0:   2 G1:  2 G2:  2 [Import mscorlib and FSharp.Core.dll]
TIME:  0.4 Delta:  0.0 Mem: 126 G0:   0 G1:  0 G2:  0 [Parse inputs]
TIME:  0.4 Delta:  0.0 Mem: 127 G0:   0 G1:  0 G2:  0 [Import non-system references]
TIME:  0.6 Delta:  0.2 Mem: 146 G0:   1 G1:  0 G2:  0 [Typecheck]
TIME:  0.6 Delta:  0.0 Mem: 146 G0:   0 G1:  0 G2:  0 [Typechecked]
TIME:  0.6 Delta:  0.0 Mem: 146 G0:   0 G1:  0 G2:  0 [Write Interface File]
TIME:  0.6 Delta:  0.0 Mem: 146 G0:   0 G1:  0 G2:  0 [Write XML document signatures]
TIME:  0.6 Delta:  0.0 Mem: 146 G0:   0 G1:  0 G2:  0 [Write XML docs]
TIME:  0.6 Delta:  0.0 Mem: 152 G0:   0 G1:  0 G2:  0 [Encode Interface Data]
TIME:  0.7 Delta:  0.0 Mem: 155 G0:   0 G1:  0 G2:  0 [Optimizations]
TIME:  0.7 Delta:  0.0 Mem: 155 G0:   0 G1:  0 G2:  0 [Ending Optimizations]
TIME:  0.7 Delta:  0.0 Mem: 156 G0:   0 G1:  0 G2:  0 [Encoding OptData]
TIME:  0.7 Delta:  0.0 Mem: 159 G0:   0 G1:  0 G2:  0 [TAST -> IL]
ilwrite: TIME      0.000 (total)        0.672 (delta) - Write Started
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Preparation
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 1
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 2
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 3
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 4
ilwrite: TIME      0.000 (total)        0.000 (delta) - Finalize Module Generation Results
ilwrite: TIME      0.000 (total)        0.000 (delta) - Generated Tables and Code
ilwrite: TIME      0.000 (total)        0.000 (delta) - Layout Header of Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Build String/Blob Address Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Sort Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Header of tablebuf
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Tables to tablebuf
ilwrite: TIME      0.000 (total)        0.000 (delta) - Layout Metadata
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata Header
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata Tables
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata Strings
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Metadata User Strings
ilwrite: TIME      0.000 (total)        0.000 (delta) - Write Blob Stream
ilwrite: TIME      0.000 (total)        0.000 (delta) - Fixup Metadata
ilwrite: TIME      0.000 (total)        0.000 (delta) - Generated IL and metadata
ilwrite: TIME      0.000 (total)        0.000 (delta) - Layout image
ilwrite: TIME      0.000 (total)        0.000 (delta) - Writing Image
ilwrite: TIME      0.000 (total)        0.000 (delta) - Finalize PDB
ilwrite: TIME      0.000 (total)        0.000 (delta) - Signing Image
TIME:  0.7 Delta:  0.0 Mem: 161 G0:   0 G1:  0 G2:  0 [Write .NET Binary]
STATS: #ByteArrayFile = 3, #MemoryMappedFileOpen = 24, #MemoryMappedFileClosed = 0, #RawMemoryFile = 0, #WeakByteArrayFile = 0

.NET 6.0.100

TIME:  0.5 Delta:  0.4 Mem: 113 G0:   8 G1:  4 G2:  3 [Import mscorlib and FSharp.Core.dll]
TIME:  0.6 Delta:  0.1 Mem: 122 G0:   0 G1:  0 G2:  0 [Parse inputs]
TIME:  0.6 Delta:  0.0 Mem: 122 G0:   0 G1:  0 G2:  0 [Import non-system references]
TIME:  1.0 Delta:  0.4 Mem: 145 G0:   3 G1:  1 G2:  0 [Typecheck]
TIME:  1.0 Delta:  0.0 Mem: 145 G0:   0 G1:  0 G2:  0 [Typechecked]
TIME:  1.0 Delta:  0.0 Mem: 145 G0:   0 G1:  0 G2:  0 [Write Interface File]
TIME:  1.0 Delta:  0.0 Mem: 145 G0:   0 G1:  0 G2:  0 [Write XML document signatures]
TIME:  1.0 Delta:  0.0 Mem: 145 G0:   0 G1:  0 G2:  0 [Write XML docs]
TIME:  1.1 Delta:  0.1 Mem: 156 G0:   2 G1:  1 G2:  0 [Encode Interface Data]
TIME:  1.2 Delta:  0.1 Mem: 158 G0:   1 G1:  0 G2:  0 [Optimizations]
TIME:  1.2 Delta:  0.0 Mem: 158 G0:   0 G1:  0 G2:  0 [Ending Optimizations]
TIME:  1.3 Delta:  0.0 Mem: 158 G0:   0 G1:  0 G2:  0 [Encoding OptData]
TIME:  1.3 Delta:  0.1 Mem: 159 G0:   0 G1:  0 G2:  0 [TAST -> IL]
ilwrite: TIME      0.000 (total)        1.344 (delta) - Write Started
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Preparation
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 1
ilwrite: TIME      0.016 (total)        0.016 (delta) - Module Generation Pass 2
ilwrite: TIME      0.047 (total)        0.031 (delta) - Module Generation Pass 3
ilwrite: TIME      0.047 (total)        0.000 (delta) - Module Generation Pass 4
ilwrite: TIME      0.047 (total)        0.000 (delta) - Finalize Module Generation Results
ilwrite: TIME      0.047 (total)        0.000 (delta) - Generated Tables and Code
ilwrite: TIME      0.062 (total)        0.016 (delta) - Layout Header of Tables
ilwrite: TIME      0.062 (total)        0.000 (delta) - Build String/Blob Address Tables
ilwrite: TIME      0.062 (total)        0.000 (delta) - Sort Tables
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Header of tablebuf
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Tables to tablebuf
ilwrite: TIME      0.062 (total)        0.000 (delta) - Layout Metadata
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Metadata Header
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Metadata Tables
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Metadata Strings
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Metadata User Strings
ilwrite: TIME      0.062 (total)        0.000 (delta) - Write Blob Stream
ilwrite: TIME      0.062 (total)        0.000 (delta) - Fixup Metadata
ilwrite: TIME      0.062 (total)        0.000 (delta) - Generated IL and metadata
ilwrite: TIME      0.062 (total)        0.000 (delta) - Layout image
ilwrite: TIME      0.062 (total)        0.000 (delta) - Writing Image
ilwrite: TIME      0.062 (total)        0.000 (delta) - Finalize PDB
ilwrite: TIME      0.062 (total)        0.000 (delta) - Signing Image
TIME:  1.4 Delta:  0.1 Mem: 161 G0:   0 G1:  0 G2:  0 [Write .NET Binary]

.NET 7.0.100-alpha.1.21558.2

TIME:  0.4 Delta:  0.3 Mem: 113 G0:   8 G1:  4 G2:  3 [Import mscorlib and FSharp.Core.dll]
TIME:  0.5 Delta:  0.1 Mem: 125 G0:   0 G1:  0 G2:  0 [Parse inputs]
TIME:  0.5 Delta:  0.0 Mem: 125 G0:   0 G1:  0 G2:  0 [Import non-system references]
TIME:  0.8 Delta:  0.3 Mem: 147 G0:   3 G1:  1 G2:  0 [Typecheck]
TIME:  0.8 Delta:  0.0 Mem: 147 G0:   0 G1:  0 G2:  0 [Typechecked]
TIME:  0.8 Delta:  0.0 Mem: 147 G0:   0 G1:  0 G2:  0 [Write Interface File]
TIME:  0.8 Delta:  0.0 Mem: 147 G0:   0 G1:  0 G2:  0 [Write XML document signatures]
TIME:  0.8 Delta:  0.0 Mem: 147 G0:   0 G1:  0 G2:  0 [Write XML docs]
TIME:  0.8 Delta:  0.1 Mem: 158 G0:   2 G1:  1 G2:  0 [Encode Interface Data]
TIME:  0.9 Delta:  0.1 Mem: 159 G0:   0 G1:  0 G2:  0 [Optimizations]
TIME:  0.9 Delta:  0.0 Mem: 159 G0:   0 G1:  0 G2:  0 [Ending Optimizations]
TIME:  0.9 Delta:  0.0 Mem: 160 G0:   1 G1:  0 G2:  0 [Encoding OptData]
TIME:  1.0 Delta:  0.1 Mem: 161 G0:   0 G1:  0 G2:  0 [TAST -> IL]
ilwrite: TIME      0.000 (total)        0.969 (delta) - Write Started
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Preparation
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 1
ilwrite: TIME      0.000 (total)        0.000 (delta) - Module Generation Pass 2
ilwrite: TIME      0.016 (total)        0.016 (delta) - Module Generation Pass 3
ilwrite: TIME      0.016 (total)        0.000 (delta) - Module Generation Pass 4
ilwrite: TIME      0.016 (total)        0.000 (delta) - Finalize Module Generation Results
ilwrite: TIME      0.016 (total)        0.000 (delta) - Generated Tables and Code
ilwrite: TIME      0.016 (total)        0.000 (delta) - Layout Header of Tables
ilwrite: TIME      0.016 (total)        0.000 (delta) - Build String/Blob Address Tables
ilwrite: TIME      0.016 (total)        0.000 (delta) - Sort Tables
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Header of tablebuf
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Tables to tablebuf
ilwrite: TIME      0.016 (total)        0.000 (delta) - Layout Metadata
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Metadata Header
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Metadata Tables
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Metadata Strings
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Metadata User Strings
ilwrite: TIME      0.016 (total)        0.000 (delta) - Write Blob Stream
ilwrite: TIME      0.016 (total)        0.000 (delta) - Fixup Metadata
ilwrite: TIME      0.016 (total)        0.000 (delta) - Generated IL and metadata
ilwrite: TIME      0.016 (total)        0.000 (delta) - Layout image
ilwrite: TIME      0.016 (total)        0.000 (delta) - Writing Image
ilwrite: TIME      0.016 (total)        0.000 (delta) - Finalize PDB
ilwrite: TIME      0.016 (total)        0.000 (delta) - Signing Image
TIME:  1.0 Delta:  0.0 Mem: 162 G0:   0 G1:  0 G2:  0 [Write .NET Binary]

cc @KevinRansom @TIHan

[dsyme]

So faster but not as fast. Could you compare with fscAnyCpu.exe (64-bit) to make sure it's not that

[dsyme]

Also how many times did you repeat? Thanks

[vzarytovskii]

Also how many times did you repeat? Thanks

I've been running each 100 times.

[vzarytovskii]

So faster but not as fast. Could you compare with fscAnyCpu.exe (64-bit) to make sure it's not that

Added fscAnyCpu too

[dsyme]

I've been running each roughly 100 times.

That should do it 😂

Added fscAnyCpu too

OK thanks

I'm not sure it's easy to get, but I'd be curious of startup time comparison for some large C# projects that are equally comparable. .NET Framework has a long tradition of really focusing on optimized startup with optimized binary layout for native mscorlib etc. It's really sophisticated. I'm not entirely sure if all these are present in .NET Core SDK distributions though they might be and more.

It could be that we realistically expect some slightly slower startup regardless of tailcalls.

@jkotas might have more insight.

Anyway I think the 0.7 --> 1.0 is looking fairly acceptable. Larger compilations should also see only a ~0.3sec slowdown hopefully, so the costs are only paid once.

[jakobbotsch]

What is under test here? IIUC, a simple small F# program being compiled with a .NET Framework version of the F# compiler, and .NET 6/7 versions of the (same source code?) F# compiler?

If you give me a short guide on how to measure these things I can try to check how much time we are spending on JIT and if there are other optimizations we can do to help.

[jkotas]

I'm not entirely sure if all these are present in .NET Core SDK distributions though they might be and more.

These optimizations are not present in .NET Core. These optimizations in .NET Framework make the AOT compiled fragile: The AOT binary can be used only if all its dependencies match exactly between the AOT time and R2R time. There is global NGen services that regenerates all binaries as needed (e.g. after servicing). This model was unworkable for .NET Core for multiple reasons.

.NET Core uses version-resilient AOT compiler code. You can read more about it in https://github.com/dotnet/runtime/blob/main/docs/design/coreclr/botr/readytorun-overview.md. The version-resilient AOT compiled is less efficient, but we compensate for it in other ways (e.g. using tiered compilation).

[vzarytovskii]

What is under test here? IIUC, a simple small F# program being compiled with a .NET Framework version of the F# compiler, and .NET 6/7 versions of the (same source code?) F# compiler?

Yep, that's pretty much what we try to test here. We compile a simple F# "Hello World" program and measure compiler start time.

If you give me a short guide on how to measure these things I can try to check how much time we are spending on JIT and if there are other optimizations we can do to help.

Let me try to come up some simple instructions how to test it.

[En3Tho]

@vzarytovskii Is this on Win only? Any info about Linux/MacOS?. As far as I understand it should help Unix family unconditionally or am I mistaken?