search

dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.37k stars 4.75k forks source link

IndexOutOfRangeException in tracing infrastructure when build is running ILC while ETW is enabled #88081

Closed jakobbotsch closed 1 year ago

jakobbotsch commented 1 year ago

Recently I've been collecting some regressions/improvements for a JIT change that involves running lots of benchmarks with tracing enabled in the background while I do my regular work. I've noticed two times now the following exception during a normal ./build.cmd of the runtime, while a benchmark was running with tracing enabled:

EXEC : error : Index was outside the bounds of the array. [C:\dev\dotnet\runtime\src\coreclr\tools\aot\ILCompiler\ILCompiler.csproj]
  System.IndexOutOfRangeException: Index was outside the bounds of the array.
     at Internal.Runtime.CompilerHelpers.ThrowHelpers.ThrowIndexOutOfRangeException() + 0x24
     at System.Diagnostics.Tracing.EventSource.WriteEventWithRelatedActivityIdCore(Int32 eventId, Guid* relatedActivityId, Int32 eve
  ntDataCount, EventSource.EventData* data) + 0x3a0
     at System.Buffers.ArrayPoolEventSource.BufferRented(Int32, Int32, Int32, Int32) + 0x98
     at System.Buffers.TlsOverPerCoreLockedStacksArrayPool`1.Rent(Int32) + 0xb4
     at System.Runtime.CompilerServices.DefaultInterpolatedStringHandler..ctor(Int32, Int32) + 0x47
     at ILCompiler.WindowsNodeMangler.CreateStaticFieldName(TypeDesc, String) + 0x39
     at ILCompiler.UserDefinedTypeDescriptor.GetClassTypeIndex(TypeDesc, Boolean) + 0x2f4
     at ILCompiler.UserDefinedTypeDescriptor.GetTypeIndex(TypeDesc, Boolean) + 0x62
     at ILCompiler.UserDefinedTypeDescriptor.GetVariableTypeIndex(TypeDesc, Boolean) + 0x18a
     at ILCompiler.UserDefinedTypeDescriptor.GetArrayTypeIndex(TypeDesc) + 0x83
     at ILCompiler.UserDefinedTypeDescriptor.GetTypeIndex(TypeDesc, Boolean) + 0x62
     at ILCompiler.DependencyAnalysis.ObjectWriter.EmitObject(String, IReadOnlyCollection`1, NodeFactory, ObjectWritingOptions, IObj
  ectDumper, Logger) + 0x824
     at ILCompiler.RyuJitCompilation.CompileInternal(String, ObjectDumper) + 0xad
     at ILCompiler.Compilation.ILCompiler.ICompilation.Compile(String, ObjectDumper) + 0x2d
     at ILCompiler.Program.Run() + 0x17a7
     at ILCompiler.ILCompilerRootCommand.<>c__DisplayClass203_0.<.ctor>b__0(InvocationContext context) + 0x20c
C:\Users\Jakob\.nuget\packages\microsoft.dotnet.ilcompiler\8.0.0-preview.5.23280.8\build\Microsoft.NETCore.Native.targets(270,5): er
ror MSB3073: The command ""C:\Users\Jakob\.nuget\packages\runtime.win-x64.microsoft.dotnet.ilcompiler\8.0.0-preview.5.23280.8\tools\
\ilc" @"C:\dev\dotnet\runtime\artifacts\obj\coreclr\ILCompiler\x64\Debug\native\ilc.ilc.rsp"" exited with code 1. [C:\dev\dotnet\run
time\src\coreclr\tools\aot\ILCompiler\ILCompiler.csproj]

Both times the build has passed on a retry. To reproduce, try to build/run ILC while running a BDN benchmark with --profiler ETW. (Presumably just starting PerfView and running ILC in a loop might have the same effect).

For posterity, the exact command I am invoking BDN with in dotnet/performance micro benchmarks was

dotnet.exe "run" "-c" "Release" "-f" "net8.0" "--" "--filter" 'System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock.Count(Pattern: "(?i)Sherlock|Holmes|Watson", Options: None)' "--corerun" "C:\dev\dotnet\runtime2\artifacts\tests\coreclr\windows.x64.Release\Tests\Core_Root\corerun.exe" "--profiler" "ETW"
ghost commented 1 year ago

Tagging subscribers to this area: @agocke, @MichalStrehovsky, @jkotas See info in area-owners.md if you want to be subscribed.

