diff --git a/Directory.Packages.props b/Directory.Packages.props index f46c178e87..8b7ac3dde9 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -24,7 +24,8 @@ - + + diff --git a/eng/SourceBuildPrebuiltBaseline.xml b/eng/SourceBuildPrebuiltBaseline.xml index 9fec0c6db3..050118984a 100644 --- a/eng/SourceBuildPrebuiltBaseline.xml +++ b/eng/SourceBuildPrebuiltBaseline.xml @@ -7,4 +7,7 @@ build because it will be retrieved from the N-1 artifacts. --> - + + + + \ No newline at end of file diff --git a/src/System.CommandLine.Tests/ObservabilityTests.cs b/src/System.CommandLine.Tests/ObservabilityTests.cs new file mode 100644 index 0000000000..bf7a612920 --- /dev/null +++ b/src/System.CommandLine.Tests/ObservabilityTests.cs @@ -0,0 +1,131 @@ +using System.CommandLine.Parsing; +using FluentAssertions; +using System.Linq; +using Xunit; +using System.Diagnostics; +using System.Collections.Generic; +using System.Threading.Tasks; +using Xunit.Abstractions; + +namespace System.CommandLine.Tests +{ + public class ObservabilityTests + { + private readonly ITestOutputHelper log; + + public ObservabilityTests(ITestOutputHelper output) + { + log = output; + } + + [Fact] + public void It_creates_activity_spans_for_parsing() + { + var (listener, activities) = SetupListener(); + + var command = new Command("the-command") + { + new Option("--option") + }; + + var args = new[] { "--option", "the-argument" }; + + var result = command.Parse(args); + listener.Dispose(); + activities + .Should() + .ContainSingle( + a => a.OperationName == "System.CommandLine.Parse" + && a.Status == ActivityStatusCode.Ok + && a.Tags.Any(t => t.Key == "command" && t.Value == "the-command")); + } + + [Fact] + public void It_creates_activity_spans_for_parsing_errors() + { + var (listener, activities) = SetupListener(); + + var command = new Command("the-command") + { + new Option("--option") + }; + + var args = new[] { "--opt", "the-argument" }; + var result = command.Parse(args); + listener.Dispose(); + activities + .Should() + .ContainSingle( + a => a.OperationName == "System.CommandLine.Parse" + && a.Status == ActivityStatusCode.Error + && a.Tags.Any(t => t.Key == "command" && t.Value == "the-command") + && a.Baggage.Any(t => t.Key == "errors")); + } + + [Fact] + public async Task It_creates_activity_spans_for_invocations() + { + var (listener, activities) = SetupListener(); + + var command = new Command("the-command"); + command.SetAction(async (pr, ctok) => await Task.FromResult(0)); + + var result = await command.Parse(Array.Empty()).InvokeAsync(); + listener.Dispose(); + + activities + .Should() + .ContainSingle( + a => a.OperationName == "System.CommandLine.Invoke" + && a.DisplayName == "the-command" + && a.Status == ActivityStatusCode.Ok + && a.Tags.Any(t => t.Key == "command" && t.Value == "the-command") + && a.Tags.Any(t => t.Key == "invoke.type" && t.Value == "async") + && a.TagObjects.Any(t => t.Key == "exitcode" && (int)t.Value == 0)); + } + + [Fact] + public async Task It_creates_activity_spans_for_invocation_errors() + { + var (listener, activities) = SetupListener(); + + var command = new Command("the-command"); +#pragma warning disable CS1998 // Async method lacks 'await' operators and will run synchronously + command.SetAction(async (pr, ctok) => + { + throw new Exception("Something went wrong"); + }); +#pragma warning restore CS1998 // Async method lacks 'await' operators and will run synchronously + + var result = await command.Parse(Array.Empty()).InvokeAsync(); + listener.Dispose(); + + foreach (var x in activities) + { + log.WriteLine($"{x.DisplayName}({x.OperationName})/{x.Status}({x.Duration}) - {x.TagObjects} - {string.Join(",", x.Events.Select((k) => $"{k.Name},{k.Tags}"))}"); + } + + activities + .Should() + .ContainSingle( + a => a.OperationName == "System.CommandLine.Invoke" + && a.DisplayName == "the-command" + && a.Status == ActivityStatusCode.Error + && a.Tags.Any(t => t.Key == "command" && t.Value == "the-command") + && a.Tags.Any(t => t.Key == "invoke.type" && t.Value == "async") + && a.TagObjects.Any(t => t.Key == "exitcode" && (int)t.Value == 1) + && a.Events.Any(t => t.Name == "exception")); + } + + private static (ActivityListener, List) SetupListener() + { + List activities = new(); + var listener = new ActivityListener(); + listener.ShouldListenTo = s => true; + listener.Sample = (ref ActivityCreationOptions options) => ActivitySamplingResult.AllData; + listener.ActivityStopped = a => activities.Add(a); + ActivitySource.AddActivityListener(listener); + return new(listener, activities); + } + } +} diff --git a/src/System.CommandLine/Activities.cs b/src/System.CommandLine/Activities.cs new file mode 100644 index 0000000000..f022e4b925 --- /dev/null +++ b/src/System.CommandLine/Activities.cs @@ -0,0 +1,46 @@ +using System.Diagnostics; + +namespace System.CommandLine; + +internal static class DiagnosticsStrings +{ + internal const string LibraryNamespace = "System.CommandLine"; + internal const string ParseMethod = LibraryNamespace + ".Parse"; + internal const string InvokeMethod = LibraryNamespace + ".Invoke"; + internal const string InvokeType = "invoke.type"; + internal const string Async = "async"; + internal const string Sync = "sync"; + internal const string ExitCode = "exitcode"; + internal const string Exception = "exception"; + internal const string Errors = "errors"; + internal const string Command = "command"; +} + +internal static class Activities +{ + internal static readonly ActivitySource ActivitySource = new ActivitySource(DiagnosticsStrings.LibraryNamespace); +} + +internal static class ActivityExtensions +{ + + /// + /// Walks up the command tree to get the build the command name by prepending the parent command names to the 'leaf' command name. + /// + /// + /// The full command name, like 'dotnet package add'. + internal static string FullCommandName(this Parsing.CommandResult commandResult) + { + var command = commandResult.Command; + var path = command.Name; + + while (commandResult.Parent is Parsing.CommandResult parent) + { + command = parent.Command; + path = $"{command.Name} {path}"; + commandResult = parent; + } + + return path; + } +} \ No newline at end of file diff --git a/src/System.CommandLine/Invocation/InvocationPipeline.cs b/src/System.CommandLine/Invocation/InvocationPipeline.cs index 3cbca453ea..790b6d530d 100644 --- a/src/System.CommandLine/Invocation/InvocationPipeline.cs +++ b/src/System.CommandLine/Invocation/InvocationPipeline.cs @@ -1,6 +1,7 @@ // Copyright (c) .NET Foundation and contributors. All rights reserved. // Licensed under the MIT license. See LICENSE file in the project root for full license information. +using System.Runtime.CompilerServices; using System.Threading; using System.Threading.Tasks; @@ -10,8 +11,17 @@ internal static class InvocationPipeline { internal static async Task InvokeAsync(ParseResult parseResult, CancellationToken cancellationToken) { + using var invokeActivity = Activities.ActivitySource.StartActivity(DiagnosticsStrings.InvokeMethod); + if (invokeActivity is not null) + { + invokeActivity.DisplayName = parseResult.CommandResult.FullCommandName(); + invokeActivity.AddTag(DiagnosticsStrings.Command, parseResult.CommandResult.Command.Name); + invokeActivity.AddTag(DiagnosticsStrings.InvokeType, DiagnosticsStrings.Async); + } + if (parseResult.Action is null) { + invokeActivity?.SetStatus(Diagnostics.ActivityStatusCode.Error); return ReturnCodeForMissingAction(parseResult); } @@ -41,7 +51,9 @@ internal static async Task InvokeAsync(ParseResult parseResult, Cancellatio switch (parseResult.Action) { case SynchronousCommandLineAction syncAction: - return syncAction.Invoke(parseResult); + var syncResult = syncAction.Invoke(parseResult); + invokeActivity?.SetExitCode(syncResult); + return syncResult; case AsynchronousCommandLineAction asyncAction: var startedInvocation = asyncAction.InvokeAsync(parseResult, cts.Token); @@ -52,7 +64,9 @@ internal static async Task InvokeAsync(ParseResult parseResult, Cancellatio if (terminationHandler is null) { - return await startedInvocation; + var asyncResult = await startedInvocation; + invokeActivity?.SetExitCode(asyncResult); + return asyncResult; } else { @@ -60,15 +74,20 @@ internal static async Task InvokeAsync(ParseResult parseResult, Cancellatio // In such cases, when CancelOnProcessTermination is configured and user presses Ctrl+C, // ProcessTerminationCompletionSource completes first, with the result equal to native exit code for given signal. Task firstCompletedTask = await Task.WhenAny(startedInvocation, terminationHandler.ProcessTerminationCompletionSource.Task); - return await firstCompletedTask; // return the result or propagate the exception + var asyncResult = await firstCompletedTask; // return the result or propagate the exception + invokeActivity?.SetExitCode(asyncResult); + return asyncResult; } default: - throw new ArgumentOutOfRangeException(nameof(parseResult.Action)); + var error = new ArgumentOutOfRangeException(nameof(parseResult.Action)); + invokeActivity?.Error(error); + throw error; } } catch (Exception ex) when (parseResult.Configuration.EnableDefaultExceptionHandler) { + invokeActivity?.Error(ex); return DefaultExceptionHandler(ex, parseResult.Configuration); } finally @@ -79,9 +98,18 @@ internal static async Task InvokeAsync(ParseResult parseResult, Cancellatio internal static int Invoke(ParseResult parseResult) { + using var invokeActivity = Activities.ActivitySource.StartActivity(DiagnosticsStrings.InvokeMethod); + if (invokeActivity is not null) + { + invokeActivity.DisplayName = parseResult.CommandResult.FullCommandName(); + invokeActivity.AddTag(DiagnosticsStrings.Command, parseResult.CommandResult.Command.Name); + invokeActivity.AddTag(DiagnosticsStrings.InvokeType, DiagnosticsStrings.Sync); + } + switch (parseResult.Action) { case null: + invokeActivity?.Error(); return ReturnCodeForMissingAction(parseResult); case SynchronousCommandLineAction syncAction: @@ -112,15 +140,20 @@ internal static int Invoke(ParseResult parseResult) } } - return syncAction.Invoke(parseResult); + var result = syncAction.Invoke(parseResult); + invokeActivity?.SetExitCode(result); + return result; } catch (Exception ex) when (parseResult.Configuration.EnableDefaultExceptionHandler) { + invokeActivity?.Error(ex); return DefaultExceptionHandler(ex, parseResult.Configuration); } default: - throw new InvalidOperationException($"{nameof(AsynchronousCommandLineAction)} called within non-async invocation."); + var error = new InvalidOperationException($"{nameof(AsynchronousCommandLineAction)} called within non-async invocation."); + invokeActivity?.Error(error); + throw error; } } @@ -150,5 +183,43 @@ private static int ReturnCodeForMissingAction(ParseResult parseResult) return 0; } } + + private static void Succeed(this Diagnostics.Activity activity) + { + activity.SetStatus(Diagnostics.ActivityStatusCode.Ok); + activity.AddTag(DiagnosticsStrings.ExitCode, 0); + } + private static void Error(this Diagnostics.Activity activity, int statusCode) + { + activity.SetStatus(Diagnostics.ActivityStatusCode.Error); + activity.AddTag(DiagnosticsStrings.ExitCode, statusCode); + } + + private static void Error(this Diagnostics.Activity activity, Exception? exception = null) + { + activity.SetStatus(Diagnostics.ActivityStatusCode.Error); + activity.AddTag(DiagnosticsStrings.ExitCode, 1); + if (exception is not null) + { + var tagCollection = new Diagnostics.ActivityTagsCollection + { + { DiagnosticsStrings.Exception, exception.ToString() } + }; + var evt = new Diagnostics.ActivityEvent(DiagnosticsStrings.Exception, tags: tagCollection); + activity.AddEvent(evt); + } + } + + private static void SetExitCode(this Diagnostics.Activity activity, int exitCode) + { + if (exitCode == 0) + { + activity.Succeed(); + } + else + { + activity.Error(exitCode); + } + } } } diff --git a/src/System.CommandLine/ParseResult.cs b/src/System.CommandLine/ParseResult.cs index 92b209f93a..6e0eb88c71 100644 --- a/src/System.CommandLine/ParseResult.cs +++ b/src/System.CommandLine/ParseResult.cs @@ -236,6 +236,7 @@ public Task InvokeAsync(CancellationToken cancellationToken = default) /// A value that can be used as a process exit code. public int Invoke() { + var useAsync = false; if (Action is AsynchronousCommandLineAction) diff --git a/src/System.CommandLine/Parsing/CommandLineParser.cs b/src/System.CommandLine/Parsing/CommandLineParser.cs index 69d629b31d..aa32241c62 100644 --- a/src/System.CommandLine/Parsing/CommandLineParser.cs +++ b/src/System.CommandLine/Parsing/CommandLineParser.cs @@ -146,6 +146,8 @@ private static ParseResult Parse( throw new ArgumentNullException(nameof(arguments)); } + using var parseActivity = Activities.ActivitySource.StartActivity(DiagnosticsStrings.ParseMethod); + configuration ??= new CommandLineConfiguration(command); arguments.Tokenize( @@ -160,7 +162,18 @@ private static ParseResult Parse( tokenizationErrors, rawInput); - return operation.Parse(); + var result = operation.Parse(); + parseActivity?.SetTag(DiagnosticsStrings.Command, result.CommandResult?.Command.Name); + if (result.Errors.Count > 0) + { + parseActivity?.SetStatus(Diagnostics.ActivityStatusCode.Error); + parseActivity?.AddBaggage(DiagnosticsStrings.Errors, string.Join("\n", result.Errors.Select(e => e.Message))); + } + else + { + parseActivity?.SetStatus(Diagnostics.ActivityStatusCode.Ok); + } + return result; } private enum Boundary diff --git a/src/System.CommandLine/System.CommandLine.csproj b/src/System.CommandLine/System.CommandLine.csproj index 17a23bebad..b58efcefcb 100644 --- a/src/System.CommandLine/System.CommandLine.csproj +++ b/src/System.CommandLine/System.CommandLine.csproj @@ -27,6 +27,7 @@ +