trace2: add performance format target (#1151)

This series adds the performance format target for TRACE2 tracing.

The first two patches are small fixes for bugs I noticed as I was
testing the
performance format target. The first moves the `FormatTargetTypes` enum
from the specific `Trace2StreamWriter` class to the shared
`Trace2Writer`
class. The second ensures the normal format event names are written in
snake
case (rather than lowercase).

The third patch adds the ability to get the "depth" of the process.
Because Sids
and depth are process-related concepts, it removes the SidManager class
and
moved depth/sid-related properties and methods into the ProcessManager
class.

The fourth patch adds the performance format target. It includes a few
notable
components:
    
1. A new GetMessage method to ensure message strings written to normal
and
performance targets are not duplicated.
2. A new PerformanceFormatComponent class to track sizing of optional
properties of performance format messages.
3. A BuildSpan method that Trace2Message children use to create
correctly-sized "spans" for optional properties of performance format
messages. A span is a piece of the message beginning with a pipe (|) and
ending just before the next pipe or the end of the message.
4. A BuildTimeSpan method that adjusts spans for long/short times. In
future, when we have events that include performance format string span
components, we will need to add an additional method to handle them.

Author: ldennington

src/shared/Atlassian.Bitbucket.UI.Avalonia/Program.cs

@@ -47,7 +47,7 @@ private static void AppMain(object o)
 
             // Set the session id (sid) for the helper process, to be
             // used when TRACE2 tracing is enabled.
-            SidManager.CreateSid();
+            ProcessManager.CreateSid();
             using (var context = new CommandContext())
             using (var app = new HelperApplication(context))
             {

src/shared/Core.Tests/ProcessManagerTests.cs

@@ -0,0 +1,33 @@
+using GitCredentialManager;
+using Xunit;
+
+namespace Core.Tests;
+
+public class ProcessManagerTests
+{
+    [Theory]
+    [InlineData("", 0)]
+    [InlineData("foo", 0)]
+    [InlineData("foo/bar", 1)]
+    [InlineData("foo/bar/baz", 2)]
+    public void CreateSid_Envar_Returns_Expected_Sid(string input, int expected)
+    {
+        ProcessManager.Sid = input;
+        var actual = ProcessManager.GetProcessDepth();
+
+        Assert.Equal(expected, actual);
+    }
+
+    [Theory]
+    [InlineData("", 0)]
+    [InlineData("foo", 0)]
+    [InlineData("foo/bar", 1)]
+    [InlineData("foo/bar/baz", 2)]
+    public void TryGetProcessDepth_Returns_Expected_Depth(string input, int expected)
+    {
+        ProcessManager.Sid = input;
+        var actual = ProcessManager.GetProcessDepth();
+
+        Assert.Equal(expected, actual);
+    }
+}

src/shared/Core.Tests/Trace2Tests.cs

@@ -1,6 +1,3 @@
-using System;
-using System.Text.RegularExpressions;
-using GitCredentialManager.Tests.Objects;
 using Xunit;
 
 namespace GitCredentialManager.Tests;
@@ -30,4 +27,14 @@ public void TryGetPipeName_Windows_Returns_Expected_Value(string input, string e
         Assert.True(isSuccessful);
         Assert.Matches(actual, expected);
     }
+
+    [Theory]
+    [InlineData(0.013772,    "  0.013772 ")]
+    [InlineData(26.316083,   " 26.316083 ")]
+    [InlineData(100.316083,  "100.316083 ")]
+    public void BuildTimeSpan_Match_Returns_Expected_String(double input, string expected)
+    {
+        var actual = Trace2Message.BuildTimeSpan(input);
+        Assert.Equal(expected, actual);
+    }
 }

src/shared/Core/Constants.cs

@@ -56,6 +56,7 @@ public static class EnvironmentVariables
             public const string GcmAllowWia           = "GCM_ALLOW_WINDOWSAUTH";
             public const string GitTrace2Event        = "GIT_TRACE2_EVENT";
             public const string GitTrace2Normal       = "GIT_TRACE2";
+            public const string GitTrace2Performance  = "GIT_TRACE2_PERF";
 
             /*
              * Unlike other environment variables, these proxy variables are normally lowercase only.
@@ -170,9 +171,10 @@ public static class Remote
 
             public static class Trace2
             {
-                public const string SectionName = "trace2";
-                public const string EventTarget = "eventtarget";
-                public const string NormalTarget = "normaltarget";
+                public const string SectionName       = "trace2";
+                public const string EventTarget       = "eventtarget";
+                public const string NormalTarget      = "normaltarget";
+                public const string PerformanceTarget = "perftarget";
             }
         }
 

src/shared/Core/ITrace2Writer.cs

@@ -3,6 +3,17 @@
 
 namespace GitCredentialManager;
 
+/// <summary>
+/// The different format targets supported in the TRACE2 tracing
+/// system.
+/// </summary>
+public enum Trace2FormatTarget
+{
+    Event,
+    Normal,
+    Performance
+}
+
 public interface ITrace2Writer : IDisposable
 {
     bool Failed { get; }
@@ -34,6 +45,9 @@ protected string Format(Trace2Message message)
             case Trace2FormatTarget.Normal:
                 sb.Append(message.ToNormalString());
                 break;
+            case Trace2FormatTarget.Performance:
+                sb.Append(message.ToPerformanceString());
+                break;
             default:
                 Console.WriteLine($"warning: unrecognized format target '{_formatTarget}', disabling TRACE2 tracing.");
                 Failed = true;

src/shared/Core/ProcessManager.cs

@@ -1,3 +1,4 @@
+using System;
 using System.Diagnostics;
 
 namespace GitCredentialManager;
@@ -26,8 +27,14 @@ public interface IProcessManager
 
 public class ProcessManager : IProcessManager
 {
+    private const string SidEnvar = "GIT_TRACE2_PARENT_SID";
+
     protected readonly ITrace2 Trace2;
 
+    public static string Sid { get; internal set; }
+
+    public static int Depth { get; internal set; }
+
     public ProcessManager(ITrace2 trace2)
     {
         EnsureArgument.NotNull(trace2, nameof(trace2));
@@ -49,9 +56,51 @@ public virtual ChildProcess CreateProcess(string path, string args, bool useShel
         return CreateProcess(psi);
     }
 
-
     public virtual ChildProcess CreateProcess(ProcessStartInfo psi)
     {
         return new ChildProcess(Trace2, psi);
     }
+
+    /// <summary>
+    /// Create a TRACE2 "session id" (sid) for this process.
+    /// </summary>
+    public static void CreateSid()
+    {
+        Sid = Environment.GetEnvironmentVariable(SidEnvar);
+
+        if (!string.IsNullOrEmpty(Sid))
+        {
+            // Use trim to ensure no accidental leading or trailing slashes
+            Sid = $"{Sid.Trim('/')}/{Guid.NewGuid():D}";
+            // Only check for process depth if there is a parent.
+            // If there is not a parent, depth defaults to 0.
+            Depth = GetProcessDepth();
+        }
+        else
+        {
+            // We are the root process; create our own 'root' SID
+            Sid = Guid.NewGuid().ToString("D");
+        }
+
+        Environment.SetEnvironmentVariable(SidEnvar, Sid);
+    }
+
+    /// <summary>
+    /// Get "depth" of current process relative to top-level GCM process.
+    /// </summary>
+    /// <returns>Depth of current process.</returns>
+    internal static int GetProcessDepth()
+    {
+        char processSeparator = '/';
+
+        int count = 0;
+        // Use AsSpan() for slight performance bump over traditional foreach loop.
+        foreach (var c in Sid.AsSpan())
+        {
+            if (c == processSeparator)
+                count++;
+        }
+
+        return count;
+    }
 }

src/shared/Core/Settings.cs

@@ -538,6 +538,12 @@ public Trace2Settings GetTrace2Settings()
                 settings.FormatTargetsAndValues.Add(Trace2FormatTarget.Normal, value);
             }
 
+            if (TryGetSetting(Constants.EnvironmentVariables.GitTrace2Performance, KnownGitCfg.Trace2.SectionName,
+                    Constants.GitConfiguration.Trace2.PerformanceTarget, out value))
+            {
+                settings.FormatTargetsAndValues.Add(Trace2FormatTarget.Performance, value);
+            }
+
             return settings;
         }