Issue Details
Recently I've been collecting some regressions/improvements for a JIT change that involves running lots of benchmarks with tracing enabled in the background while I do my regular work. I've noticed two times now the following exception during a normal `./build.cmd` of the runtime, while a benchmark was running with tracing enabled: ```scala EXEC : error : Index was outside the bounds of the array. [C:\dev\dotnet\runtime\src\coreclr\tools\aot\ILCompiler\ILCompiler.csproj] System.IndexOutOfRangeException: Index was outside the bounds of the array. at Internal.Runtime.CompilerHelpers.ThrowHelpers.ThrowIndexOutOfRangeException() + 0x24 at System.Diagnostics.Tracing.EventSource.WriteEventWithRelatedActivityIdCore(Int32 eventId, Guid* relatedActivityId, Int32 eve ntDataCount, EventSource.EventData* data) + 0x3a0 at System.Buffers.ArrayPoolEventSource.BufferRented(Int32, Int32, Int32, Int32) + 0x98 at System.Buffers.TlsOverPerCoreLockedStacksArrayPool`1.Rent(Int32) + 0xb4 at System.Runtime.CompilerServices.DefaultInterpolatedStringHandler..ctor(Int32, Int32) + 0x47 at ILCompiler.WindowsNodeMangler.CreateStaticFieldName(TypeDesc, String) + 0x39 at ILCompiler.UserDefinedTypeDescriptor.GetClassTypeIndex(TypeDesc, Boolean) + 0x2f4 at ILCompiler.UserDefinedTypeDescriptor.GetTypeIndex(TypeDesc, Boolean) + 0x62 at ILCompiler.UserDefinedTypeDescriptor.GetVariableTypeIndex(TypeDesc, Boolean) + 0x18a at ILCompiler.UserDefinedTypeDescriptor.GetArrayTypeIndex(TypeDesc) + 0x83 at ILCompiler.UserDefinedTypeDescriptor.GetTypeIndex(TypeDesc, Boolean) + 0x62 at ILCompiler.DependencyAnalysis.ObjectWriter.EmitObject(String, IReadOnlyCollection`1, NodeFactory, ObjectWritingOptions, IObj ectDumper, Logger) + 0x824 at ILCompiler.RyuJitCompilation.CompileInternal(String, ObjectDumper) + 0xad at ILCompiler.Compilation.ILCompiler.ICompilation.Compile(String, ObjectDumper) + 0x2d at ILCompiler.Program.Run() + 0x17a7 at ILCompiler.ILCompilerRootCommand.<>c__DisplayClass203_0.<.ctor>b__0(InvocationContext context) + 0x20c C:\Users\Jakob\.nuget\packages\microsoft.dotnet.ilcompiler\8.0.0-preview.5.23280.8\build\Microsoft.NETCore.Native.targets(270,5): er ror MSB3073: The command ""C:\Users\Jakob\.nuget\packages\runtime.win-x64.microsoft.dotnet.ilcompiler\8.0.0-preview.5.23280.8\tools\ \ilc" @"C:\dev\dotnet\runtime\artifacts\obj\coreclr\ILCompiler\x64\Debug\native\ilc.ilc.rsp"" exited with code 1. [C:\dev\dotnet\run time\src\coreclr\tools\aot\ILCompiler\ILCompiler.csproj] ``` Both times the build has passed on a retry. To reproduce, try to build/run ILC while running a BDN benchmark with `--profiler ETW`. (Presumably just starting PerfView and running ILC in a loop might have the same effect). For posterity, the exact command I am invoking BDN with in dotnet/performance micro benchmarks was ```powershell dotnet.exe "run" "-c" "Release" "-f" "net8.0" "--" "--filter" 'System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock.Count(Pattern: "(?i)Sherlock|Holmes|Watson", Options: None)' "--corerun" "C:\dev\dotnet\runtime2\artifacts\tests\coreclr\windows.x64.Release\Tests\Core_Root\corerun.exe" "--profiler" "ETW" ```
Author: jakobbotsch
Assignees: -
Labels: `untriaged`, `area-NativeAOT-coreclr`
Milestone: -
MichalStrehovsky commented 1 year ago

Cc @LakshanF

LakshanF commented 1 year ago

I haven't been able to repro this issue but the details strongly resembles the problem ILCcompilershows when the runtime provider is enabled via the managed side. The PR #87785 fixed that for NativeAOT applications but the ILCompiler hasn't been updated yet. This PR #89655 is attempting to do that.

Issues #87739, #8649 has more details.

LakshanF commented 1 year ago

This should be fixed now.