dotnet / dotnet/runtime

EventPipe doesn't correctly recompute global keyword and level filters after session close

Open
#121,462 3 comments 2 reactions 2 assignees Claimed by @steveisok View on GitHub
area-System.Diagnostics.Tracing EventPipe
Dominant language
C#
Stars
18.3k
Forks
5.6k
PR merge metrics
PR metrics pending

Description

### Description

EventPipe is intended to maintain a current keyword and level filter for each EventSource based on the set of active tracing sessions. Whenever a new session starts or an existing session finishes these filters may need to be updated. Unforetunately the update on session end isn't correct and the keyword and level filters still include the session that is exiting. One of the ways the keyword and level filters are visible is through the EventSource.IsEnabled(level, keyword) API which returns incorrect results.

### Reproduction Steps

1. Compile and run this code:

```C#
using System.Diagnostics.Tracing;

namespace ConsoleApp63
{
internal class Program
{
static void Main(string[] args)
{
MyEventSource.Log.Info1("Hello, World!");
Console.ReadLine();
}
}

[EventSource(Name ="MyEventSource")]
public class MyEventSource : EventSource
{
public static MyEventSource Log = new MyEventSource();
[Event(1, Level = EventLevel.Informational)]
public void Info1(string message)
{
WriteEvent(1, message);
}

override protected void OnEventCommand(EventCommandEventArgs args)
{
Console.WriteLine($"IsEnabled(Level=Info,Keyword=2): {this.IsEnabled(EventLevel.Informational, (EventKeywords)0x2)}");
}
}
}
```

2. In a 2nd console window start an EventPipe session by running:
`dotnet-trace collect -n --providers MyEventSource:1:Error`

3. In a 3rd console window start another EventPipe session by running:
`dotnet-trace collect -n --providers MyEventSource:2:Informational`

4. Hit enter in the 3rd console window to stop the Informational level session
5. Hit enter in the 2nd console window to stop the Error level session

### Expected behavior

Each step 2-5 should print one line of this output:
```
IsEnabled(Level=Info,Keyword=2): False
IsEnabled(Level=Info,Keyword=2): True
IsEnabled(Level=Info,Keyword=2): False
IsEnabled(Level=Info,Keyword=2): False
```

### Actual behavior

Each step 2-5 should print one line of this output:
```
IsEnabled(Level=Info,Keyword=2): False
IsEnabled(Level=Info,Keyword=2): True
IsEnabled(Level=Info,Keyword=2): True
IsEnabled(Level=Info,Keyword=2): False
```

### Regression?

Unverified, but the issue probably extends back to when EventPipe was first added.

### Known Workarounds

_No response_

### Configuration

Windows x64 .NET 10 Preview but I expect it reproes on any config

### Other information

I believe there are actually two separate bugs that cause this:

1. In the EventPipe source code when disabling a session the update calcuation for level and keyword should exclude the session being disabled but doesn't:
https://github.com/dotnet/runtime/blob/main/src/native/eventpipe/ep-config.c#L588

2. In the EventSource code when a session disables a provider the keyword and level aren't recalculated
https://github.com/dotnet/runtime/blob/767be2a5fc0ca26a4059883ae22a5d4522086cc6/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs#L2760-L2791

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.