You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
If you are doing in-proc processing of events with EventPipeEventSource and do something that creates an EventPipe provider, such as constructing a new EventSource, in your event processing callback it can deadlock.
The deadlock occurs when the EventPipeSession is being disabled and flushing the remaining contents to the stream, but the EventPipeEventSource thread that is in the middle of reading from the stream is trying to create a new provider. Both provider creation and session termination happen under the global EventPipe lock.
Further complicating this is that EventPipeEventSource is in managed code, so the developer may not be intentionally creating an EventSource. I ran in to it because Console.WriteLine triggered (through String.Format) the creation of ArrayPoolEventSource.
Here is the sample program that will deadlock
using System;
using System.Collections;
using System.Collections.Generic;
using System.Collections.ObjectModel;
using System.Diagnostics;
using System.Diagnostics.Tracing;
using System.Globalization;
using System.IO;
using System.Linq;
using System.Runtime.CompilerServices;
using System.Text;
using System.Threading;
using Microsoft.Diagnostics.NETCore.Client;
using Microsoft.Diagnostics.Tracing;
using Microsoft.Diagnostics.Tracing.Etlx;
namespace MultiThreadedApp
{
[EventData]
struct NestedSerializableClass
{
public int i;
}
[EventData]
struct SerializableClass
{
public int i;
public NestedSerializableClass nested;
public DateTime time;
}
class MyEventSource : EventSource
{
public MyEventSource()
: base(EventSourceSettings.EtwSelfDescribingEventFormat)
{
}
[Event(1, Level = EventLevel.LogAlways)]
public void IntEnumEvent(IEnumerable<int> simpleEnum)
{
WriteEvent(1, simpleEnum);
}
[Event(2, Level = EventLevel.LogAlways)]
public void IntArrayEvent(int[] intArray)
{
WriteEvent(2, intArray);
}
[Event(3, Level = EventLevel.LogAlways)]
public void BasicEvent(int i)
{
WriteEvent(3, i);
}
protected override void OnEventCommand(EventCommandEventArgs command)
{
Console.WriteLine($"command={command.Command}");
}
}
class Program
{
public static EventPipeSession AttachEventPipeSessionToSelf(IEnumerable<EventPipeProvider> providers)
{
int processId = Process.GetCurrentProcess().Id;
DiagnosticsClient client = new DiagnosticsClient(processId);
return client.StartEventPipeSession(providers, /* requestRunDown */ false);
}
static void Main(string[] args)
{
try
{
List<EventPipeProvider> providers = new List<EventPipeProvider>
{
new EventPipeProvider("Microsoft-Windows-DotNETRuntime", EventLevel.Informational, (long)Keywords.Default),
new EventPipeProvider("MyEventSource", EventLevel.Verbose, (long)0xf00000000000)
};
using (EventPipeSession session = AttachEventPipeSessionToSelf(providers))
{
WriteEvents();
ManualResetEvent allEventsReceivedEvent = new ManualResetEvent(false);
int eventCount = 0;
var source = new EventPipeEventSource(session.EventStream);
source.Dynamic.All += (TraceEvent traceEvent) =>
{
if (traceEvent.ProviderName != "Microsoft-Windows-DotNETRuntime")
{
Console.WriteLine($"{traceEvent.ToString()} Keywords={traceEvent.Keywords.ToString("X")} Opcode={traceEvent.Opcode}");
}
if (traceEvent.ProviderName != "MyEventSource")
{
return;
}
Console.WriteLine($"Got event {traceEvent.EventName} with payload count {traceEvent.PayloadNames.Length}");
++eventCount;
if (eventCount == 3)
{
allEventsReceivedEvent.Set();
}
};
Thread processingThread = new Thread(new ThreadStart(() =>
{
source.Process();
}));
Console.WriteLine("Starting processing thread");
processingThread.Start();
session.Stop();
Console.WriteLine("Waiting on event");
allEventsReceivedEvent.WaitOne(TimeSpan.FromSeconds(5));
Console.WriteLine("Joining processing thread");
processingThread.Join();
}
}
catch (Exception e)
{
Console.WriteLine($"Got exception {e.Message} while processing events.");
}
}
private static SerializableClass[] GenerateComplexArray()
{
Random rand = new Random();
SerializableClass[] complexArray = new SerializableClass[1000];
for (int i = 0; i < complexArray.Length; ++i)
{
SerializableClass temp = new SerializableClass()
{
i = rand.Next(),
nested = new NestedSerializableClass()
{
i = rand.Next()
},
time = new DateTime((long)rand.NextDouble())
};
complexArray[i] = temp;
}
return complexArray;
}
private static void WriteEvents()
{
MyEventSource eventSource = new MyEventSource();
Console.WriteLine("Writing events from MyEventSource");
eventSource.BasicEvent(12);
int[] intArray = Enumerable.Range(0, 100).ToArray();
eventSource.IntArrayEvent(intArray);
IEnumerable<int> intEnum = intArray;
eventSource.IntEnumEvent(intEnum);
Console.WriteLine("Done");
}
}
}
I haven't thought about the solution much. It would be nice if we could flush the session's stream outside of the global lock, I imagine that this isn't the only scenario where we could run in to issues. Another option would be to rework EventPipeEventSource so it finished reading from the stream before calling user's callbacks.
Right now I'm filing this as a placeholder so I can finish the array type work.
If you are doing in-proc processing of events with EventPipeEventSource and do something that creates an EventPipe provider, such as constructing a new EventSource, in your event processing callback it can deadlock.
The deadlock occurs when the EventPipeSession is being disabled and flushing the remaining contents to the stream, but the EventPipeEventSource thread that is in the middle of reading from the stream is trying to create a new provider. Both provider creation and session termination happen under the global EventPipe lock.
Further complicating this is that EventPipeEventSource is in managed code, so the developer may not be intentionally creating an EventSource. I ran in to it because Console.WriteLine triggered (through String.Format) the creation of ArrayPoolEventSource.
Here is the sample program that will deadlock
Here are the relevant deadlocked callstacks:
The text was updated successfully, but these errors were encountered: