Add detail for OpenTelemetry (#67)

* Add detail for OpenTelemetry

* fmt

* review fixes

* more fixes

src/Speckle.Sdk.Logging/Consts.cs

@@ -1,7 +1,38 @@
+using System.Reflection;
+
 namespace Speckle.Sdk.Logging;
 
 public static class Consts
 {
-  public const string SERVICE_NAME = "service.name";
-  public const string SERVICE_SLUG = "service.slug";
+  public const string SERVICE_NAME = "connector.name";
+  public const string SERVICE_SLUG = "connector.slug";
+  public const string OS_NAME = "os.name";
+  public const string OS_TYPE = "os.type";
+  public const string OS_SLUG = "os.slug";
+  public const string RUNTIME_NAME = "runtime.name";
+
+  public static readonly string Application = "speckle-connectors";
+  public static string Version => Assembly.GetExecutingAssembly().GetPackageVersion();
+
+  public static string GetPackageVersion(this Assembly assembly)
+  {
+    // MinVer https://github.com/adamralph/minver?tab=readme-ov-file#version-numbers
+    // together with Microsoft.SourceLink.GitHub https://github.com/dotnet/sourcelink
+    // fills AssemblyInformationalVersionAttribute by
+    // {majorVersion}.{minorVersion}.{patchVersion}.{pre-release label}.{pre-release version}.{gitHeight}+{Git SHA of current commit}
+    // Ex: 1.5.0-alpha.1.40+807f703e1b4d9874a92bd86d9f2d4ebe5b5d52e4
+    // The following parts are optional: pre-release label, pre-release version, git height, Git SHA of current commit
+    // For package version, value of AssemblyInformationalVersionAttribute without commit hash is returned.
+
+    var informationalVersion = assembly
+      .GetCustomAttribute<AssemblyInformationalVersionAttribute>()
+      ?.InformationalVersion;
+    if (informationalVersion is null)
+    {
+      return String.Empty;
+    }
+
+    var indexOfPlusSign = informationalVersion.IndexOf('+');
+    return indexOfPlusSign > 0 ? informationalVersion.Substring(0, indexOfPlusSign) : informationalVersion;
+  }
 }

src/Speckle.Sdk.Logging/ISpeckleActivity.cs

@@ -3,4 +3,19 @@ namespace Speckle.Sdk.Logging;
 public interface ISpeckleActivity : IDisposable
 {
   void SetTag(string key, object? value);
+  void RecordException(Exception e);
+  string TraceId { get; }
+  void SetStatus(SpeckleActivityStatusCode code);
+}
+
+public enum SpeckleActivityStatusCode
+{
+  /// <summary>Unset status code is the default value indicating the status code is not initialized.</summary>
+  Unset,
+
+  /// <summary>Status code indicating the operation has been validated and completed successfully.</summary>
+  Ok,
+
+  /// <summary>Status code indicating an error is encountered during the operation.</summary>
+  Error,
 }

src/Speckle.Sdk.Logging/LogBuilder.cs

@@ -1,6 +1,9 @@
 using System.Diagnostics;
 using System.Reflection;
 using System.Runtime.InteropServices;
+using OpenTelemetry.Exporter;
+using OpenTelemetry.Resources;
+using OpenTelemetry.Trace;
 using Serilog;
 using Serilog.Exceptions;
 using Serilog.Sinks.OpenTelemetry;
@@ -9,13 +12,28 @@ namespace Speckle.Sdk.Logging;
 
 public static class LogBuilder
 {
-  public static void Initialize(
+  public static IDisposable? Initialize(
     string userId,
     string applicationAndVersion,
-    string? slug,
-    SpeckleLogging? speckleLogging
+    string slug,
+    SpeckleLogging? speckleLogging,
+    SpeckleTracing? speckleTracing
   )
   {
+    var resourceBuilder = ResourceBuilder
+      .CreateEmpty()
+      .AddService(serviceName: Consts.Application, serviceVersion: Consts.Version)
+      .AddAttributes(
+        new List<KeyValuePair<string, object>>
+        {
+          new(Consts.SERVICE_NAME, applicationAndVersion),
+          new(Consts.SERVICE_SLUG, slug),
+          new(Consts.OS_NAME, Environment.OSVersion.ToString()),
+          new(Consts.OS_TYPE, RuntimeInformation.ProcessArchitecture.ToString()),
+          new(Consts.OS_SLUG, DetermineHostOsSlug()),
+          new(Consts.RUNTIME_NAME, RuntimeInformation.FrameworkDescription)
+        }
+      );
     var fileVersionInfo = GetFileVersionInfo();
     var serilogLogConfiguration = new LoggerConfiguration()
       .MinimumLevel.Is(SpeckleLogger.GetLevel(speckleLogging?.MinimumLevel ?? SpeckleLogLevel.Warning))
@@ -48,20 +66,12 @@ public static void Initialize(
 
     if (speckleLogging?.Otel is not null)
     {
-      serilogLogConfiguration = serilogLogConfiguration.WriteTo.OpenTelemetry(o =>
-      {
-        o.Protocol = OtlpProtocol.HttpProtobuf;
-        o.LogsEndpoint = speckleLogging.Otel.Endpoint;
-        o.Headers = speckleLogging.Otel.Headers ?? o.Headers;
-        o.ResourceAttributes = new Dictionary<string, object>
-        {
-          [Consts.SERVICE_NAME] = applicationAndVersion,
-          [Consts.SERVICE_SLUG] = slug ?? string.Empty
-        };
-      });
+      serilogLogConfiguration = InitializeOtelLogging(serilogLogConfiguration, speckleLogging.Otel, resourceBuilder);
     }
     var logger = serilogLogConfiguration.CreateLogger();
     Log.Logger = logger;
+
+    return InitializeOtelTracing(speckleTracing, resourceBuilder);
   }
 
   private static FileVersionInfo GetFileVersionInfo()
@@ -89,4 +99,92 @@ private static string DetermineHostOsSlug()
 
     return RuntimeInformation.OSDescription;
   }
+
+  private static LoggerConfiguration InitializeOtelLogging(
+    LoggerConfiguration serilogLogConfiguration,
+    SpeckleOtelLogging speckleOtelLogging,
+    ResourceBuilder resourceBuilder
+  ) =>
+    serilogLogConfiguration.WriteTo.OpenTelemetry(o =>
+    {
+      o.Protocol = OtlpProtocol.HttpProtobuf;
+      o.LogsEndpoint = speckleOtelLogging.Endpoint;
+      o.Headers = speckleOtelLogging.Headers ?? o.Headers;
+      o.ResourceAttributes = resourceBuilder.Build().Attributes.ToDictionary(x => x.Key, x => x.Value);
+    });
+
+  private static IDisposable? InitializeOtelTracing(SpeckleTracing? logConfiguration, ResourceBuilder resourceBuilder)
+  {
+    var consoleEnabled = logConfiguration?.Console ?? false;
+    var otelEnabled = logConfiguration?.Otel?.Enabled ?? false;
+    if (!consoleEnabled && !otelEnabled)
+    {
+      return null;
+    }
+
+    var tracerProviderBuilder = OpenTelemetry.Sdk.CreateTracerProviderBuilder().AddSource(Consts.Application);
+    tracerProviderBuilder = tracerProviderBuilder.AddHttpClientInstrumentation(
+      (options) =>
+      {
+        options.FilterHttpWebRequest = (httpWebRequest) =>
+        {
+          // Example: Only collect telemetry about HTTP GET requests.
+          return httpWebRequest.Method.Equals(HttpMethod.Get.Method);
+        };
+        options.EnrichWithHttpWebRequest = (activity, httpWebRequest) =>
+        {
+          activity.SetTag("requestVersion", httpWebRequest.ProtocolVersion);
+        };
+        // Note: Only called on .NET Framework.
+        options.EnrichWithHttpWebResponse = (activity, httpWebResponse) =>
+        {
+          activity.SetTag("responseVersion", httpWebResponse.ProtocolVersion);
+        };
+        // Note: Only called on .NET & .NET Core runtimes.
+        options.EnrichWithHttpRequestMessage = (activity, httpRequestMessage) =>
+        {
+          activity.SetTag("requestVersion", httpRequestMessage.Version);
+        };
+        // Note: Only called on .NET & .NET Core runtimes.
+        options.EnrichWithHttpResponseMessage = (activity, httpResponseMessage) =>
+        {
+          activity.SetTag("responseVersion", httpResponseMessage.Version);
+        };
+        // Note: Called for all runtimes.
+        options.EnrichWithException = (activity, exception) =>
+        {
+          activity.SetTag("stackTrace", exception.StackTrace);
+        };
+        options.RecordException = true;
+      }
+    );
+    if (otelEnabled)
+    {
+      tracerProviderBuilder = tracerProviderBuilder.AddOtlpExporter(x => ProcessOptions(logConfiguration!, x));
+    }
+
+    if (consoleEnabled)
+    {
+      tracerProviderBuilder = tracerProviderBuilder.AddConsoleExporter();
+    }
+
+    tracerProviderBuilder = tracerProviderBuilder.SetResourceBuilder(resourceBuilder).SetSampler<AlwaysOnSampler>();
+
+    return tracerProviderBuilder.Build();
+  }
+
+  private static void ProcessOptions(SpeckleTracing logConfiguration, OtlpExporterOptions options)
+  {
+    options.Protocol = OtlpExportProtocol.HttpProtobuf;
+    var headers = string.Join(",", logConfiguration.Otel?.Headers?.Select(x => x.Key + "=" + x.Value) ?? []);
+    if (headers.Length != 0)
+    {
+      options.Headers = headers;
+    }
+
+    if (logConfiguration.Otel?.Endpoint is not null)
+    {
+      options.Endpoint = new Uri(logConfiguration.Otel.Endpoint);
+    }
+  }
 }

src/Speckle.Sdk.Logging/SpeckleActivity.cs

@@ -1,4 +1,5 @@
 using System.Diagnostics;
+using OpenTelemetry.Trace;
 
 namespace Speckle.Sdk.Logging;
 
@@ -7,4 +8,19 @@ public class SpeckleActivity(Activity activity) : ISpeckleActivity
   public void Dispose() => activity.Dispose();
 
   public void SetTag(string key, object? value) => activity.SetTag(key, value);
+
+  public void RecordException(Exception e) => activity.RecordException(e);
+
+  public string TraceId => activity.TraceId.ToString();
+
+  public void SetStatus(SpeckleActivityStatusCode code) =>
+    activity.SetStatus(
+      code switch
+      {
+        SpeckleActivityStatusCode.Error => ActivityStatusCode.Error,
+        SpeckleActivityStatusCode.Unset => ActivityStatusCode.Unset,
+        SpeckleActivityStatusCode.Ok => ActivityStatusCode.Ok,
+        _ => throw new ArgumentOutOfRangeException(nameof(code), code, null)
+      }
+    );
 }

src/Speckle.Sdk.Logging/SpeckleActivityFactory.cs

@@ -5,13 +5,11 @@ namespace Speckle.Sdk.Logging;
 
 public static class SpeckleActivityFactory
 {
-  private static ActivitySource? s_activitySource;
+  private static readonly ActivitySource? s_activitySource = new(Consts.Application, Consts.Version);
 
-  public static void Initialize(string slug, string version) => s_activitySource = new ActivitySource(slug, version);
-
-  public static ISpeckleActivity? Start([CallerMemberName] string name = "SpeckleActivityFactory")
+  public static ISpeckleActivity? Start(string? name = null, [CallerMemberName] string source = "")
   {
-    var activity = s_activitySource?.StartActivity(name, ActivityKind.Client);
+    var activity = s_activitySource?.StartActivity(name ?? source, ActivityKind.Client);
     if (activity is null)
     {
       return null;

src/Speckle.Sdk/Api/GraphQL/Client.cs

@@ -75,7 +75,7 @@ public void Dispose()
       CommitUpdatedSubscription?.Dispose();
       CommitDeletedSubscription?.Dispose();
       CommentActivitySubscription?.Dispose();
-      GQLClient?.Dispose();
+      GQLClient.Dispose();
     }
     catch (Exception ex) when (!ex.IsFatal()) { }
   }
@@ -105,13 +105,10 @@ internal async Task<T> ExecuteWithResiliencePolicies<T>(Func<Task<T>> func)
   /// <inheritdoc/>
   public async Task<T> ExecuteGraphQLRequest<T>(GraphQLRequest request, CancellationToken cancellationToken = default)
   {
-    // using IDisposable context0 = LogContext.Push(CreateEnrichers<T>(request));
-    var timer = Stopwatch.StartNew();
-
-    Exception? exception = null;
+    using var activity = SpeckleActivityFactory.Start();
     try
     {
-      return await ExecuteWithResiliencePolicies(async () =>
+      var ret = await ExecuteWithResiliencePolicies(async () =>
         {
           GraphQLResponse<T> result = await GQLClient
             .SendMutationAsync<T>(request, cancellationToken)
@@ -120,31 +117,15 @@ public async Task<T> ExecuteGraphQLRequest<T>(GraphQLRequest request, Cancellati
           return result.Data;
         })
         .ConfigureAwait(false);
+      activity?.SetStatus(SpeckleActivityStatusCode.Ok);
+      return ret;
     }
-    catch (Exception ex)
+    catch (Exception e)
     {
-      exception = ex;
+      activity?.SetStatus(SpeckleActivityStatusCode.Error);
+      activity?.RecordException(e);
       throw;
     }
-    finally
-    {
-      SpeckleLogLevel logLevel = exception switch
-      {
-        null => SpeckleLogLevel.Information,
-        OperationCanceledException
-          => cancellationToken.IsCancellationRequested ? SpeckleLogLevel.Debug : SpeckleLogLevel.Error,
-        SpeckleException => SpeckleLogLevel.Warning,
-        _ => SpeckleLogLevel.Error,
-      };
-      SpeckleLog.Logger.Write(
-        logLevel,
-        exception,
-        "Execution of the graphql request to get {resultType} completed with success:{status} after {elapsed} seconds",
-        typeof(T).Name,
-        exception is null,
-        timer.Elapsed.TotalSeconds
-      );
-    }
   }
 
   internal void MaybeThrowFromGraphQLErrors<T>(GraphQLRequest request, GraphQLResponse<T> response)
@@ -154,7 +135,6 @@ internal void MaybeThrowFromGraphQLErrors<T>(GraphQLRequest request, GraphQLResp
     var errors = response.Errors;
     if (errors != null && errors.Length != 0)
     {
-      var errorMessages = errors.Select(e => e.Message);
       if (
         errors.Any(e =>
           e.Extensions != null