CLR profiling: DoStackSnapshot returns wrong Instruction Pointer

[GalSvirin]

I'm currently writing a CLR profiler, and I came across something very odd. When throwing two different exceptions, one from the try clause and one from the catch clause, the CLR notifies me of the same instruction pointer.

I'm registered to receive the ExceptionThrown callback
While inside that callback, I start a DoStackSnapshot on the current thread.

HRESULT stackSnapshotCallback(FunctionID funcId, UINT_PTR ip, COR_PRF_FRAME_INFO, ULONG32, BYTE context[], void *clientData)

(https://docs.microsoft.com/en-us/dotnet/framework/unmanaged-api/profiling/icorprofilerinfo2-dostacksnapshot-method)

I have an exception thrown from a try clause and the corresponding catch clause. StackSnapshotCallback returns the SAME ip for both (UINT_PTR ip)

c# code that reproduces the issue

try
{
    try
    {
        throw new Exception("A");
    }
    catch (Exception)
    {
        throw new Exception("B");
    }
}
catch (Exception)
{
}

I'll also mention that this is not a case of a rethrow, when this is expected.

[lt72]

@GalSvirin1: what platform are you running your test on?
@davmason: PTAL

[ghost]

@lt72 I can confirm this happens to me on Windows x64. Can provide any further information needed. Thanks!

[davmason]

Does it change if you disable optimizations on the method? Either putting a [MethodImpl(MethodImplOptions.NoOptimization | MethodImplOptions.NoInlining)] on the method or running under a debugger should disable optimizations.

I haven't done any investigations, but my first guess would be because the two different throws are being optimized into one instruction. This happens for various reasons inside the jit and it can cause IPs that are ambiguous. I'd like to rule this easy explanation out first.

[ghost]

This happens both during debugging and if I disable the optimizations using MethodImpl.
Also adding COR_PRF_DISABLE_OPTIMIZATIONS to the event masks does not help.
You can see the IL code here: https://gist.github.com/NitzanEgozy/288643aa0d5310dd12802ea9b6b10193
The generated assembly code here: https://gist.github.com/NitzanEgozy/ea15e5420a688aede4002b9f5d758c2f
And the ILToNativeMapping from the profiler API here:
https://gist.github.com/NitzanEgozy/a84926868cc4cfe44dcd50869e2ddf5e
The IP received by the profiler is 0x00007ffaa6aa398e, which matches the first throw, but we can clearly see that the second throw is generated and matches the IL.

I don't know if this is relevant, but this seems to happen with plain c# as well (no profiling):

This code:

try
{
    try
    {
        throw new Exception("A");
    }
    catch (Exception)
    {
        StackTrace st = new StackTrace(true);
        StackFrame sf = st.GetFrame(0);
        Console.WriteLine("Inside catch, instruction: " + sf.GetILOffset() + ". line: " + sf.GetFileLineNumber());
        throw new Exception("B");
    }
}
catch (Exception)
{
    StackTrace st = new StackTrace(true);
    StackFrame sf = st.GetFrame(0);
    Console.WriteLine("Outer catch, instruction: " + sf.GetILOffset() + ". line: " + sf.GetFileLineNumber());
}

Produces this result:
Inside catch, instruction: 13. line: 54 Outer catch, instruction: 13. line: 54

[yyjdelete]

I think hit the same issue but different with NitzanEgozy's, which I can get different(but wrong) IL/Native offset with Expection.

        public static ushort[] FromPMulti2(params string[] ps)
        {
            if (ps.Length == 0)
#line 1000
                throw new InvalidDataException("Invalid Data");

#line 2000
            Console.WriteLine("XX");

#line 3000
            int j = 1 / (ps.Length - 1);

            if (ps.Length > 1)
#line 4000
                throw new InvalidDataException("Test");

            return new ushort[0];
        }

        static void Main(string[] args)
        {
            TryLog(() => FromPMulti2());
            TryLog(() => FromPMulti2(""));
            TryLog(() => FromPMulti2("", ""));
        }

        static void TryLog(Action action)
        {
            try
            {
                action();
            }
            catch (Exception e)
            {
                Console.WriteLine(e.ToString());
            }
        }

Tested with netcoreapp2.0/net471 win10-x64, that always get line 2000 with Debug, and line 4000 with Release(seems the JIT move the two throw to the end of method) instead of line 1000 for the first Exception.
And that only happen with directly throw Exception, runtime Exception like NPE or divide by zero is not affected by that.

@davmason
Not sure, but seems directly throw Exception will call GetILOffsetFromNative with offset of THE NEXT native code instead of the current to get line info?

[ghost]

Any news regarding this?
Thanks,
Nitzan.

[ghost]

Should this bug also be tagged in
https://github.com/orgs/dotnet/projects/9

[dotnet-policy-service]

Due to lack of recent activity, this issue has been marked as a candidate for backlog cleanup. It will be closed if no further activity occurs within 14 more days. Any new comment (by anyone, not necessarily the author) will undo this process.

This process is part of our issue cleanup automation.