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.06k stars 4.69k forks source link

Invalid profiler callbacks on exception handling since .NET 9 preview 3 #104300

Closed valco1994 closed 2 months ago

valco1994 commented 3 months ago

Description

There is some mess with profiling callbacks related to exception handling since .NET 9 preview 3. As far as I understand, it's caused by the switch to the new exception handling subsystem.

Reproduction Steps

The issue is reproduced on the following test application:

using System;
using System.Runtime.InteropServices;

internal static partial class Kernel32
{
  [LibraryImport("kernel32.dll", EntryPoint = "GetFileAttributesW", SetLastError = true, StringMarshalling = StringMarshalling.Utf16)]
  internal static partial uint GetFileAttributes(string fileName);
}

internal static partial class LibC
{
  // ReSharper disable once InconsistentNaming
  [LibraryImport("libc", EntryPoint = "access", SetLastError = true, StringMarshalling = StringMarshalling.Utf8)]
  internal static partial int access(string fileName, int mode);
}

internal static class Program
{
  private static int Main()
  {
    try
    {
      const string fileName = "file-that-should-not-exist.txt";
      Console.WriteLine("[{0}] Create", DateTime.Now);

      var fileNotFound = RuntimeInformation.IsOSPlatform(OSPlatform.Windows)
        ? IsFileNotFoundWindows(fileName)
        : IsFileNotFoundLinuxMacOs(fileName);
      Console.WriteLine("[{0}] Check fileNotFound? {1}! fileName {2}", DateTime.Now, fileNotFound, fileName);
      if (!fileNotFound)
        throw new Exception("File-not-found error is expected");

      Console.WriteLine("[{0}] Done", DateTime.Now);
      return 0;
    }
    catch (Exception e)
    {
      Console.Error.WriteLine(e);
      return 1;
    }
  }

  private static bool IsFileNotFoundWindows(string fileName)
  {
    // ReSharper disable InconsistentNaming
    const uint INVALID_FILE_ATTRIBUTES = unchecked((uint)-1);
    const int ERROR_FILE_NOT_FOUND = 2;
    // ReSharper restore InconsistentNaming
    return Kernel32.GetFileAttributes(fileName) == INVALID_FILE_ATTRIBUTES && Marshal.GetLastPInvokeError() == ERROR_FILE_NOT_FOUND;
  }

  private static bool IsFileNotFoundLinuxMacOs(string fileName)
  {
    // ReSharper disable InconsistentNaming
    const int F_OK = 0;
    const uint ENOENT = 2;
    // ReSharper restore InconsistentNaming
    return LibC.access(fileName, F_OK) == -1 && Marshal.GetLastPInvokeError() == ENOENT;
  }
}

Expected behavior

Profiler callbacks should be called in accordance with the state machine for exception handling, see https://github.com/dotnet/runtime/blob/main/docs/design/coreclr/botr/profiling.md#exceptions

Actual behavior

In some cases I receive ExceptionUnwindFunctionLeave notification after ExceptionSearchFunctionEnter (on the same thread, of course).

In other cases I receive notifications in a proper order, but id of the function received in ExceptionUnwindFunctionLeave doesn't match the top frame of the callstack.

Regression?

Yes, everything worked fine in previous versions, inclduing .NET 9 preview 1-2.

Known Workarounds

No workarounds

Configuration

.NET 9 preview 3-5 Linux x64, Ubuntu 22.04

Other information

No response

dotnet-policy-service[bot] commented 3 months ago

Tagging subscribers to this area: @dotnet/interop-contrib See info in area-owners.md if you want to be subscribed.

valco1994 commented 3 months ago

@janvorli, is it supposed to be fixed by your recent fixes for https://github.com/dotnet/runtime/pull/103047 and https://github.com/dotnet/runtime/pull/103048?

mangod9 commented 3 months ago

@tommcdon for visibility here. @valco1994, assume the test works for you after disabling the new EH ?

valco1994 commented 3 months ago

@mangod9 I don't know. Please, tell me how to switch to the old EH (is it controlled by some environment variable?) and I will check.

mangod9 commented 3 months ago

new EH can be disabled using DOTNET_LegacyExceptionHandling=1

valco1994 commented 2 months ago

@mangod9 I have checked, and tests work fine after the switch to the legacy exception handling. So, the problem is indeed caused by the new exception handling.

janvorli commented 2 months ago

@janvorli, is it supposed to be fixed by your recent fixes for #103047 and #103048?

No, those were unrelated. Thank you for reporting this problem!

janvorli commented 2 months ago

@valco1994 I have added prints to all the profiler callbacks to see what's wrong, but I don't see any issue with your repro code:

