Access violation (crashes the process) while writing EventSource events

[minkom-ms]

Describe the bug

There is a path in the logging of EventSource events in the HTTP stack which causes an Access Violation.

To Reproduce

Issue appears entirely in .NET call stacks so there are no specific steps to reproduce.

Exceptions (if any)

Application: Microsoft.Office.AugLoop.ServerCore.YarpGateway.exe
CoreCLR Version: 8.0.224.6711
.NET Version: 8.0.2
Description: The process was terminated due to an unhandled exception.
Exception Info: System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
Stack:
   at System.Buffer.Memmove(Byte ByRef, Byte ByRef, UIntPtr)
   at System.String.Ctor(Char*, Int32, Int32)
   at System.Diagnostics.Tracing.EventSource.DecodeObjects(System.Object[], System.Type[], EventData*)
   at System.Diagnostics.Tracing.EventSource.WriteToAllListeners(System.Diagnostics.Tracing.EventWrittenEventArgs, Int32, EventData*)
   at System.Diagnostics.Tracing.EventSource.WriteEventWithRelatedActivityIdCore(Int32, System.Guid*, Int32, EventData*)
   at System.Net.Http.HttpTelemetry.WriteEvent(Int32, Byte, Byte, Int64, System.String, System.String, Int32, System.String)
   at System.Net.Http.HttpConnectionBase..ctor(System.Net.Http.HttpConnectionPool, System.Net.IPEndPoint)
   at System.Net.Http.HttpConnectionPool+<ConstructHttp11ConnectionAsync>d__108.MoveNext()
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.Net.Http.HttpConnectionPool+<ConstructHttp11ConnectionAsync>d__108, System.Net.Http, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]](<ConstructHttp11ConnectionAsync>d__108 ByRef)
   at System.Net.Http.HttpConnectionPool+<CreateHttp11ConnectionAsync>d__105.MoveNext()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.__Canon, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Http.HttpConnectionPool+<CreateHttp11ConnectionAsync>d__105, System.Net.Http, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext(System.Threading.Thread)
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox, Boolean)
   at System.Threading.Tasks.Task.RunContinuations(System.Object)
   at System.Net.Http.HttpConnectionPool+<ConnectAsync>d__103.MoveNext()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.ValueTuple`3[[System.__Canon, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Http.HttpConnectionPool+<ConnectAsync>d__103, System.Net.Http, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext(System.Threading.Thread)
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox, Boolean)
   at System.Threading.Tasks.Task.RunContinuations(System.Object)
   at System.Net.Http.ConnectHelper+<EstablishSslConnectionAsync>d__2.MoveNext()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.__Canon, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Http.ConnectHelper+<EstablishSslConnectionAsync>d__2, System.Net.Http, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext(System.Threading.Thread)
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox, Boolean)
   at System.Threading.Tasks.Task.RunContinuations(System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].SetExistingTaskResult(System.Threading.Tasks.Task`1<System.Threading.Tasks.VoidTaskResult>, System.Threading.Tasks.VoidTaskResult)
   at System.Net.Security.SslStream+<ForceAuthenticationAsync>d__150`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Security.SslStream+<ForceAuthenticationAsync>d__150`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext(System.Threading.Thread)
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox, Boolean)
   at System.Threading.Tasks.Task.RunContinuations(System.Object)
   at System.Net.Security.SslStream+<ReceiveHandshakeFrameAsync>d__151`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Int32, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Security.SslStream+<ReceiveHandshakeFrameAsync>d__151`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext(System.Threading.Thread)
   at System.Net.Security.SslStream+<EnsureFullTlsFrameAsync>d__161`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Net.Sockets.SocketAsyncEventArgs+<>c.<.cctor>b__173_0(UInt32, UInt32, System.Threading.NativeOverlapped*)
   at System.Threading.ThreadPoolTypedWorkItemQueue`2[[System.Threading.PortableThreadPool+IOCompletionPoller+Event, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Threading.PortableThreadPool+IOCompletionPoller+Callback, System.Private.CoreLib, Version=8.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].System.Threading.IThreadPoolWorkItem.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()

Further technical details

CLR and .Net versions are in the call stack above.

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.

[KalleOlaviNiemitalo]

There is a bug here:

runtime/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs

Lines 342 to 386 in 1381d5e

	const int NumEventDatas = 7;
	EventData* descrs = stackalloc EventData[NumEventDatas];
	fixed (char* arg4Ptr = arg4)
	fixed (char* arg5Ptr = arg5)
	fixed (char* arg7Ptr = arg7)
	{
	descrs[0] = new EventData
	{
	DataPointer = (IntPtr)(&arg1),
	Size = sizeof(byte)
	};
	descrs[1] = new EventData
	{
	DataPointer = (IntPtr)(&arg2),
	Size = sizeof(byte)
	};
	descrs[2] = new EventData
	{
	DataPointer = (IntPtr)(&arg3),
	Size = sizeof(long)
	};
	descrs[3] = new EventData
	{
	DataPointer = (IntPtr)arg4Ptr,
	Size = (arg4.Length + 1) * sizeof(char)
	};
	descrs[4] = new EventData
	{
	DataPointer = (IntPtr)arg5Ptr,
	Size = (arg5.Length + 1) * sizeof(char)
	};
	descrs[5] = new EventData
	{
	DataPointer = (IntPtr)(&arg6),
	Size = sizeof(int)
	};
	descrs[6] = new EventData
	{
	DataPointer = (IntPtr)arg7Ptr,
	Size = (arg7.Length + 1) * sizeof(char)
	};
	}
	WriteEventCore(eventId, NumEventDatas, descrs);

The WriteEventCore(eventId, NumEventDatas, descrs) call is not within the fixed block. This allows the garbage collector to move the strings and invalidate the pointers that were stored in descrs[3].DataPointer, descrs[4].DataPointer, and descrs[6].DataPointer. I don't know whether this is what actually causes the crash, but it could very well be.

[KalleOlaviNiemitalo]

Repro by internal reflection

using System;
using System.Diagnostics.Tracing;
using System.Net;
using System.Net.Http;
using System.Reflection;
using System.Threading;
using System.Threading.Tasks;

class Program
{
    static void Main()
    {
        Type httpTelemetryType = Type.GetType("System.Net.Http.HttpTelemetry, System.Net.Http", throwOnError: true)!;
        FieldInfo logField = httpTelemetryType.GetField("Log") ?? throw new Exception("HttpTelemetry.Log field does not exist");
        var httpTelemetry = (EventSource)logField.GetValue(null) ?? throw new Exception("HttpTelemetry.Log is null");

        // public void Http11ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint)
        Action<long, string, string, int, IPEndPoint?> http11ConnectionEstablished
            = httpTelemetryType.GetMethod("Http11ConnectionEstablished")
            .CreateDelegate<Action<long, string, string, int, IPEndPoint?>>(httpTelemetry);

        // public void Http11ConnectionClosed(long connectionId)
        Action<long> http11ConnectionClosed
            = httpTelemetryType.GetMethod("Http11ConnectionClosed")
            .CreateDelegate<Action<long>>(httpTelemetry);

        var listener = new DummyListener();
        listener.EnableEvents(httpTelemetry, EventLevel.Verbose);

        var gcInducerThread = new Thread(() =>
        {
            while (true)
            {
                Thread.Sleep(TimeSpan.FromSeconds(1));
                Console.Write("GC...");
                GC.Collect();
                Console.WriteLine("finished.");
            }
        });
        gcInducerThread.IsBackground = true;
        gcInducerThread.Start();

        Console.WriteLine("Running...");
        Parallel.For(1, 1_000_000_000, (long connectionId) =>
        {
            var remoteEndPoint = new IPEndPoint(address: connectionId, port: 80);
            http11ConnectionEstablished(connectionId, "http", $"host{connectionId}", remoteEndPoint.Port, remoteEndPoint);
            http11ConnectionClosed(connectionId);
        });
    }
}

class DummyListener : EventListener
{
}

[KalleOlaviNiemitalo]

I guess area-System.Net.Http.

[MihaZupan]

Looks like we introduced this one in 8.0: #88853
Thanks for calling out the fixed scope issue @KalleOlaviNiemitalo