From dd4ee672ed3e2f4463a1a40e164e235acfe91aa4 Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Wed, 3 Dec 2025 00:42:29 +0000 Subject: [PATCH 01/10] [Tests] Standup shared UserEventsTestRunner --- eng/Versions.props | 3 +- src/tests/tracing/userevents/README.md | 29 +++ .../tracing/userevents/common/NuGet.config | 6 + .../common/UserEventsRequirements.cs | 185 ++++++++++++++++++ .../userevents/common/UserEventsTestRunner.cs | 163 +++++++++++++++ .../common/userevents_common.csproj | 28 +++ 6 files changed, 413 insertions(+), 1 deletion(-) create mode 100644 src/tests/tracing/userevents/README.md create mode 100644 src/tests/tracing/userevents/common/NuGet.config create mode 100644 src/tests/tracing/userevents/common/UserEventsRequirements.cs create mode 100644 src/tests/tracing/userevents/common/UserEventsTestRunner.cs create mode 100644 src/tests/tracing/userevents/common/userevents_common.csproj diff --git a/eng/Versions.props b/eng/Versions.props index ad0283439a0745..50d929abea061a 100644 --- a/eng/Versions.props +++ b/eng/Versions.props @@ -109,7 +109,7 @@ 2.0.0 17.10.0-beta1.24272.1 - 3.1.16 + 3.1.28 0.2.621003 2.1.0 2.0.3 @@ -124,6 +124,7 @@ 1.6.0 17.4.0-preview-20220707-01 + 0.1.32221 3.12.0 4.5.0 6.0.4 diff --git a/src/tests/tracing/userevents/README.md b/src/tests/tracing/userevents/README.md new file mode 100644 index 00000000000000..a679912f6093dc --- /dev/null +++ b/src/tests/tracing/userevents/README.md @@ -0,0 +1,29 @@ +# User Events Functional Tests + +This directory contains **functional tests** for the .NET user_events scenario. These tests validate that .NET Runtime user events can be emitted via EventPipe and collected by [one-collect](https://github.com/microsoft/one-collect/)'s `record-trace` tool. + +## High-level Test Flow + +Each scenario uses the same pattern: + +1. **Scenario invokes the shared test runner** + + User events scenarios can differ in their tracee logic, the events expected in the .nettrace, the record-trace script used to collect those events, and how long it takes for the tracee to emit them and for record-trace to resolve symbols and write the .nettrace. To handle this variance, UserEventsTestRunner lets each scenario pass in its scenario-specific record-trace script path, the path to its test assembly (used to spawn the tracee process), a validator that checks for the expected events from the tracee, and optional timeouts for both the tracee and record-trace to exit gracefully. + +2. **`UserEventsTestRunner` orchestrates tracing and validation** + + Using this configuration, UserEventsTestRunner first checks whether user events are supported. It then starts record-trace with the scenario’s script and launches the tracee process so it can emit events. After the run completes, the runner stops both the tracee and record-trace, opens the resulting .nettrace with EventPipeEventSource, and applies the scenario’s validator to confirm that the expected events were recorded. Finally, it returns an exit code indicating whether the scenario passed or failed. + +## Layout + +- `common/` + - `UserEventsRequirements.cs` - Checks whether the environment supports user events. + - `UserEventsTestRunner.cs` - Shared runner that coordinates `record-trace`, the tracee process, and event validation. + - `userevents_common.csproj` - Common project for shared user events test logic. + - `NuGet.config` - Configures dotnet-diagnostics-tests nuget source which transports Microsoft.OneCollect.RecordTrace. +- `/` + - `.cs` - The tracee workload logic used when invoked with the `tracee` argument. + - `.csproj` - Project file for the scenario. + - `.script` - `record-trace` script that configures how to collect the trace for the scenario. + +Each scenario reuses the common runner and shared `record-trace` deployable instead of duplicating binaries or orchestration logic. diff --git a/src/tests/tracing/userevents/common/NuGet.config b/src/tests/tracing/userevents/common/NuGet.config new file mode 100644 index 00000000000000..583af9d11bb787 --- /dev/null +++ b/src/tests/tracing/userevents/common/NuGet.config @@ -0,0 +1,6 @@ + + + + + + diff --git a/src/tests/tracing/userevents/common/UserEventsRequirements.cs b/src/tests/tracing/userevents/common/UserEventsRequirements.cs new file mode 100644 index 00000000000000..7f210f1e1d7e57 --- /dev/null +++ b/src/tests/tracing/userevents/common/UserEventsRequirements.cs @@ -0,0 +1,185 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics; +using System.IO; + +namespace Tracing.UserEvents.Tests.Common +{ + internal static class UserEventsRequirements + { + private static readonly Version s_minKernelVersion = new(6, 4); + private const string TracefsPath = "/sys/kernel/tracing"; + private const string UserEventsDataPath = "/sys/kernel/tracing/user_events_data"; + private static readonly Version s_minGlibcVersion = new(2, 35); + + internal static bool IsSupported() + { + if (Environment.OSVersion.Version < s_minKernelVersion) + { + Console.WriteLine($"Kernel version '{Environment.OSVersion.Version}' is less than the minimum required '{s_minKernelVersion}'"); + return false; + } + + return IsGlibcAtLeast(s_minGlibcVersion) && + IsTracefsMounted() && + IsUserEventsDataAvailable(); + } + + private static bool IsTracefsMounted() + { + ProcessStartInfo checkTracefsStartInfo = new(); + checkTracefsStartInfo.FileName = "sudo"; + checkTracefsStartInfo.Arguments = $"-n test -d {TracefsPath}"; + checkTracefsStartInfo.UseShellExecute = false; + checkTracefsStartInfo.RedirectStandardOutput = true; + checkTracefsStartInfo.RedirectStandardError = true; + + using Process checkTracefs = new() { StartInfo = checkTracefsStartInfo }; + checkTracefs.OutputDataReceived += (_, e) => + { + if (!string.IsNullOrEmpty(e.Data)) + { + Console.WriteLine($"[tracefs-check] {e.Data}"); + } + }; + checkTracefs.ErrorDataReceived += (_, e) => + { + if (!string.IsNullOrEmpty(e.Data)) + { + Console.Error.WriteLine($"[tracefs-check] {e.Data}"); + } + }; + + checkTracefs.Start(); + checkTracefs.BeginOutputReadLine(); + checkTracefs.BeginErrorReadLine(); + checkTracefs.WaitForExit(); + if (checkTracefs.ExitCode == 0) + { + return true; + } + + Console.WriteLine($"Tracefs not mounted at '{TracefsPath}'."); + return false; + } + + private static bool IsUserEventsDataAvailable() + { + ProcessStartInfo checkUserEventsDataStartInfo = new(); + checkUserEventsDataStartInfo.FileName = "sudo"; + checkUserEventsDataStartInfo.Arguments = $"-n test -e {UserEventsDataPath}"; + checkUserEventsDataStartInfo.UseShellExecute = false; + checkUserEventsDataStartInfo.RedirectStandardOutput = true; + checkUserEventsDataStartInfo.RedirectStandardError = true; + + using Process checkUserEventsData = new() { StartInfo = checkUserEventsDataStartInfo }; + checkUserEventsData.OutputDataReceived += (_, e) => + { + if (!string.IsNullOrEmpty(e.Data)) + { + Console.WriteLine($"[user-events-check] {e.Data}"); + } + }; + checkUserEventsData.ErrorDataReceived += (_, e) => + { + if (!string.IsNullOrEmpty(e.Data)) + { + Console.Error.WriteLine($"[user-events-check] {e.Data}"); + } + }; + + checkUserEventsData.Start(); + checkUserEventsData.BeginOutputReadLine(); + checkUserEventsData.BeginErrorReadLine(); + checkUserEventsData.WaitForExit(); + if (checkUserEventsData.ExitCode == 0) + { + return true; + } + + Console.WriteLine($"User events data not available at '{UserEventsDataPath}'."); + return false; + } + + private static bool IsGlibcAtLeast(Version minVersion) + { + ProcessStartInfo lddStartInfo = new(); + lddStartInfo.FileName = "ldd"; + lddStartInfo.Arguments = "--version"; + lddStartInfo.UseShellExecute = false; + lddStartInfo.RedirectStandardOutput = true; + lddStartInfo.RedirectStandardError = true; + + using Process lddProcess = new() { StartInfo = lddStartInfo }; + string? detectedVersionLine = null; + + lddProcess.OutputDataReceived += (_, e) => + { + if (!string.IsNullOrEmpty(e.Data) && detectedVersionLine is null) + { + detectedVersionLine = e.Data; + } + }; + lddProcess.ErrorDataReceived += (_, e) => + { + if (!string.IsNullOrEmpty(e.Data)) + { + Console.Error.WriteLine($"[ldd] {e.Data}"); + } + }; + + try + { + lddProcess.Start(); + } + catch (Exception ex) + { + Console.WriteLine($"Failed to start 'ldd --version': {ex.Message}"); + return false; + } + + lddProcess.BeginOutputReadLine(); + lddProcess.BeginErrorReadLine(); + lddProcess.WaitForExit(); + + if (lddProcess.ExitCode != 0) + { + Console.WriteLine($"'ldd --version' exited with code {lddProcess.ExitCode}."); + return false; + } + + if (string.IsNullOrEmpty(detectedVersionLine)) + { + Console.WriteLine("Could not read glibc version from 'ldd --version' output."); + return false; + } + + string[] tokens = detectedVersionLine.Split(' ', StringSplitOptions.RemoveEmptyEntries); + Version? glibcVersion = null; + foreach (string token in tokens) + { + if (Version.TryParse(token, out Version? parsedVersion)) + { + glibcVersion = parsedVersion; + break; + } + } + + if (glibcVersion is null) + { + Console.WriteLine($"Failed to parse glibc version from 'ldd --version' output line: {detectedVersionLine}"); + return false; + } + + if (glibcVersion < minVersion) + { + Console.WriteLine($"glibc version '{glibcVersion}' is less than required '{minVersion}'."); + return false; + } + + return true; + } + } +} diff --git a/src/tests/tracing/userevents/common/UserEventsTestRunner.cs b/src/tests/tracing/userevents/common/UserEventsTestRunner.cs new file mode 100644 index 00000000000000..41896c59fa162e --- /dev/null +++ b/src/tests/tracing/userevents/common/UserEventsTestRunner.cs @@ -0,0 +1,163 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics; +using System.IO; +using System.Runtime.InteropServices; +using Microsoft.Diagnostics.Tracing; + +namespace Tracing.UserEvents.Tests.Common +{ + public class UserEventsTestRunner + { + private const int SIGINT = 2; + private const int DefaultTraceeExitTimeoutMs = 5000; + private const int DefaultRecordTraceExitTimeoutMs = 20000; + + [DllImport("libc", EntryPoint = "kill", SetLastError = true)] + private static extern int Kill(int pid, int sig); + + public static int Run( + string scenarioName, + string traceeAssemblyPath, + Func traceValidator, + int traceeExitTimeout = DefaultTraceeExitTimeoutMs, + int recordTraceExitTimeout = DefaultRecordTraceExitTimeoutMs) + { + string userEventsScenarioDir = Path.GetDirectoryName(traceeAssemblyPath); + string recordTracePath = ResolveRecordTracePath(userEventsScenarioDir); + string scriptFilePath = Path.Combine(userEventsScenarioDir, $"{scenarioName}.script"); + + if (!UserEventsRequirements.IsSupported()) + { + Console.WriteLine("Skipping test: environment does not support user events."); + return 100; + } + if (!File.Exists(recordTracePath)) + { + Console.Error.WriteLine($"record-trace not found at `{recordTracePath}`. Test cannot run."); + return -1; + } + if (!File.Exists(scriptFilePath)) + { + Console.Error.WriteLine($"record-trace script-file not found at `{scriptFilePath}`. Test cannot run."); + return -1; + } + + string traceFilePath = Path.GetTempFileName(); + // In the past, it's been observed that record-trace has trouble overwriting newly created temp files + // in `/tmp` (e.g. mktemp or Path.GetTempFileName). It's suspected to be a permissions issue. + // As a workaround, deleting the temp file and allowing record-trace to create it works reliably. + File.Delete(traceFilePath); + traceFilePath = Path.ChangeExtension(traceFilePath, ".nettrace"); + + ProcessStartInfo recordTraceStartInfo = new(); + recordTraceStartInfo.FileName = "sudo"; + recordTraceStartInfo.Arguments = $"-n {recordTracePath} --script-file {scriptFilePath} --out {traceFilePath}"; + recordTraceStartInfo.WorkingDirectory = userEventsScenarioDir; + recordTraceStartInfo.UseShellExecute = false; + recordTraceStartInfo.RedirectStandardOutput = true; + recordTraceStartInfo.RedirectStandardError = true; + + Console.WriteLine($"Starting record-trace: {recordTraceStartInfo.FileName} {recordTraceStartInfo.Arguments}"); + using Process recordTraceProcess = Process.Start(recordTraceStartInfo); + recordTraceProcess.OutputDataReceived += (_, args) => + { + if (!string.IsNullOrEmpty(args.Data)) + { + Console.WriteLine($"[record-trace] {args.Data}"); + } + }; + recordTraceProcess.BeginOutputReadLine(); + recordTraceProcess.ErrorDataReceived += (_, args) => + { + if (!string.IsNullOrEmpty(args.Data)) + { + Console.Error.WriteLine($"[record-trace] {args.Data}"); + } + }; + recordTraceProcess.BeginErrorReadLine(); + Console.WriteLine($"record-trace started with PID: {recordTraceProcess.Id}"); + + ProcessStartInfo traceeStartInfo = new(); + traceeStartInfo.FileName = Process.GetCurrentProcess().MainModule!.FileName; + traceeStartInfo.Arguments = $"{traceeAssemblyPath} tracee"; + traceeStartInfo.WorkingDirectory = userEventsScenarioDir; + traceeStartInfo.RedirectStandardOutput = true; + traceeStartInfo.RedirectStandardError = true; + + Console.WriteLine($"Starting tracee process: {traceeStartInfo.FileName} {traceeStartInfo.Arguments}"); + using Process traceeProcess = Process.Start(traceeStartInfo); + Console.WriteLine($"Tracee process started with PID: {traceeProcess.Id}"); + traceeProcess.OutputDataReceived += (_, args) => + { + if (!string.IsNullOrEmpty(args.Data)) + { + Console.WriteLine($"[tracee] {args.Data}"); + } + }; + traceeProcess.BeginOutputReadLine(); + traceeProcess.ErrorDataReceived += (_, args) => + { + if (!string.IsNullOrEmpty(args.Data)) + { + Console.Error.WriteLine($"[tracee] {args.Data}"); + } + }; + traceeProcess.BeginErrorReadLine(); + + Console.WriteLine($"Waiting for tracee process to exit..."); + if (!traceeProcess.HasExited && !traceeProcess.WaitForExit(traceeExitTimeout)) + { + Console.WriteLine($"Tracee process did not exit within the {traceeExitTimeout}ms timeout, killing it."); + traceeProcess.Kill(); + } + traceeProcess.WaitForExit(); // flush async output + + if (!recordTraceProcess.HasExited) + { + // Until record-trace supports duration, the only way to stop it is to send SIGINT (ctrl+c) + Console.WriteLine($"Stopping record-trace with SIGINT."); + Kill(recordTraceProcess.Id, SIGINT); + Console.WriteLine($"Waiting for record-trace to exit..."); + if (!recordTraceProcess.WaitForExit(recordTraceExitTimeout)) + { + // record-trace needs to stop gracefully to generate the trace file + Console.WriteLine($"record-trace did not exit within the {recordTraceExitTimeout}ms timeout, killing it."); + recordTraceProcess.Kill(); + } + } + else + { + Console.WriteLine($"record-trace unexpectedly exited without SIGINT with code {recordTraceProcess.ExitCode}."); + } + recordTraceProcess.WaitForExit(); // flush async output + + if (!File.Exists(traceFilePath)) + { + Console.Error.WriteLine($"Expected trace file not found at `{traceFilePath}`"); + return -1; + } + + using EventPipeEventSource source = new EventPipeEventSource(traceFilePath); + if (!traceValidator(source)) + { + Console.Error.WriteLine($"Trace file `{traceFilePath}` does not contain expected events."); + return -1; + } + + return 100; + } + + private static string ResolveRecordTracePath(string userEventsScenarioDir) + { + // scenario dir: .../tracing/userevents// + string usereventsRoot = Path.GetFullPath(Path.Combine(userEventsScenarioDir, "..", "..")); + // common dir: .../tracing/userevents/common/userevents_common + string commonDir = Path.Combine(usereventsRoot, "common", "userevents_common"); + string recordTracePath = Path.Combine(commonDir, "record-trace"); + return recordTracePath; + } + } +} \ No newline at end of file diff --git a/src/tests/tracing/userevents/common/userevents_common.csproj b/src/tests/tracing/userevents/common/userevents_common.csproj new file mode 100644 index 00000000000000..8bae27e3e7d1e2 --- /dev/null +++ b/src/tests/tracing/userevents/common/userevents_common.csproj @@ -0,0 +1,28 @@ + + + BuildOnly + false + + + + + + + + + + + + + + <_DestDir>$(TargetDir) + <_DestDir Condition="'$(_DestDir)' == ''">$(OutputPath) + <_RecordTraceSource>$(NuGetPackageRoot)microsoft.onecollect.recordtrace/$(MicrosoftOneCollectRecordTraceVersion)/runtimes/linux-$(TargetArchitecture)/native/record-trace + + + + + + + + From acf1c284ff7c575c1e55eef48ba61efbb9042d48 Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Wed, 3 Dec 2025 00:43:07 +0000 Subject: [PATCH 02/10] [Tests] Add basic UserEvents scenario --- src/tests/tracing/userevents/README.md | 4 +- src/tests/tracing/userevents/basic/basic.cs | 64 +++++++++++++++++++ .../tracing/userevents/basic/basic.csproj | 19 ++++++ .../tracing/userevents/basic/basic.script | 2 + 4 files changed, 87 insertions(+), 2 deletions(-) create mode 100644 src/tests/tracing/userevents/basic/basic.cs create mode 100644 src/tests/tracing/userevents/basic/basic.csproj create mode 100644 src/tests/tracing/userevents/basic/basic.script diff --git a/src/tests/tracing/userevents/README.md b/src/tests/tracing/userevents/README.md index a679912f6093dc..71df5e9c7fccf1 100644 --- a/src/tests/tracing/userevents/README.md +++ b/src/tests/tracing/userevents/README.md @@ -4,7 +4,7 @@ This directory contains **functional tests** for the .NET user_events scenario. ## High-level Test Flow -Each scenario uses the same pattern: +Each scenario (for example, `basic`) uses the same pattern: 1. **Scenario invokes the shared test runner** @@ -26,4 +26,4 @@ Each scenario uses the same pattern: - `.csproj` - Project file for the scenario. - `.script` - `record-trace` script that configures how to collect the trace for the scenario. -Each scenario reuses the common runner and shared `record-trace` deployable instead of duplicating binaries or orchestration logic. +Each scenario reuses the common runner and shared `record-trace` deployable instead of duplicating binaries or orchestration logic. The `basic` scenario serves as a concrete example of how to add additional scenarios. diff --git a/src/tests/tracing/userevents/basic/basic.cs b/src/tests/tracing/userevents/basic/basic.cs new file mode 100644 index 00000000000000..b53774c0dde677 --- /dev/null +++ b/src/tests/tracing/userevents/basic/basic.cs @@ -0,0 +1,64 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics; +using System.Threading; +using Tracing.UserEvents.Tests.Common; +using Microsoft.Diagnostics.Tracing; + +namespace Tracing.UserEvents.Tests.Basic +{ + public class Basic + { + private static byte[] s_array; + + public static void BasicTracee() + { + long startTimestamp = Stopwatch.GetTimestamp(); + long targetTicks = Stopwatch.Frequency; // 1s + + while (Stopwatch.GetTimestamp() - startTimestamp < targetTicks) + { + s_array = new byte[1024 * 100]; + Thread.Sleep(100); + } + } + + private readonly static Func s_traceValidator = source => + { + bool allocationSampledEventFound = false; + + source.Dynamic.All += (TraceEvent e) => + { + if (e.ProviderName == "Microsoft-Windows-DotNETRuntime") + { + // TraceEvent's ClrTraceEventParser does not know about the AllocationSampled Event, so it shows up as "Unknown(303)" + if (e.EventName.StartsWith("Unknown") && e.ID == (TraceEventID)303) + { + allocationSampledEventFound = true; + } + } + }; + + source.Process(); + + if (!allocationSampledEventFound) + { + Console.Error.WriteLine("The trace did not contain an AllocationSampled event."); + } + return allocationSampledEventFound; + }; + + public static int Main(string[] args) + { + if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) + { + BasicTracee(); + return 0; + } + + return UserEventsTestRunner.Run("basic", typeof(Basic).Assembly.Location, s_traceValidator); + } + } +} diff --git a/src/tests/tracing/userevents/basic/basic.csproj b/src/tests/tracing/userevents/basic/basic.csproj new file mode 100644 index 00000000000000..6e47928f023a62 --- /dev/null +++ b/src/tests/tracing/userevents/basic/basic.csproj @@ -0,0 +1,19 @@ + + + true + true + false + + + + + + + + + + Always + basic.script + + + diff --git a/src/tests/tracing/userevents/basic/basic.script b/src/tests/tracing/userevents/basic/basic.script new file mode 100644 index 00000000000000..d6ac4f6ee89060 --- /dev/null +++ b/src/tests/tracing/userevents/basic/basic.script @@ -0,0 +1,2 @@ +let Microsoft_Windows_DotNETRuntime_flags = new_dotnet_provider_flags(); +record_dotnet_provider("Microsoft-Windows-DotNETRuntime", 0x80000000000, 4, Microsoft_Windows_DotNETRuntime_flags); From 5e94c0550a08aa047945c57cb9bfad14bad2178b Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Wed, 3 Dec 2025 00:48:26 +0000 Subject: [PATCH 03/10] [Helix] Adapt tests for helix nuances UserEvents functional runtime tests differ from other runtime tests because it depends on OneCollect's Record-Trace tool to enable a userevents-based eventpipe session and to collect events. By design, Record-Trace requires elevated privileges, so these tests invoke a record-trace executable with sudo. When tests run on Helix, test artifacts are stripped of their permissions, so the test infrastructure was modified to give record-trace execute permissions (helix-extra-executables.list). Moreover, to avoid having one copy of record-trace per scenario, which in turn requires re-adding execute permissions for each, more modifications were added to copy over a single record-trace executable that would be used by all scenarios (OutOfProcess marker). Additionally, in Helix environments, TMPDIR is set to a helix specific temporary directory like /datadisks/disk1/work//t, and at this time, record-trace only scans /tmp/ for the runtime's diagnostic ports. So as a workaround, the tracee apps are spawned with TMPDIR set to /tmp. Lastly, the job steps to run tests on AzDO prevents restoring individual runtime test projects. Because record-trace is currently only resolvable through the dotnet-diagnostics-tests source, userevents_common.csproj was added to the group of projects restored at the beginning of copying native test components to restore Microsoft.OneCollect.RecordTrace. --- src/tests/Common/helixpublishwitharcade.proj | 16 +++++++ src/tests/build.proj | 1 + .../userevents/common/UserEventsTestRunner.cs | 42 ++++++++++++++++++- .../common/userevents_common.csproj | 15 ++++++- 4 files changed, 72 insertions(+), 2 deletions(-) diff --git a/src/tests/Common/helixpublishwitharcade.proj b/src/tests/Common/helixpublishwitharcade.proj index fa4ecc1faf92e4..b613c275deeb69 100644 --- a/src/tests/Common/helixpublishwitharcade.proj +++ b/src/tests/Common/helixpublishwitharcade.proj @@ -412,12 +412,28 @@ $(XUnitLogCheckerHelixPath)XUnitLogChecker$(ExeSuffix) $(XUnitLogCheckerArgs) + + <_ExtraTestExecutablesListFiles Remote="@(_ExtraTestExecutablesListFiles)" /> + <_ExtraTestExecutablesListFiles Include="@(_MergedPayloadFiles)" + Condition="$([System.String]::Copy('%(Identity)').ToLower().EndsWith('helix-extra-executables.list'))" /> + <_ExtraTestExecutables Remove="@(_ExtraTestExecutables)" /> + + + + + + <_ExtraTestExecutables Remove="@(_ExtraTestExecutables)" Condition="'%(Identity)' == ''" /> + + + + + diff --git a/src/tests/build.proj b/src/tests/build.proj index 8ba1b4eb2f3ed6..c2f21ca2877dc5 100644 --- a/src/tests/build.proj +++ b/src/tests/build.proj @@ -40,6 +40,7 @@ + diff --git a/src/tests/tracing/userevents/common/UserEventsTestRunner.cs b/src/tests/tracing/userevents/common/UserEventsTestRunner.cs index 41896c59fa162e..0c8b6f9897d3e8 100644 --- a/src/tests/tracing/userevents/common/UserEventsTestRunner.cs +++ b/src/tests/tracing/userevents/common/UserEventsTestRunner.cs @@ -87,9 +87,14 @@ public static int Run( traceeStartInfo.RedirectStandardOutput = true; traceeStartInfo.RedirectStandardError = true; + // record-trace currently only searches /tmp/ for diagnostic ports https://github.com/microsoft/one-collect/issues/183 + string diagnosticPortDir = "/tmp/"; + traceeStartInfo.Environment["TMPDIR"] = diagnosticPortDir; + Console.WriteLine($"Starting tracee process: {traceeStartInfo.FileName} {traceeStartInfo.Arguments}"); using Process traceeProcess = Process.Start(traceeStartInfo); - Console.WriteLine($"Tracee process started with PID: {traceeProcess.Id}"); + int traceePid = traceeProcess.Id; + Console.WriteLine($"Tracee process started with PID: {traceePid}"); traceeProcess.OutputDataReceived += (_, args) => { if (!string.IsNullOrEmpty(args.Data)) @@ -115,6 +120,12 @@ public static int Run( } traceeProcess.WaitForExit(); // flush async output + // TMPDIR is configured on Helix, but the diagnostic port was created outside of helix's default temp datadisk path. + // The diagnostic port should be automatically cleaned up when the tracee shutsdown, but just in case of an + // abrupt exit, ensure cleanup to avoid leaving artifacts on helix machines. + // When https://github.com/microsoft/one-collect/issues/183 is fixed, this and the above TMPDIR should be removed. + CleanupTraceeDiagnosticPorts(diagnosticPortDir, traceePid); + if (!recordTraceProcess.HasExited) { // Until record-trace supports duration, the only way to stop it is to send SIGINT (ctrl+c) @@ -144,6 +155,7 @@ public static int Run( if (!traceValidator(source)) { Console.Error.WriteLine($"Trace file `{traceFilePath}` does not contain expected events."); + UploadTraceFileFromHelix(traceFilePath, scenarioName); return -1; } @@ -159,5 +171,33 @@ private static string ResolveRecordTracePath(string userEventsScenarioDir) string recordTracePath = Path.Combine(commonDir, "record-trace"); return recordTracePath; } + + private static void CleanupTraceeDiagnosticPorts(string diagnosticPortDir, int traceePid) + { + try + { + string[] udsFiles = Directory.GetFiles(diagnosticPortDir, $"dotnet-diagnostic-{traceePid}-*-socket"); + foreach (string udsFile in udsFiles) + { + Console.WriteLine($"Deleting tracee diagnostic port UDS file: {udsFile}"); + File.Delete(udsFile); + } + } + catch (Exception ex) + { + Console.Error.WriteLine($"Failed to cleanup tracee diagnostic ports: {ex}"); + } + } + + private static void UploadTraceFileFromHelix(string traceFilePath, string scenarioName) + { + var helixWorkItemDirectory = Environment.GetEnvironmentVariable("HELIX_WORKITEM_UPLOAD_ROOT"); + if (helixWorkItemDirectory != null && Directory.Exists(helixWorkItemDirectory)) + { + var destPath = Path.Combine(helixWorkItemDirectory, $"{scenarioName}.nettrace"); + Console.WriteLine($"Uploading trace file to Helix work item directory: {destPath}"); + File.Copy(traceFilePath, destPath, overwrite: true); + } + } } } \ No newline at end of file diff --git a/src/tests/tracing/userevents/common/userevents_common.csproj b/src/tests/tracing/userevents/common/userevents_common.csproj index 8bae27e3e7d1e2..dff80ae7a50008 100644 --- a/src/tests/tracing/userevents/common/userevents_common.csproj +++ b/src/tests/tracing/userevents/common/userevents_common.csproj @@ -13,16 +13,29 @@ - + <_DestDir>$(TargetDir) <_DestDir Condition="'$(_DestDir)' == ''">$(OutputPath) <_RecordTraceSource>$(NuGetPackageRoot)microsoft.onecollect.recordtrace/$(MicrosoftOneCollectRecordTraceVersion)/runtimes/linux-$(TargetArchitecture)/native/record-trace + <_RecordTraceRelative Condition="$(BuildProjectRelativeDir) != ''">$(BuildProjectRelativeDir)record-trace + <_RecordTraceRelative Condition="'$(_RecordTraceRelative)' == ''">$([System.IO.Path]::GetRelativePath('$(TestBinDir)', '$(_DestDir)record-trace')) + + + + + + From 79ab95079113e973a49f3660c095f6f2936f54ff Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Wed, 3 Dec 2025 04:51:00 +0000 Subject: [PATCH 04/10] [Test][UserEvents] Add ManagedEvent scenario --- .../userevents/managedevent/managedevent.cs | 76 +++++++++++++++++++ .../managedevent/managedevent.csproj | 19 +++++ .../managedevent/managedevent.script | 2 + 3 files changed, 97 insertions(+) create mode 100644 src/tests/tracing/userevents/managedevent/managedevent.cs create mode 100644 src/tests/tracing/userevents/managedevent/managedevent.csproj create mode 100644 src/tests/tracing/userevents/managedevent/managedevent.script diff --git a/src/tests/tracing/userevents/managedevent/managedevent.cs b/src/tests/tracing/userevents/managedevent/managedevent.cs new file mode 100644 index 00000000000000..2e5b09612cbb80 --- /dev/null +++ b/src/tests/tracing/userevents/managedevent/managedevent.cs @@ -0,0 +1,76 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics; +using System.Diagnostics.Tracing; +using System.Threading; +using Tracing.UserEvents.Tests.Common; +using Microsoft.Diagnostics.Tracing; + +namespace Tracing.UserEvents.Tests.ManagedEvent +{ + public class ManagedEvent + { + public static void ManagedEventTracee() + { + long startTimestamp = Stopwatch.GetTimestamp(); + long targetTicks = Stopwatch.Frequency; // 1s + + while (Stopwatch.GetTimestamp() - startTimestamp < targetTicks) + { + ManagedUserEventSource.Log.SampleEvent("SampleWork"); + Thread.Sleep(100); + } + } + + private static readonly Func s_traceValidator = source => + { + bool sampleEventFound = false; + + source.Dynamic.All += (TraceEvent e) => + { + if (!string.Equals(e.ProviderName, "ManagedUserEvent", StringComparison.OrdinalIgnoreCase)) + { + return; + } + + if (e.EventName is null) + { + return; + } + + sampleEventFound = true; + }; + + source.Process(); + + if (!sampleEventFound) + { + Console.Error.WriteLine("The trace did not contain the expected managed event."); + } + + return sampleEventFound; + }; + + public static int Main(string[] args) + { + if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) + { + ManagedEventTracee(); + return 0; + } + + return UserEventsTestRunner.Run("managedevent", typeof(ManagedEvent).Assembly.Location, s_traceValidator); + } + } + + [EventSource(Name = "ManagedUserEvent")] + internal sealed class ManagedUserEventSource : EventSource + { + public static readonly ManagedUserEventSource Log = new ManagedUserEventSource(); + + [Event(1)] + public void SampleEvent(string requestName) => WriteEvent(1, requestName); + } +} \ No newline at end of file diff --git a/src/tests/tracing/userevents/managedevent/managedevent.csproj b/src/tests/tracing/userevents/managedevent/managedevent.csproj new file mode 100644 index 00000000000000..d3ed72c432a53d --- /dev/null +++ b/src/tests/tracing/userevents/managedevent/managedevent.csproj @@ -0,0 +1,19 @@ + + + true + true + false + + + + + + + + + + Always + managedevent.script + + + diff --git a/src/tests/tracing/userevents/managedevent/managedevent.script b/src/tests/tracing/userevents/managedevent/managedevent.script new file mode 100644 index 00000000000000..5d2e512acf1733 --- /dev/null +++ b/src/tests/tracing/userevents/managedevent/managedevent.script @@ -0,0 +1,2 @@ +let manageduserevent_flags = new_dotnet_provider_flags(); +record_dotnet_provider("ManagedUserEvent", 0x0, 5, manageduserevent_flags); From 086eb16b751b38e85a1fb23caeecf59f77b3e015 Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Wed, 3 Dec 2025 04:51:17 +0000 Subject: [PATCH 05/10] [Test][UserEvents] Add Multithreaded scenario --- .../userevents/multithread/multithread.cs | 106 ++++++++++++++++++ .../userevents/multithread/multithread.csproj | 19 ++++ .../userevents/multithread/multithread.script | 2 + 3 files changed, 127 insertions(+) create mode 100644 src/tests/tracing/userevents/multithread/multithread.cs create mode 100644 src/tests/tracing/userevents/multithread/multithread.csproj create mode 100644 src/tests/tracing/userevents/multithread/multithread.script diff --git a/src/tests/tracing/userevents/multithread/multithread.cs b/src/tests/tracing/userevents/multithread/multithread.cs new file mode 100644 index 00000000000000..2b0920a9668671 --- /dev/null +++ b/src/tests/tracing/userevents/multithread/multithread.cs @@ -0,0 +1,106 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Diagnostics.Tracing; +using System.Threading; +using System.Threading.Tasks; +using Tracing.UserEvents.Tests.Common; +using Microsoft.Diagnostics.Tracing; + +namespace Tracing.UserEvents.Tests.MultiThread +{ + [EventSource(Name = "DemoMultiThread")] + public sealed class MultiThreadEventSource : EventSource + { + public static readonly MultiThreadEventSource Log = new MultiThreadEventSource(); + + private MultiThreadEventSource() {} + + [Event(1, Level = EventLevel.Informational)] + public void WorkerEvent(int workerId) + { + WriteEvent(1, workerId); + } + } + + public static class MultiThread + { + private const int WorkerCount = 4; + + public static void MultiThreadTracee() + { + Task[] tasks = new Task[WorkerCount]; + + for (int i = 0; i < WorkerCount; i++) + { + int workerId = i; + tasks[i] = Task.Run(() => + { + MultiThreadEventSource.Log.WorkerEvent(workerId); + }); + } + + Task.WaitAll(tasks); + } + + private static readonly Func s_traceValidator = source => + { + HashSet seenWorkers = new HashSet(); + + source.Dynamic.All += (TraceEvent e) => + { + if (!string.Equals(e.ProviderName, "DemoMultiThread", StringComparison.Ordinal)) + { + return; + } + + if (e.EventName is not "WorkerEvent") + { + return; + } + + int workerId = -1; + try + { + workerId = (int)(e.PayloadByName("workerId") ?? -1); + } + catch (Exception ex) + { + Console.Error.WriteLine($"Exception while reading workerId payload: {ex}"); + } + + if (workerId >= 0) + { + seenWorkers.Add(workerId); + } + }; + + source.Process(); + + for (int i = 0; i < WorkerCount; i++) + { + if (!seenWorkers.Contains(i)) + { + Console.Error.WriteLine($"Did not observe event for worker {i}."); + return false; + } + } + + return true; + }; + + public static int Main(string[] args) + { + if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) + { + MultiThreadTracee(); + return 0; + } + + return UserEventsTestRunner.Run("multithread", typeof(MultiThread).Assembly.Location, s_traceValidator); + } + } +} diff --git a/src/tests/tracing/userevents/multithread/multithread.csproj b/src/tests/tracing/userevents/multithread/multithread.csproj new file mode 100644 index 00000000000000..3fe2c9de43d545 --- /dev/null +++ b/src/tests/tracing/userevents/multithread/multithread.csproj @@ -0,0 +1,19 @@ + + + true + true + false + + + + + + + + + + Always + multithread.script + + + diff --git a/src/tests/tracing/userevents/multithread/multithread.script b/src/tests/tracing/userevents/multithread/multithread.script new file mode 100644 index 00000000000000..d874f623445c18 --- /dev/null +++ b/src/tests/tracing/userevents/multithread/multithread.script @@ -0,0 +1,2 @@ +let DemoMultiThread_flags = new_dotnet_provider_flags(); +record_dotnet_provider("DemoMultiThread", 0x0, 5, DemoMultiThread_flags); From 5b9f214f9f40d3951ddbdff85c65e1a2d875f524 Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Thu, 4 Dec 2025 01:37:54 +0000 Subject: [PATCH 06/10] Disable UserEvents tests for Mono --- src/tests/issues.targets | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/tests/issues.targets b/src/tests/issues.targets index 185634263fe8be..02d5b76e8ac6f4 100644 --- a/src/tests/issues.targets +++ b/src/tests/issues.targets @@ -1535,6 +1535,9 @@ Test issue. The test relies on overriding the process return code. + + Record-Trace's diagnostic port detection logic relies on memfd-based double mapping + From 4ee90c4a10024df07925b295caca314ae9cbf573 Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Thu, 4 Dec 2025 01:39:18 +0000 Subject: [PATCH 07/10] Reference glibc requirement issue --- src/tests/tracing/userevents/common/UserEventsRequirements.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/src/tests/tracing/userevents/common/UserEventsRequirements.cs b/src/tests/tracing/userevents/common/UserEventsRequirements.cs index 7f210f1e1d7e57..313cdd942b21b2 100644 --- a/src/tests/tracing/userevents/common/UserEventsRequirements.cs +++ b/src/tests/tracing/userevents/common/UserEventsRequirements.cs @@ -12,6 +12,7 @@ internal static class UserEventsRequirements private static readonly Version s_minKernelVersion = new(6, 4); private const string TracefsPath = "/sys/kernel/tracing"; private const string UserEventsDataPath = "/sys/kernel/tracing/user_events_data"; + // https://github.com/microsoft/one-collect/issues/225 private static readonly Version s_minGlibcVersion = new(2, 35); internal static bool IsSupported() From 50efb18c1a291c5f8e9d632f115175de8e7ac7c7 Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Thu, 4 Dec 2025 02:02:22 +0000 Subject: [PATCH 08/10] [Test][UserEvents] Add ActivityIDs scenario --- .../tracing/userevents/activity/activity.cs | 186 ++++++++++++++++++ .../userevents/activity/activity.csproj | 19 ++ .../userevents/activity/activity.script | 5 + 3 files changed, 210 insertions(+) create mode 100644 src/tests/tracing/userevents/activity/activity.cs create mode 100644 src/tests/tracing/userevents/activity/activity.csproj create mode 100644 src/tests/tracing/userevents/activity/activity.script diff --git a/src/tests/tracing/userevents/activity/activity.cs b/src/tests/tracing/userevents/activity/activity.cs new file mode 100644 index 00000000000000..773a97816f2113 --- /dev/null +++ b/src/tests/tracing/userevents/activity/activity.cs @@ -0,0 +1,186 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics.Tracing; +using System.Threading; +using System.Threading.Tasks; +using Tracing.UserEvents.Tests.Common; +using Microsoft.Diagnostics.Tracing; + +namespace Tracing.UserEvents.Tests.Activity +{ + public static class Activity + { + public static void ActivityTracee() + { + // Allow some time for tracepoints be enabled before emitting events + Thread.Sleep(150); + ActivityTraceeAsync().GetAwaiter().GetResult(); + } + + private static async Task ActivityTraceeAsync() + { + Task requestA = ProcessRequest("RequestA"); + Task requestB = ProcessRequest("RequestB"); + + await Task.WhenAll(requestA, requestB); + } + + private static async Task ProcessRequest(string requestName) + { + ActivityEventSource.Log.WorkStart(requestName); + + Task query1 = Query("Query1 for " + requestName); + Task query2 = Query("Query2 for " + requestName); + + await Task.WhenAll(query1, query2); + + ActivityEventSource.Log.WorkStop(); + } + + private static async Task Query(string query) + { + ActivityEventSource.Log.QueryStart(query); + await Task.Delay(50); + ActivityEventSource.Log.DebugMessage("processing " + query); + await Task.Delay(50); + ActivityEventSource.Log.QueryStop(); + } + + private static readonly Func s_traceValidator = source => + { + Guid firstWorkActivityId = Guid.Empty; + Guid secondWorkActivityId = Guid.Empty; + + Guid firstWorkQuery1ActivityId = Guid.Empty; + Guid firstWorkQuery2ActivityId = Guid.Empty; + Guid secondWorkQuery1ActivityId = Guid.Empty; + Guid secondWorkQuery2ActivityId = Guid.Empty; + + Guid firstWorkQuery1RelatedActivityId = Guid.Empty; + Guid firstWorkQuery2RelatedActivityId = Guid.Empty; + Guid secondWorkQuery1RelatedActivityId = Guid.Empty; + Guid secondWorkQuery2RelatedActivityId = Guid.Empty; + + source.Dynamic.All += e => + { + if (!string.Equals(e.ProviderName, "DemoActivityIDs", StringComparison.Ordinal)) + { + return; + } + + if (e.EventName is null) + { + return; + } + + if (e.EventName.Equals("Work/Start", StringComparison.OrdinalIgnoreCase)) + { + string requestName = e.PayloadByName("requestName") as string ?? string.Empty; + + if (string.Equals(requestName, "RequestA", StringComparison.Ordinal)) + { + firstWorkActivityId = e.ActivityID; + } + else if (string.Equals(requestName, "RequestB", StringComparison.Ordinal)) + { + secondWorkActivityId = e.ActivityID; + } + } + else if (e.EventName.Equals("Query/Start", StringComparison.OrdinalIgnoreCase)) + { + string queryText = e.PayloadByName("query") as string ?? string.Empty; + + if (string.Equals(queryText, "Query1 for RequestA", StringComparison.Ordinal)) + { + firstWorkQuery1ActivityId = e.ActivityID; + firstWorkQuery1RelatedActivityId = e.RelatedActivityID; + } + else if (string.Equals(queryText, "Query2 for RequestA", StringComparison.Ordinal)) + { + firstWorkQuery2ActivityId = e.ActivityID; + firstWorkQuery2RelatedActivityId = e.RelatedActivityID; + } + else if (string.Equals(queryText, "Query1 for RequestB", StringComparison.Ordinal)) + { + secondWorkQuery1ActivityId = e.ActivityID; + secondWorkQuery1RelatedActivityId = e.RelatedActivityID; + } + else if (string.Equals(queryText, "Query2 for RequestB", StringComparison.Ordinal)) + { + secondWorkQuery2ActivityId = e.ActivityID; + secondWorkQuery2RelatedActivityId = e.RelatedActivityID; + } + } + }; + + source.Process(); + + if (firstWorkActivityId == Guid.Empty || secondWorkActivityId == Guid.Empty) + { + Console.Error.WriteLine("The trace did not contain two WorkStart events with ActivityIds for RequestA and RequestB."); + return false; + } + + if (firstWorkQuery1ActivityId == Guid.Empty || firstWorkQuery2ActivityId == Guid.Empty || + secondWorkQuery1ActivityId == Guid.Empty || secondWorkQuery2ActivityId == Guid.Empty) + { + Console.Error.WriteLine("The trace did not contain all expected QueryStart events with ActivityIds for both requests."); + return false; + } + + if (firstWorkQuery1RelatedActivityId == Guid.Empty || firstWorkQuery2RelatedActivityId == Guid.Empty || + secondWorkQuery1RelatedActivityId == Guid.Empty || secondWorkQuery2RelatedActivityId == Guid.Empty) + { + Console.Error.WriteLine("The trace did not contain RelatedActivityIds on all QueryStart events."); + return false; + } + + if (firstWorkQuery1RelatedActivityId != firstWorkActivityId || + firstWorkQuery2RelatedActivityId != firstWorkActivityId || + secondWorkQuery1RelatedActivityId != secondWorkActivityId || + secondWorkQuery2RelatedActivityId != secondWorkActivityId) + { + Console.Error.WriteLine("QueryStart RelatedActivityIds did not match their corresponding WorkStart ActivityIds."); + return false; + } + + return true; + }; + + public static int Main(string[] args) + { + if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) + { + ActivityTracee(); + return 0; + } + + return UserEventsTestRunner.Run("activity", typeof(Activity).Assembly.Location, s_traceValidator, 10000); + } + } + + [EventSource(Name = "DemoActivityIDs")] + internal sealed class ActivityEventSource : EventSource + { + public static readonly ActivityEventSource Log = new ActivityEventSource(); + + private ActivityEventSource() {} + + [Event(1)] + public void WorkStart(string requestName) => WriteEvent(1, requestName); + + [Event(2)] + public void WorkStop() => WriteEvent(2); + + [Event(3)] + public void DebugMessage(string message) => WriteEvent(3, message); + + [Event(4)] + public void QueryStart(string query) => WriteEvent(4, query); + + [Event(5)] + public void QueryStop() => WriteEvent(5); + } +} diff --git a/src/tests/tracing/userevents/activity/activity.csproj b/src/tests/tracing/userevents/activity/activity.csproj new file mode 100644 index 00000000000000..1b701787d37286 --- /dev/null +++ b/src/tests/tracing/userevents/activity/activity.csproj @@ -0,0 +1,19 @@ + + + true + true + false + + + + + + + + + + Always + activity.script + + + diff --git a/src/tests/tracing/userevents/activity/activity.script b/src/tests/tracing/userevents/activity/activity.script new file mode 100644 index 00000000000000..f0303375493623 --- /dev/null +++ b/src/tests/tracing/userevents/activity/activity.script @@ -0,0 +1,5 @@ +let DemoActivityIds_flags = new_dotnet_provider_flags(); +record_dotnet_provider("DemoActivityIDs", 0x0, 5, DemoActivityIds_flags); + +let System_Threading_Tasks_TplEventSource_flags = new_dotnet_provider_flags(); +record_dotnet_provider("System.Threading.Tasks.TplEventSource", 0x80, 5, System_Threading_Tasks_TplEventSource_flags); \ No newline at end of file From 9141e048cc0ddd67755a491ef5e065b429bf620d Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Thu, 4 Dec 2025 02:49:20 +0000 Subject: [PATCH 09/10] [Test][UserEvents] Add CustomMetadata scenario --- .../custommetadata/custommetadata.cs | 96 +++++++++++++++++++ .../custommetadata/custommetadata.csproj | 19 ++++ .../custommetadata/custommetadata.script | 2 + 3 files changed, 117 insertions(+) create mode 100644 src/tests/tracing/userevents/custommetadata/custommetadata.cs create mode 100644 src/tests/tracing/userevents/custommetadata/custommetadata.csproj create mode 100644 src/tests/tracing/userevents/custommetadata/custommetadata.script diff --git a/src/tests/tracing/userevents/custommetadata/custommetadata.cs b/src/tests/tracing/userevents/custommetadata/custommetadata.cs new file mode 100644 index 00000000000000..da9a01386d22f0 --- /dev/null +++ b/src/tests/tracing/userevents/custommetadata/custommetadata.cs @@ -0,0 +1,96 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics; +using System.Diagnostics.Tracing; +using System.Threading; +using Tracing.UserEvents.Tests.Common; +using Microsoft.Diagnostics.Tracing; + +namespace Tracing.UserEvents.Tests.CustomMetadata +{ + public static class CustomMetadata + { + public static void CustomMetadataTracee() + { + // Allow some time for tracepoints be enabled before emitting events + Thread.Sleep(150); + CustomMetadataEventSource.Log.WorkItem(1, "Item1"); + } + + private static readonly Func s_traceValidator = source => + { + bool anyMatching = false; + + source.Dynamic.All += (TraceEvent e) => + { + if (!string.Equals(e.ProviderName, "DemoCustomMetadata", StringComparison.Ordinal)) + { + return; + } + + if (!string.Equals(e.EventName, "WorkItem", StringComparison.Ordinal)) + { + return; + } + + try + { + object? idObj = e.PayloadByName("id"); + object? nameObj = e.PayloadByName("name"); + int id = idObj is null ? -1 : Convert.ToInt32(idObj); + string? name = nameObj as string; + + if (id != 1 || !string.Equals(name, "Item1", StringComparison.Ordinal)) + { + Console.Error.WriteLine($"Unexpected payload values: id={id}, name={name}"); + } + else + { + anyMatching = true; + Console.WriteLine($"CustomMetadata event: Id={id}, Name={name}"); + } + } + catch (Exception ex) + { + Console.Error.WriteLine($"Exception while reading CustomMetadata payload: {ex}"); + } + }; + + source.Process(); + + if (!anyMatching) + { + Console.Error.WriteLine("The trace did not contain the expected CustomMetadata event."); + } + + return anyMatching; + }; + + public static int Main(string[] args) + { + if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) + { + CustomMetadataTracee(); + return 0; + } + + return UserEventsTestRunner.Run("custommetadata", typeof(CustomMetadata).Assembly.Location, s_traceValidator, 20000); + } + } + + [EventSource(Name = "DemoCustomMetadata")] + public sealed class CustomMetadataEventSource : EventSource + { + public static readonly CustomMetadataEventSource Log = new CustomMetadataEventSource(); + + private CustomMetadataEventSource() : base(EventSourceSettings.EtwSelfDescribingEventFormat) {} + + [Event(1, Level = EventLevel.Informational)] + public void WorkItem(int id, string name) + { + WriteEvent(1, id, name); + } + } +} diff --git a/src/tests/tracing/userevents/custommetadata/custommetadata.csproj b/src/tests/tracing/userevents/custommetadata/custommetadata.csproj new file mode 100644 index 00000000000000..2e5c43fafccd4e --- /dev/null +++ b/src/tests/tracing/userevents/custommetadata/custommetadata.csproj @@ -0,0 +1,19 @@ + + + true + true + false + + + + + + + + + + Always + custommetadata.script + + + diff --git a/src/tests/tracing/userevents/custommetadata/custommetadata.script b/src/tests/tracing/userevents/custommetadata/custommetadata.script new file mode 100644 index 00000000000000..e0d6fe0b50830d --- /dev/null +++ b/src/tests/tracing/userevents/custommetadata/custommetadata.script @@ -0,0 +1,2 @@ +let DemoCustomMetadata_flags = new_dotnet_provider_flags(); +record_dotnet_provider("DemoCustomMetadata", 0x0, 5, DemoCustomMetadata_flags); From 9236c5a7247e2bbe72ff9b8a68975568c87c1e7d Mon Sep 17 00:00:00 2001 From: mdh1418 Date: Wed, 10 Dec 2025 01:56:45 +0000 Subject: [PATCH 10/10] Address feedback --- .../tracing/userevents/activity/activity.cs | 16 ++- src/tests/tracing/userevents/basic/basic.cs | 13 ++- .../userevents/common/UserEventsTestRunner.cs | 100 ++++++++++++++---- .../custommetadata/custommetadata.cs | 16 ++- .../userevents/managedevent/managedevent.cs | 13 ++- .../userevents/multithread/multithread.cs | 13 ++- 6 files changed, 112 insertions(+), 59 deletions(-) diff --git a/src/tests/tracing/userevents/activity/activity.cs b/src/tests/tracing/userevents/activity/activity.cs index 773a97816f2113..3e711af20a9ad9 100644 --- a/src/tests/tracing/userevents/activity/activity.cs +++ b/src/tests/tracing/userevents/activity/activity.cs @@ -3,7 +3,6 @@ using System; using System.Diagnostics.Tracing; -using System.Threading; using System.Threading.Tasks; using Tracing.UserEvents.Tests.Common; using Microsoft.Diagnostics.Tracing; @@ -14,8 +13,6 @@ public static class Activity { public static void ActivityTracee() { - // Allow some time for tracepoints be enabled before emitting events - Thread.Sleep(150); ActivityTraceeAsync().GetAwaiter().GetResult(); } @@ -151,13 +148,12 @@ private static async Task Query(string query) public static int Main(string[] args) { - if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) - { - ActivityTracee(); - return 0; - } - - return UserEventsTestRunner.Run("activity", typeof(Activity).Assembly.Location, s_traceValidator, 10000); + return UserEventsTestRunner.Run( + args, + "activity", + typeof(Activity).Assembly.Location, + ActivityTracee, + s_traceValidator); } } diff --git a/src/tests/tracing/userevents/basic/basic.cs b/src/tests/tracing/userevents/basic/basic.cs index b53774c0dde677..180a59f6e7ab20 100644 --- a/src/tests/tracing/userevents/basic/basic.cs +++ b/src/tests/tracing/userevents/basic/basic.cs @@ -52,13 +52,12 @@ public static void BasicTracee() public static int Main(string[] args) { - if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) - { - BasicTracee(); - return 0; - } - - return UserEventsTestRunner.Run("basic", typeof(Basic).Assembly.Location, s_traceValidator); + return UserEventsTestRunner.Run( + args, + "basic", + typeof(Basic).Assembly.Location, + BasicTracee, + s_traceValidator); } } } diff --git a/src/tests/tracing/userevents/common/UserEventsTestRunner.cs b/src/tests/tracing/userevents/common/UserEventsTestRunner.cs index 0c8b6f9897d3e8..567aec069a4802 100644 --- a/src/tests/tracing/userevents/common/UserEventsTestRunner.cs +++ b/src/tests/tracing/userevents/common/UserEventsTestRunner.cs @@ -2,9 +2,13 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; +using System.Collections.Generic; using System.Diagnostics; using System.IO; +using System.Linq; using System.Runtime.InteropServices; +using System.Text.RegularExpressions; +using System.Threading; using Microsoft.Diagnostics.Tracing; namespace Tracing.UserEvents.Tests.Common @@ -14,16 +18,46 @@ public class UserEventsTestRunner private const int SIGINT = 2; private const int DefaultTraceeExitTimeoutMs = 5000; private const int DefaultRecordTraceExitTimeoutMs = 20000; + private const int DefaultTraceeDelayToSetupTracepointsMs = 200; [DllImport("libc", EntryPoint = "kill", SetLastError = true)] private static extern int Kill(int pid, int sig); public static int Run( + string[] args, string scenarioName, string traceeAssemblyPath, + Action traceeAction, Func traceValidator, int traceeExitTimeout = DefaultTraceeExitTimeoutMs, - int recordTraceExitTimeout = DefaultRecordTraceExitTimeoutMs) + int recordTraceExitTimeout = DefaultRecordTraceExitTimeoutMs, + int traceeDelayToSetupTracepoints = DefaultTraceeDelayToSetupTracepointsMs) + { + if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) + { + if (traceeDelayToSetupTracepoints > 0) + { + Thread.Sleep(traceeDelayToSetupTracepoints); + } + + traceeAction(); + return 0; + } + + return RunOrchestrator( + scenarioName, + traceeAssemblyPath, + traceValidator, + traceeExitTimeout, + recordTraceExitTimeout); + } + + private static int RunOrchestrator( + string scenarioName, + string traceeAssemblyPath, + Func traceValidator, + int traceeExitTimeout, + int recordTraceExitTimeout) { string userEventsScenarioDir = Path.GetDirectoryName(traceeAssemblyPath); string recordTracePath = ResolveRecordTracePath(userEventsScenarioDir); @@ -88,9 +122,15 @@ public static int Run( traceeStartInfo.RedirectStandardError = true; // record-trace currently only searches /tmp/ for diagnostic ports https://github.com/microsoft/one-collect/issues/183 - string diagnosticPortDir = "/tmp/"; + string diagnosticPortDir = "/tmp"; traceeStartInfo.Environment["TMPDIR"] = diagnosticPortDir; + // TMPDIR is configured on Helix, but the diagnostic port is created outside of Helix's default temp datadisk path. + // The diagnostic port should be automatically cleaned up when the tracee shuts down, but zombie sockets can be left + // behind after catastrophic exits. Clean them before launching the tracee to avoid deleting sockets from a reused PID. + // When https://github.com/microsoft/one-collect/issues/183 is fixed, this and the above TMPDIR should be removed. + EnsureCleanDiagnosticPorts(diagnosticPortDir); + Console.WriteLine($"Starting tracee process: {traceeStartInfo.FileName} {traceeStartInfo.Arguments}"); using Process traceeProcess = Process.Start(traceeStartInfo); int traceePid = traceeProcess.Id; @@ -120,12 +160,6 @@ public static int Run( } traceeProcess.WaitForExit(); // flush async output - // TMPDIR is configured on Helix, but the diagnostic port was created outside of helix's default temp datadisk path. - // The diagnostic port should be automatically cleaned up when the tracee shutsdown, but just in case of an - // abrupt exit, ensure cleanup to avoid leaving artifacts on helix machines. - // When https://github.com/microsoft/one-collect/issues/183 is fixed, this and the above TMPDIR should be removed. - CleanupTraceeDiagnosticPorts(diagnosticPortDir, traceePid); - if (!recordTraceProcess.HasExited) { // Until record-trace supports duration, the only way to stop it is to send SIGINT (ctrl+c) @@ -172,20 +206,50 @@ private static string ResolveRecordTracePath(string userEventsScenarioDir) return recordTracePath; } - private static void CleanupTraceeDiagnosticPorts(string diagnosticPortDir, int traceePid) + // Similar to IpcTraceTest.EnsureCleanEnvironment, but scoped to the provided diagnosticPortDir. + // Check for zombie diagnostic IPC sockets left behind by previous runs and remove them. + // If multiple sockets exist for a running PID, delete all but the newest. + private static void EnsureCleanDiagnosticPorts(string diagnosticPortDir) { - try + if (!Directory.Exists(diagnosticPortDir)) { - string[] udsFiles = Directory.GetFiles(diagnosticPortDir, $"dotnet-diagnostic-{traceePid}-*-socket"); - foreach (string udsFile in udsFiles) - { - Console.WriteLine($"Deleting tracee diagnostic port UDS file: {udsFile}"); - File.Delete(udsFile); - } + return; } - catch (Exception ex) + + Func<(IEnumerable>, List)> getPidsAndSockets = () => { - Console.Error.WriteLine($"Failed to cleanup tracee diagnostic ports: {ex}"); + IEnumerable> currentIpcs = Directory.GetFiles(diagnosticPortDir, "dotnet-diagnostic*") + .Select(filename => new { pid = int.Parse(Regex.Match(filename, @"dotnet-diagnostic-(?\d+)").Groups["pid"].Value), fileInfo = new FileInfo(filename) }) + .GroupBy(fileInfos => fileInfos.pid, fileInfos => fileInfos.fileInfo); + List currentPids = System.Diagnostics.Process.GetProcesses().Select(pid => pid.Id).ToList(); + return (currentIpcs, currentPids); + }; + + var (currentIpcs, currentPids) = getPidsAndSockets(); + + foreach (var ipc in currentIpcs) + { + if (!currentPids.Contains(ipc.Key)) + { + foreach (FileInfo fi in ipc) + { + Console.WriteLine($"Deleting zombie diagnostic port: {fi.FullName}"); + fi.Delete(); + } + } + else + { + if (ipc.Count() > 1) + { + // delete zombied pipes except newest which is owned + var duplicates = ipc.OrderBy(fileInfo => fileInfo.CreationTime.Ticks).SkipLast(1); + foreach (FileInfo fi in duplicates) + { + Console.WriteLine($"Deleting duplicate diagnostic port: {fi.FullName}"); + fi.Delete(); + } + } + } } } diff --git a/src/tests/tracing/userevents/custommetadata/custommetadata.cs b/src/tests/tracing/userevents/custommetadata/custommetadata.cs index da9a01386d22f0..50fdc3d242d48a 100644 --- a/src/tests/tracing/userevents/custommetadata/custommetadata.cs +++ b/src/tests/tracing/userevents/custommetadata/custommetadata.cs @@ -4,7 +4,6 @@ using System; using System.Diagnostics; using System.Diagnostics.Tracing; -using System.Threading; using Tracing.UserEvents.Tests.Common; using Microsoft.Diagnostics.Tracing; @@ -14,8 +13,6 @@ public static class CustomMetadata { public static void CustomMetadataTracee() { - // Allow some time for tracepoints be enabled before emitting events - Thread.Sleep(150); CustomMetadataEventSource.Log.WorkItem(1, "Item1"); } @@ -70,13 +67,12 @@ public static void CustomMetadataTracee() public static int Main(string[] args) { - if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) - { - CustomMetadataTracee(); - return 0; - } - - return UserEventsTestRunner.Run("custommetadata", typeof(CustomMetadata).Assembly.Location, s_traceValidator, 20000); + return UserEventsTestRunner.Run( + args, + "custommetadata", + typeof(CustomMetadata).Assembly.Location, + CustomMetadataTracee, + s_traceValidator); } } diff --git a/src/tests/tracing/userevents/managedevent/managedevent.cs b/src/tests/tracing/userevents/managedevent/managedevent.cs index 2e5b09612cbb80..798a86a723d2dd 100644 --- a/src/tests/tracing/userevents/managedevent/managedevent.cs +++ b/src/tests/tracing/userevents/managedevent/managedevent.cs @@ -55,13 +55,12 @@ public static void ManagedEventTracee() public static int Main(string[] args) { - if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) - { - ManagedEventTracee(); - return 0; - } - - return UserEventsTestRunner.Run("managedevent", typeof(ManagedEvent).Assembly.Location, s_traceValidator); + return UserEventsTestRunner.Run( + args, + "managedevent", + typeof(ManagedEvent).Assembly.Location, + ManagedEventTracee, + s_traceValidator); } } diff --git a/src/tests/tracing/userevents/multithread/multithread.cs b/src/tests/tracing/userevents/multithread/multithread.cs index 2b0920a9668671..eb7230f6922f76 100644 --- a/src/tests/tracing/userevents/multithread/multithread.cs +++ b/src/tests/tracing/userevents/multithread/multithread.cs @@ -94,13 +94,12 @@ public static void MultiThreadTracee() public static int Main(string[] args) { - if (args.Length > 0 && args[0].Equals("tracee", StringComparison.OrdinalIgnoreCase)) - { - MultiThreadTracee(); - return 0; - } - - return UserEventsTestRunner.Run("multithread", typeof(MultiThread).Assembly.Location, s_traceValidator); + return UserEventsTestRunner.Run( + args, + "multithread", + typeof(MultiThread).Assembly.Location, + MultiThreadTracee, + s_traceValidator); } } }