[7/8/2024 8:35:01 PM] Create
[7/8/2024 8:35:02 PM] Check fileNotFound? False! fileName file-that-should-not-exist.txt
ExceptionThrown
ExceptionSearchFunctionEnter pFunction=00007FF967273718
ExceptionSearchCatcherFound pFunction=00007FF967273718
ExceptionSearchFunctionLeave pFunction=00007FF967273718
ExceptionUnwindFunctionEnter pFunction=00007FF967273718
ExceptionCatcherEnter pFunction=00007FF967273718
System.Exception: File-not-found error is expected
   at Program.Main() in F:\issues\104300\Program.cs:line 31
ExceptionCatcherLeave
valco1994 commented 2 months ago

It's a little bit non-trivial actually.

Firstly, I will try it in preview 6 today. I hope it can be related to shadow stack handling, and there is a chance that the problem is gone in preview 6. But I need to check, of course.

If the problem is still relevant, I will collect the details and attach them here. I will do it either today or tomorrow.

valco1994 commented 2 months ago

Unfortunately, the problem is indeed still relevant in preview 6.

I saw an invalid callback order only when I had enabled enter-leaves logging. And in this case, something very strange started to happen, TimeZoneInfo constructor threw an exception, and everything worked unexpectedly. I don't understand how it's possible at all, to be honest, but I saw it.

Considering the second case, I understood that most likely the issue is on our side. It was supposed that FUID received in ExceptionUnwindFunctionEnter should match to the last managed frame when we look at the call stack in the corresponding ExceptionUnwindFunctionLeave. And it was true previously when exception handling was implemented entirely in C++ code. But new exception handling is distributed between C++ code and C# code, so there could be additional managed frames that should be ignored as well.

Do I understand it correctly?

janvorli commented 2 months ago

@valco1994 what do you use to look at the call stack? There are couple of managed frames (one of the System.EH.ThrowEx, ThrowHwEx, Rethrow and the System.EH.DispatchEx) on the stack on top of the last managed frame.

valco1994 commented 2 months ago

It is being constructed and updated manually relying on other profiler callbacks.

valco1994 commented 2 months ago

I will need some time for further investigation. I will close the issue if I find that all the mess was really caused by the assumption in our code that is not correct anymore.

k15tfu commented 2 months ago

@janvorli Hi!

We use ELT hooks for tracing managed call stack and in addition ICorProfilerCallback::ExceptionUnwindFunctionLeave() to unwind the top frame when an exception is thrown, but now these top frames point to the internal exception handling functions like System.Runtime.ExceptionServices.InternalCalls.RhpSfiNext(), System.Runtime.EH.DispatchEx(), and so:

