fix: Structured Logging follow-up (#2390)

Author: bitsandfoxes

CHANGELOG.md

@@ -2,8 +2,9 @@
 
 ## Unreleased
 
-### Fixes 
+### Fixes
 
+- Structured logs now have the `origin` and `sdk` attributes correctly set ([#2390](https://github.com/getsentry/sentry-unity/pull/2390))
 - Resolved possible startup crashes on Android VR platforms like the Oculus Quest. The SDK no longer natively subscribes to interaction hooks for automatic tracing and breadcrumb creation. ([#2393](https://github.com/getsentry/sentry-unity/pull/2393))
 
 ### Dependencies

src/Sentry.Unity/Integrations/UnityApplicationLoggingIntegration.cs

@@ -1,5 +1,6 @@
 using System;
 using Sentry.Extensibility;
+using Sentry.Infrastructure;
 using Sentry.Integrations;
 using UnityEngine;
 
@@ -12,26 +13,28 @@ namespace Sentry.Unity.Integrations;
 /// </summary>
 internal class UnityApplicationLoggingIntegration : ISdkIntegration
 {
-    private readonly IApplication _application;
     private readonly bool _captureExceptions;
+    private readonly IApplication _application;
+    private readonly ISystemClock _clock;
 
     private ErrorTimeDebounce _errorTimeDebounce = null!;       // Set in Register
     private LogTimeDebounce _logTimeDebounce = null!;           // Set in Register
     private WarningTimeDebounce _warningTimeDebounce = null!;   // Set in Register
 
-    private IHub? _hub;
+    private IHub _hub = null!;                                  // Set in Register
     private SentryUnityOptions _options = null!;                // Set in Register
 
-    internal UnityApplicationLoggingIntegration(bool captureExceptions = false, IApplication? application = null)
+    internal UnityApplicationLoggingIntegration(bool captureExceptions = false, IApplication? application = null, ISystemClock? clock = null)
     {
         _captureExceptions = captureExceptions;
         _application = application ?? ApplicationAdapter.Instance;
+        _clock = clock ?? SystemClock.Clock;
     }
 
     public void Register(IHub hub, SentryOptions sentryOptions)
     {
-        _hub = hub;
-        // This should never throw
+        // These should never throw but in case they do...
+        _hub = hub ?? throw new ArgumentException("Hub is null.");
         _options = sentryOptions as SentryUnityOptions ?? throw new ArgumentException("Options is not of type 'SentryUnityOptions'.");
 
         _logTimeDebounce = new LogTimeDebounce(_options.DebounceTimeLog);
@@ -44,11 +47,6 @@ public void Register(IHub hub, SentryOptions sentryOptions)
 
     internal void OnLogMessageReceived(string message, string stacktrace, LogType logType)
     {
-        if (_hub is null)
-        {
-            return;
-        }
-
         // We're not capturing the SDK's own logs
         if (message.StartsWith(UnityLogger.LogTag))
         {
@@ -64,6 +62,7 @@ internal void OnLogMessageReceived(string message, string stacktrace, LogType lo
         ProcessException(message, stacktrace, logType);
         ProcessError(message, stacktrace, logType);
         ProcessBreadcrumbs(message, logType);
+        ProcessStructuredLog(message, logType);
     }
 
     private bool IsGettingDebounced(LogType logType)
@@ -92,7 +91,7 @@ private void ProcessException(string message, string stacktrace, LogType logType
             _options.LogDebug("Exception capture has been enabled. Capturing exception through '{0}'.", nameof(UnityApplicationLoggingIntegration));
 
             var evt = UnityLogEventFactory.CreateExceptionEvent(message, stacktrace, false, _options);
-            _hub?.CaptureEvent(evt);
+            _hub.CaptureEvent(evt);
         }
     }
 
@@ -108,11 +107,11 @@ private void ProcessError(string message, string stacktrace, LogType logType)
         if (_options.AttachStacktrace && !string.IsNullOrEmpty(stacktrace))
         {
             var evt = UnityLogEventFactory.CreateMessageEvent(message, stacktrace, SentryLevel.Error, _options);
-            _hub?.CaptureEvent(evt);
+            _hub.CaptureEvent(evt);
         }
         else
         {
-            _hub?.CaptureMessage(message, level: SentryLevel.Error);
+            _hub.CaptureMessage(message, level: SentryLevel.Error);
         }
     }
 
@@ -133,8 +132,26 @@ private void ProcessBreadcrumbs(string message, LogType logType)
         if (_options.AddBreadcrumbsForLogType.TryGetValue(logType, out var value) && value)
         {
             _options.LogDebug("Adding breadcrumb for log message of type: {0}", logType);
-            _hub?.AddBreadcrumb(message: message, category: "unity.logger", level: ToBreadcrumbLevel(logType));
+            _hub.AddBreadcrumb(message: message, category: "unity.logger", level: ToBreadcrumbLevel(logType));
+        }
+    }
+
+    private void ProcessStructuredLog(string message, LogType logType)
+    {
+        if (!_options.Experimental.EnableLogs || !_options.Experimental.CaptureStructuredLogsForLogType.TryGetValue(logType, out var captureLog) || !captureLog)
+        {
+            return;
         }
+
+        _options.LogDebug("Capturing structured log message of type '{0}'.", logType);
+
+        SentryLog.GetTraceIdAndSpanId(_hub, out var traceId, out var spanId);
+        SentryLog log = new(_clock.GetUtcNow(), traceId, ToLogLevel(logType), message) { ParentSpanId = spanId };
+
+        log.SetDefaultAttributes(_options, UnitySdkInfo.Sdk);
+        log.SetOrigin("auto.log.unity");
+
+        _hub.Logger.CaptureLog(log);
     }
 
     private void OnQuitting() => _application.LogMessageReceived -= OnLogMessageReceived;
@@ -149,4 +166,15 @@ private static BreadcrumbLevel ToBreadcrumbLevel(LogType logType)
             LogType.Warning => BreadcrumbLevel.Warning,
             _ => BreadcrumbLevel.Info
         };
+
+    private static SentryLogLevel ToLogLevel(LogType logType)
+        => logType switch
+        {
+            LogType.Assert => SentryLogLevel.Error,
+            LogType.Error => SentryLogLevel.Error,
+            LogType.Exception => SentryLogLevel.Error,
+            LogType.Log => SentryLogLevel.Info,
+            LogType.Warning => SentryLogLevel.Warning,
+            _ => SentryLogLevel.Info
+        };
 }

src/Sentry.Unity/Integrations/UnityLogHandlerIntegration.cs

@@ -12,24 +12,15 @@ namespace Sentry.Unity.Integrations;
 /// </summary>
 internal sealed class UnityLogHandlerIntegration : ISdkIntegration, ILogHandler
 {
-    private readonly Func<SentryStructuredLogger>? _loggerFactory;
     private IHub? _hub;
     private SentryUnityOptions _options = null!; // Set during register
     private ILogHandler _unityLogHandler = null!; // Set during register
-    private SentryStructuredLogger _structuredLogger = null!; // Set during register
-
-    // For testing: allows injecting a custom logger factory
-    internal UnityLogHandlerIntegration(Func<SentryStructuredLogger>? loggerFactory = null)
-    {
-        _loggerFactory = loggerFactory;
-    }
 
     public void Register(IHub hub, SentryOptions sentryOptions)
     {
         _hub = hub;
         // This should never happen, but if it does...
         _options = sentryOptions as SentryUnityOptions ?? throw new ArgumentException("Options is not of type 'SentryUnityOptions'.");
-        _structuredLogger = _loggerFactory?.Invoke() ?? _hub.Logger;
 
         // If called twice (i.e. init with the same options object) the integration will reference itself as the
         // original handler loghandler and endlessly forward to itself
@@ -70,66 +61,13 @@ internal void ProcessException(Exception exception, UnityEngine.Object? context)
         // https://docs.sentry.io/platforms/unity/troubleshooting/#unhandled-exceptions---debuglogexception
         exception.SetSentryMechanism("Unity.LogException", handled: false, terminal: false);
         _ = _hub.CaptureException(exception);
-
-        if (_options.Experimental.CaptureStructuredLogsForLogType.TryGetValue(LogType.Exception, out var captureException) && captureException)
-        {
-            _options.LogDebug("Capturing structured log message of type '{0}'.", LogType.Exception);
-            _structuredLogger.LogError(exception.Message);
-        }
     }
 
     public void LogFormat(LogType logType, UnityEngine.Object? context, string format, params object[] args)
     {
-        try
-        {
-            ProcessLog(logType, context, format, args);
-        }
-        finally
-        {
-            // Always pass the log back to Unity
-            // Capturing of `Debug`, `Warning`, and `Error` happens in the Application Logging Integration.
-            // The LogHandler does not have access to the stacktrace information required
-            _unityLogHandler.LogFormat(logType, context, format, args);
-        }
-    }
-
-    private void ProcessLog(LogType logType, UnityEngine.Object? context, string format, params object[] args)
-    {
-        if (_hub?.IsEnabled is not true || !_options.Experimental.EnableLogs)
-        {
-            return;
-        }
-
-        // We're not capturing the SDK's own logs.
-        if (args.Length > 1 && Equals(args[0], UnityLogger.LogTag))
-        {
-            return;
-        }
-
-        ProcessStructuredLog(logType, format, args);
-    }
-
-    private void ProcessStructuredLog(LogType logType, string format, params object[] args)
-    {
-        if (!_options.Experimental.CaptureStructuredLogsForLogType.TryGetValue(logType, out var captureLog) || !captureLog)
-        {
-            return;
-        }
-
-        _options.LogDebug("Capturing structured log message of type '{0}'.", logType);
-
-        switch (logType)
-        {
-            case LogType.Log:
-                _structuredLogger.LogInfo(format, args);
-                break;
-            case LogType.Warning:
-                _structuredLogger.LogWarning(format, args);
-                break;
-            case LogType.Assert:
-            case LogType.Error:
-                _structuredLogger.LogError(format, args);
-                break;
-        }
+        // Always pass the log back to Unity
+        // Capturing of `Debug`, `Warning`, and `Error` happens in the Application Logging Integration.
+        // The LogHandler does not have access to the stacktrace information required
+        _unityLogHandler.LogFormat(logType, context, format, args);
     }
 }

src/Sentry.Unity/Integrations/UnityScopeIntegration.cs

@@ -13,6 +13,8 @@ internal static class UnitySdkInfo
     public static string Version { get; } = typeof(UnitySdkInfo).Assembly.GetNameAndVersion().Version ?? "0.0.0";
     public const string Name = "sentry.dotnet.unity";
     public const string PackageName = "upm:sentry.unity";
+
+    public static readonly SdkVersion Sdk = new() { Name = Name, Version = Version };
 }
 
 internal class UnityScopeIntegration : ISdkIntegration

test/Sentry.Unity.Tests/Stubs/TestHub.cs

@@ -16,12 +16,10 @@ internal sealed class TestHub : IHub
     public IReadOnlyList<SentryTransaction> CapturedTransactions => _capturedTransactions;
     public IReadOnlyList<Action<Scope>> ConfigureScopeCalls => _configureScopeCalls;
 
-    public TestHub(bool isEnabled = true)
+    public TestHub(bool isEnabled = true, SentryStructuredLogger? logger = null)
     {
-#pragma warning disable SENTRY0001
-        Logger = null!;
-#pragma warning restore SENTRY0001
         IsEnabled = isEnabled;
+        Logger = logger ?? new TestStructuredLogger();
     }
     public bool IsEnabled { get; }
 
@@ -134,10 +132,7 @@ public void BindException(Exception exception, ISpan span)
         throw new NotImplementedException();
     }
 
-    ISpan? IHub.GetSpan()
-    {
-        throw new NotImplementedException();
-    }
+    ISpan? IHub.GetSpan() => null;
 
     public SentryTraceHeader? GetTraceHeader()
     {

test/Sentry.Unity.Tests/Stubs/TestStructuredLogger.cs

@@ -6,19 +6,24 @@ namespace Sentry.Unity.Tests.Stubs;
 internal sealed class TestStructuredLogger : SentryStructuredLogger
 {
     public List<(string level, string message, object[] args)> LogCalls { get; } = new();
+    public List<SentryLog> CapturedLogs { get; } = new();
 
     private protected override void CaptureLog(SentryLogLevel level, string template, object[]? parameters, Action<SentryLog>? configureLog)
         => LogCalls.Add((level.ToString(), template, parameters ?? []));
 
     protected internal override void CaptureLog(SentryLog log)
     {
-        // Not needed for our tests
+        CapturedLogs.Add(log);
     }
 
     protected internal override void Flush()
     {
         // Not needed for our tests
     }
 
-    public void Clear() => LogCalls.Clear();
+    public void Clear()
+    {
+        LogCalls.Clear();
+        CapturedLogs.Clear();
+    }
 }