DOTNET_EnableEventPipe=1 vs dotnet-trace collect

[stefan-sf-ibm]

I'm wondering what the difference between enabling EventPipe tracing via environment variable DOTNET_EnableEventPipe=1 and via command dotnet-trace collect is. Consider the following example:

namespace HelloWorld
{
  class Program
  {
    static void foo()
    {
      System.Console.WriteLine("Hello World");
    }

    static void Main(string[] args)
    {
      foo();
    }
  }
}

and a minimal c# project file:

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net6.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

</Project>

Running dotnet-trace collect -- dotnet bin/Debug/net6.0/test.dll after dotnet build creates a nettrace file of size roughly 200kb. Inspecting the trace e.g. via perfview I see a call to test!HelloWorld.Program.Main(class System.String[]) and then a call to test!HelloWorld.Program.foo() as expected in the flame graph.

In contrast, running DOTNET_EnableEventPipe=1 dotnet run creates a nettrace file of size roughly 15mb which is way bigger than the previous trace. However, inspecting the trace I barely see any function calls. Especially the function calls of my test application are all missing in the flame graph.

I first assumed that the difference is due to different configured providers. According to this if DOTNET_EnableEventPipe=1 is set, then the following providers are enabled:

• Microsoft-Windows-DotNETRuntime:4c14fccbd:5
• Microsoft-Windows-DotNETRuntimePrivate:4002000b:5
• Microsoft-DotNETCore-SampleProfiler:0:5

However, those are also enabled via dotnet-trace collect which prints to stdout:

$ dotnet-trace collect -- dotnet bin/Debug/net6.0/test.dll
No profile or providers specified, defaulting to trace profile 'cpu-sampling'

Provider Name                           Keywords            Level               Enabled By
Microsoft-DotNETCore-SampleProfiler     0x0000F00000000000  Informational(4)    --profile
Microsoft-Windows-DotNETRuntime         0x00000014C14FCCBD  Informational(4)    --profile

...

All providers which are enabled via dotnet-trace collect are also enabled via DOTNET_EnableEventPipe=1 and even more. The level is also higher. The only difference I see is the keyword for the CPU sampler (though, couldn't find it documented). In order to rule out that the keyword makes a difference I tried to explicitly enable the same providers as done via dotnet-trace collect and ran:

DOTNET_EnableEventPipe=1 DOTNET_EventPipeConfig=Microsoft-DotNETCore-SampleProfiler:f00000000000:4,Microsoft-Windows-DotNETRuntime:4c14fccbd:4 dotnet run

Though, this leads to a segfault on Ubuntu 20.04 (EDIT: the segfault is fixed for me by PR #68552).

I'm probably missing something. Can someone shed some light on the difference between DOTNET_EnableEventPipe=1 and dotnet-trace collect?

$ dotnet --info
.NET SDK (reflecting any global.json):
 Version:   6.0.202
 Commit:    f8a55617d2

Runtime Environment:
 OS Name:     ubuntu
 OS Version:  20.04
 OS Platform: Linux
 RID:         ubuntu.20.04-x64
 Base Path:   /dotnet-sdk-6.0.202-linux-x64/sdk/6.0.202/

Host (useful for support):
  Version: 6.0.4
  Commit:  be98e88c76

.NET SDKs installed:
  6.0.202 [/dotnet-sdk-6.0.202-linux-x64/sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.4 [/dotnet-sdk-6.0.202-linux-x64/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 6.0.4 [/dotnet-sdk-6.0.202-linux-x64/shared/Microsoft.NETCore.App]

To install additional .NET runtimes or SDKs:
  https://aka.ms/dotnet-download

[uweigand]

Hi @directhex @steveisok @crummel - do you know who could help with this question?

[steveisok]

I think there isn't a whole lot different other than a consistent cli experience.

@lateralusX is that correct?

[lateralusX]

Main difference is that the single file based version have different defaults and starts up a little earlier compared to what you can get with sessions through diagnostic server starting up in suspended mode (waiting for first session to be created). The single file based version also depends on clean process shutdown in order to get all rundown events, something that the session based nettrace files will get when you stop them. I have successfully used both versions to get profiled data, but you need to close down the runtime in order to get a complete file when using the single file based version. There might also be an idea to run with streaming mode, or you might end up with dropped events due to full buffer manager, https://github.com/dotnet/runtime/blob/main/docs/design/mono/diagnostics-tracing.md#application-running-single-file-based-eventpipe-session.

[lateralusX]

If you don't get the rundown events into the nettrace files, tools won't be able to symbolicate callstacks.

[lateralusX]

Also, the single file defaults to verbose output of the events, that will generate more events. Having a nettrace file of 15MB for above sounds large, when I run single file on x64 system using a simple Hello World sample, it normally ends up around 1MB using defaults.

You can always load the nettrace file into tools like prefview if you would like to see what events and the number of events generated into the nettrace file. It is also quite easy to use TraceEvent library to write a simple parser inspecting nettrace files as well.

[stefan-sf-ibm]

I did some further experiments and it turns out that I ran into the following described in https://docs.microsoft.com/en-us/dotnet/core/diagnostics/dotnet-trace#use-diagnostic-port-to-collect-a-trace-from-app-startup

Launching your app with dotnet run can be problematic because the dotnet CLI may spawn many child processes that are not your app and they can connect to dotnet-trace before your app, leaving your app to be suspended at run time. It is recommended you directly use a self-contained version of the app or use dotnet exec to launch the application.

Thus, I might have traced a different process than my Hello World application which might explain the file size difference. Running dotnet exec gives me 1MB trace, too.