000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97567FB170 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97567FB170 res=ok fuid=80000001 fname='ThrowExceptionForIoErrno' cname='Interop'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97567FB170 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=80000001
[...]
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionThrown oid=00007D572A80D880 cid=00007D9756948E30 cname='System.IO.FileNotFoundException'
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionEnter fid=00007D97567FB170 fuid=80000001
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106ED7
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010479B
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574510 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574510 res=ok fuid=00104796 fname='get_OriginalControlPC' cname='System.Runtime.StackFrameIterator'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574510 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574570 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574570 res=ok fuid=00104799 fname='get_FramePointer' cname='System.Runtime.StackFrameIterator'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574570 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574550 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574550 res=ok fuid=00104798 fname='get_SP' cname='System.Runtime.StackFrameIterator'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574550 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574060 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574060 res=ok fuid=0010478D fname='UpdateStackTrace' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574060 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756573F60 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756573F60 res=ok fuid=00104785 fname='AppendExceptionStackFrameViaClasslib' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756573F60 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715F
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationStarted fid=00007D97569EFB28 safe=true
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationFinished fid=00007D97569EFB28 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574080 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574080 res=ok fuid=0010478E fname='FindFirstPassHandler' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574080 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97565742E0 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97565742E0 res=ok fuid=00106EDE fname='RhpEHEnumInitFromStackFrameIterator' cname='System.Runtime.ExceptionServices.InternalCalls'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97565742E0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106EDE
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationStarted fid=00007D97569F01C0 safe=true
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationFinished fid=00007D97569F01C0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97565745D0 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97565745D0 res=ok fuid=0010479C fname='Next' cname='System.Runtime.StackFrameIterator'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97565745D0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010479C
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97565741A0 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97565741A0 res=ok fuid=00106ED8 fname='RhpSfiNext' cname='System.Runtime.ExceptionServices.InternalCalls'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97565741A0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106ED8
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationStarted fid=00007D97569F02C8 safe=true
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationFinished fid=00007D97569F02C8 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionLeave
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionEnter fid=00007D97567FB190 fuid=80000000
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106ED8
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010479C
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010479C
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106ED8
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionLeave
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionEnter fid=00007D97566EE5D8 fuid=00100139
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106ED8
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010479C
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010479C
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106ED8
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionLeave
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionEnter fid=00007D97566EE668 fuid=0010013E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106ED8
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010479C
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104799
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104796
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010715F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104785
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478D
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574040 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574040 res=ok fuid=0010478C fname='CalculateCodeOffset' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574040 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478C
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478C
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574300 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574300 res=ok fuid=00106EDF fname='RhpEHEnumNext' cname='System.Runtime.ExceptionServices.InternalCalls'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574300 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106EDF
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationStarted fid=00007D97569F03D0 safe=true
000012D3 1 00005E634FE81AE0 BProf::DynamicMethodJITCompilationFinished fid=00007D97569F03D0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106EDF
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97569F0090 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97569F0090 res=ok fuid=00104792 fname='ContainsCodeOffset' cname='System.Runtime.EH+RhEHClause'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97569F0090 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104792
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104792
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D9756574590 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D9756574590 res=ok fuid=0010479A fname='get_IsRuntimeWrappedExceptions' cname='System.Runtime.StackFrameIterator'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D9756574590 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010479A
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010479A
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97565740A0 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97565740A0 res=ok fuid=0010478F fname='ShouldTypedClauseCatchThisException' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97565740A0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010478F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106F27
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106F27
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478F
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010478E
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010479B
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106ED7
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchCatcherFound fid=00007D97566EE668 fuid=0010013E
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionSearchFunctionLeave
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionUnwindFunctionEnter fid=00007D97567FB170 fuid=80000001  <-- Interop.ThrowExceptionForIoErrno
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106ED7  <-- System.Runtime.ExceptionServices.InternalCalls.RhpSfiInit
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=0010479B  <-- System.Runtime.StackFrameIterator.Init
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798  <-- System.Runtime.StackFrameIterator.get_SP
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104798
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97565740C0 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97565740C0 res=ok fuid=00104790 fname='InvokeSecondPass' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97565740C0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104790  <-- System.Runtime.EH.InvokeSecondPass
000012D3 1 00005E634FE81AE0 PTIProf::JITCompilationStarted fid=00007D97565740E0 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::FunctionIdMapper fid=00007D97565740E0 res=ok fuid=00104791 fname='InvokeSecondPass' cname='System.Runtime.EH'
000012D3 1 00005E634FE81AE0 BProf::JITCompilationFinished fid=00007D97565740E0 hr=00000000 safe=true
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00104791  <-- System.Runtime.EH.InvokeSecondPass
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106EDE  <-- System.Runtime.ExceptionServices.InternalCalls.RhpEHEnumInitFromStackFrameIterator
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00106EDE
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104791
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastLeave fuid=00104790
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=0010479C  <-- System.Runtime.StackFrameIterator.Next
000012D3 1 00005E634FE81AE0 PTIProf::RdtscFastEnter fuid=00106ED8  <-- System.Runtime.ExceptionServices.InternalCalls.RhpSfiNext
000012D3 1 00005E634FE81AE0 PTIProf::ExceptionUnwindFunctionLeave  <-- Here we expect to unwind fuid 80000001, but the top is 00106ED8.

What are the new contracts between ELT hooks (e.g. from the internal exception handling functions) and exception callbacks?

janvorli commented 2 months ago

@k15tfu the exception callbacks report only functions whose frames the exception handling processes when searching for the handler. The methods on System.Runtime.EH, System.Runtime.StackFrameIterator and System.Runtime.ExceptionServices.InternalCalls are never processed during the EH process, we start on the frame that has thrown the exception, so that should be the first function you'd get reported in ExceptionSearchFunctionEnter/Leave in the first pass / ExceptionUnwindFunctionEnter in the second pass. So I guess the ETL FuntionEnter/FunctionLeave would report the function with the same function id as the one that will be reported by the first ExceptionSearchFunctionEnter, then it would report the internal managed frames on System.Runtime.EH, System.Runtime.StackFrameIterator and System.Runtime.ExceptionServices.InternalCalls and then the actual ExceptionSearchFunctionEnter would be called.

Is there any documentation saying that the last frame reported by the ETL FuntionEnter before an ExceptionSearchFunctionEnter is the one that is throwing the exception?

valco1994 commented 2 months ago

We have managed to resolve the issues mentioned in this issue. It occurred that an invalid profiler callback order occurred due to UB, caused by overwritten XMM registers. The second problem was caused by too strict assumption about the top managed frame in exception-related callbacks, invalid for the new exception handling.