diff --git a/src/Sentry.Unity.Editor/ConfigurationWindow/LoggingTab.cs b/src/Sentry.Unity.Editor/ConfigurationWindow/LoggingTab.cs index 367fe9cc7..40fe77dbd 100644 --- a/src/Sentry.Unity.Editor/ConfigurationWindow/LoggingTab.cs +++ b/src/Sentry.Unity.Editor/ConfigurationWindow/LoggingTab.cs @@ -130,24 +130,26 @@ internal static void Display(ScriptableSentryUnityOptions options) EditorGUI.indentLevel++; - options.DebounceTimeLog = EditorGUILayout.IntField( - new GUIContent("Log Debounce [ms]", "The time that has to pass between events of " + - "LogType.Log before the SDK sends it again."), - options.DebounceTimeLog); - options.DebounceTimeLog = Math.Max(0, options.DebounceTimeLog); - - options.DebounceTimeWarning = EditorGUILayout.IntField( - new GUIContent("Warning Debounce [ms]", "The time that has to pass between events of " + - "LogType.Warning before the SDK sends it again."), - options.DebounceTimeWarning); - options.DebounceTimeWarning = Math.Max(0, options.DebounceTimeWarning); - - options.DebounceTimeError = EditorGUILayout.IntField( - new GUIContent("Error Debounce [ms]", "The time that has to pass between events of " + - "LogType.Assert, LogType.Exception and LogType.Error before " + - "the SDK sends it again."), - options.DebounceTimeError); - options.DebounceTimeError = Math.Max(0, options.DebounceTimeError); + options.StructuredLogOnDebugLog = EditorGUILayout.Toggle( + new GUIContent("Debug.Log", + "Whether the SDK should forward Debug.Log messages to Sentry structured logging"), + options.StructuredLogOnDebugLog); + options.StructuredLogOnDebugLogWarning = EditorGUILayout.Toggle( + new GUIContent("Debug.LogWarning", + "Whether the SDK should forward Debug.LogWarning messages to Sentry structured logging"), + options.StructuredLogOnDebugLogWarning); + options.StructuredLogOnDebugLogAssertion = EditorGUILayout.Toggle( + new GUIContent("Debug.LogAssertion", + "Whether the SDK should forward Debug.LogAssertion messages to Sentry structured logging"), + options.StructuredLogOnDebugLogAssertion); + options.StructuredLogOnDebugLogError = EditorGUILayout.Toggle( + new GUIContent("Debug.LogError", + "Whether the SDK should forward Debug.LogError messages to Sentry structured logging"), + options.StructuredLogOnDebugLogError); + options.StructuredLogOnDebugLogException = EditorGUILayout.Toggle( + new GUIContent("Debug.LogException", + "Whether the SDK should forward Debug.LogException messages to Sentry structured logging"), + options.StructuredLogOnDebugLogException); EditorGUI.indentLevel--; EditorGUILayout.EndToggleGroup(); diff --git a/src/Sentry.Unity/ContentDebounce.cs b/src/Sentry.Unity/ContentDebounce.cs new file mode 100644 index 000000000..e076a8dc7 --- /dev/null +++ b/src/Sentry.Unity/ContentDebounce.cs @@ -0,0 +1,76 @@ +using System; +using UnityEngine; + +namespace Sentry.Unity; + +/// +/// Interface for log message deduplication. +/// +public interface IUnityLogMessageDebounce +{ + /// + /// Checks if a log message should be debounced based on its content. + /// Returns true if the message should be allowed through, false if it should be blocked. + /// + bool Debounced(string message, string stacktrace, LogType logType); +} + +/// +/// Content-based debounce that deduplicates log messages based on their content hash. +/// This class is not thread-safe and is designed to be called by Unity non-threaded logger callback. +/// +public class ContentDebounce : IUnityLogMessageDebounce +{ + private static DateTimeOffset Now => DateTimeOffset.UtcNow; + + private readonly struct LogEntry + { + public readonly int Hash; + public readonly DateTimeOffset Timestamp; + + public LogEntry(int hash, DateTimeOffset timestamp) + { + Hash = hash; + Timestamp = timestamp; + } + } + + private readonly TimeSpan _debounceWindow; + private readonly LogEntry[] _ringBuffer; + private int _head; + + public ContentDebounce(TimeSpan debounceWindow, int bufferSize = 100) + { + _debounceWindow = debounceWindow; + _ringBuffer = new LogEntry[bufferSize]; + _head = 0; + } + + /// + /// Checks if the log content should be debounced. + /// Returns true if the message should be allowed through, false if it should be blocked. + /// + public bool Debounced(string message, string stacktrace, LogType logType) + { + var contentHash = HashCode.Combine(message, stacktrace); + var currentTime = Now; + + foreach (var entry in _ringBuffer) + { + if (entry.Hash != contentHash || entry.Timestamp == default) + { + continue; + } + + var timeSinceLastSeen = currentTime - entry.Timestamp; + if (timeSinceLastSeen < _debounceWindow) + { + return false; + } + } + + _ringBuffer[_head] = new LogEntry(contentHash, currentTime); + _head = (_head + 1) % _ringBuffer.Length; + return true; + } +} diff --git a/src/Sentry.Unity/Integrations/LifeCycleIntegration.cs b/src/Sentry.Unity/Integrations/LifeCycleIntegration.cs index d5c046d0b..c2c92ce89 100644 --- a/src/Sentry.Unity/Integrations/LifeCycleIntegration.cs +++ b/src/Sentry.Unity/Integrations/LifeCycleIntegration.cs @@ -49,7 +49,6 @@ public void Register(IHub hub, SentryOptions sentryOptions) _options.DiagnosticLogger?.LogDebug("Resuming session."); hub.ResumeSession(); }; - _sentryMonoBehaviour.ApplicationPausing += () => { if (!hub.IsEnabled) diff --git a/src/Sentry.Unity/Integrations/UnityApplicationLoggingIntegration.cs b/src/Sentry.Unity/Integrations/UnityApplicationLoggingIntegration.cs index d91f0b878..c810e6264 100644 --- a/src/Sentry.Unity/Integrations/UnityApplicationLoggingIntegration.cs +++ b/src/Sentry.Unity/Integrations/UnityApplicationLoggingIntegration.cs @@ -16,10 +16,6 @@ internal class UnityApplicationLoggingIntegration : ISdkIntegration 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 = null!; // Set in Register private SentryUnityOptions _options = null!; // Set in Register @@ -35,10 +31,6 @@ public void Register(IHub hub, SentryOptions sentryOptions) _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); - _warningTimeDebounce = new WarningTimeDebounce(_options.DebounceTimeWarning); - _errorTimeDebounce = new ErrorTimeDebounce(_options.DebounceTimeError); - _application.LogMessageReceived += OnLogMessageReceived; _application.Quitting += OnQuitting; } @@ -51,7 +43,7 @@ internal void OnLogMessageReceived(string message, string stacktrace, LogType lo return; } - if (IsGettingDebounced(logType)) + if (IsGettingDebounced(message, stacktrace, logType)) { _options.LogDebug("Log message of type '{0}' is getting debounced.", logType); return; @@ -59,24 +51,17 @@ internal void OnLogMessageReceived(string message, string stacktrace, LogType lo ProcessError(message, stacktrace, logType); ProcessBreadcrumbs(message, logType); - ProcessStructuredLog(message, logType); } - private bool IsGettingDebounced(LogType logType) + private bool IsGettingDebounced(string message, string stacktrace, LogType logType) { if (_options.EnableLogDebouncing is false) { return false; } - return logType switch - { - LogType.Exception => !_errorTimeDebounce.Debounced(), - LogType.Error or LogType.Assert => !_errorTimeDebounce.Debounced(), - LogType.Log => !_logTimeDebounce.Debounced(), - LogType.Warning => !_warningTimeDebounce.Debounced(), - _ => true - }; + // Use the debouncer from options - returns true if allowed, false if blocked + return !_options.LogDebouncer.Debounced(message, stacktrace, logType); } private void ProcessError(string message, string stacktrace, LogType logType) @@ -91,11 +76,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); } } diff --git a/src/Sentry.Unity/Integrations/UnityLogHandlerIntegration.cs b/src/Sentry.Unity/Integrations/UnityLogHandlerIntegration.cs index 51c2a535e..8bdcca89f 100644 --- a/src/Sentry.Unity/Integrations/UnityLogHandlerIntegration.cs +++ b/src/Sentry.Unity/Integrations/UnityLogHandlerIntegration.cs @@ -15,6 +15,7 @@ internal sealed class UnityLogHandlerIntegration : ISdkIntegration, ILogHandler private IHub? _hub; private SentryUnityOptions _options = null!; // Set during register private ILogHandler _unityLogHandler = null!; // Set during register + private SentryStructuredLogger _structuredLogger = null!; // Set during register public void Register(IHub hub, SentryOptions sentryOptions) { @@ -61,6 +62,12 @@ 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.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) diff --git a/src/Sentry.Unity/Integrations/UnityWebGLExceptionHandler.cs b/src/Sentry.Unity/Integrations/UnityWebGLExceptionHandler.cs index 398303257..36028bd62 100644 --- a/src/Sentry.Unity/Integrations/UnityWebGLExceptionHandler.cs +++ b/src/Sentry.Unity/Integrations/UnityWebGLExceptionHandler.cs @@ -14,7 +14,6 @@ internal sealed class UnityWebGLExceptionHandler : ISdkIntegration private readonly IApplication _application; private IHub _hub = null!; private SentryUnityOptions _options = null!; - private ErrorTimeDebounce _errorTimeDebounce = null!; internal UnityWebGLExceptionHandler(IApplication? application = null) { @@ -27,7 +26,6 @@ public void Register(IHub hub, SentryOptions sentryOptions) _options = sentryOptions as SentryUnityOptions ?? throw new ArgumentException("Options is not of type 'SentryUnityOptions'."); - _errorTimeDebounce = new ErrorTimeDebounce(_options.DebounceTimeError); _application.LogMessageReceived += OnLogMessageReceived; _application.Quitting += OnQuitting; } @@ -50,11 +48,11 @@ internal void OnLogMessageReceived(string message, string stacktrace, LogType lo return; } - if (_options.EnableLogDebouncing && !_errorTimeDebounce.Debounced()) - { - _options.LogDebug("Exception is getting debounced."); - return; - } + // if (_options.EnableLogDebouncing && !_errorTimeDebounce.Debounced()) + // { + // _options.LogDebug("Exception is getting debounced."); + // return; + // } _options.LogDebug("Capturing exception on WebGL through LogMessageReceived."); var evt = UnityLogEventFactory.CreateExceptionEvent(message, stacktrace, false, _options); diff --git a/src/Sentry.Unity/ScriptableSentryUnityOptions.cs b/src/Sentry.Unity/ScriptableSentryUnityOptions.cs index 07afe57fd..236d33dbc 100644 --- a/src/Sentry.Unity/ScriptableSentryUnityOptions.cs +++ b/src/Sentry.Unity/ScriptableSentryUnityOptions.cs @@ -30,9 +30,7 @@ public static string GetConfigPath(string? notDefaultConfigName = null) [field: SerializeField] public bool CaptureInEditor { get; set; } = true; [field: SerializeField] public bool EnableLogDebouncing { get; set; } = false; - [field: SerializeField] public int DebounceTimeLog { get; set; } = (int)TimeSpan.FromSeconds(1).TotalMilliseconds; - [field: SerializeField] public int DebounceTimeWarning { get; set; } = (int)TimeSpan.FromSeconds(1).TotalMilliseconds; - [field: SerializeField] public int DebounceTimeError { get; set; } = (int)TimeSpan.FromSeconds(1).TotalMilliseconds; + [field: SerializeField] public int DebounceTimeWindow { get; set; } = (int)TimeSpan.FromSeconds(1).TotalMilliseconds; [field: SerializeField] public double TracesSampleRate { get; set; } = 0; [field: SerializeField] public bool AutoStartupTraces { get; set; } = true; @@ -149,9 +147,7 @@ internal SentryUnityOptions ToSentryUnityOptions( Dsn = Dsn, CaptureInEditor = CaptureInEditor, EnableLogDebouncing = EnableLogDebouncing, - DebounceTimeLog = TimeSpan.FromMilliseconds(DebounceTimeLog), - DebounceTimeWarning = TimeSpan.FromMilliseconds(DebounceTimeWarning), - DebounceTimeError = TimeSpan.FromMilliseconds(DebounceTimeError), + DebounceTimeWindow = TimeSpan.FromMilliseconds(DebounceTimeWindow), TracesSampleRate = TracesSampleRate, AutoStartupTraces = AutoStartupTraces, AutoSceneLoadTraces = AutoSceneLoadTraces, diff --git a/src/Sentry.Unity/SentryUnityOptions.cs b/src/Sentry.Unity/SentryUnityOptions.cs index 899398f11..b0038a8a8 100644 --- a/src/Sentry.Unity/SentryUnityOptions.cs +++ b/src/Sentry.Unity/SentryUnityOptions.cs @@ -48,24 +48,29 @@ public sealed class SentryUnityOptions : SentryOptions public bool CaptureInEditor { get; set; } = true; /// - /// Whether Sentry events should be debounced it too frequent. + /// Whether Sentry events should be deduplicated if they occur too frequently. + /// When enabled, duplicate log messages with the same content will be suppressed within the debounce window. /// public bool EnableLogDebouncing { get; set; } = false; /// - /// Timespan between sending events of LogType.Log + /// Time window for deduplicating log messages with identical content. + /// If the same log message appears multiple times within this window, only the first occurrence is captured. /// - public TimeSpan DebounceTimeLog { get; set; } = TimeSpan.FromSeconds(1); + public TimeSpan DebounceTimeWindow { get; set; } = TimeSpan.FromSeconds(1); - /// - /// Timespan between sending events of LogType.Warning - /// - public TimeSpan DebounceTimeWarning { get; set; } = TimeSpan.FromSeconds(1); + private IUnityLogMessageDebounce? _logDebouncer; /// - /// Timespan between sending events of LogType.Assert, LogType.Exception and LogType.Error + /// The debouncer used for deduplicating log messages. + /// Defaults to ContentDebounce which uses content-based hashing. + /// Can be set to a custom implementation for advanced deduplication logic. /// - public TimeSpan DebounceTimeError { get; set; } = TimeSpan.FromSeconds(1); + public IUnityLogMessageDebounce LogDebouncer + { + get => _logDebouncer ??= new ContentDebounce(DebounceTimeWindow); + set => _logDebouncer = value; + } private CompressionLevelWithAuto _requestBodyCompressionLevel = CompressionLevelWithAuto.Auto; diff --git a/src/Sentry.Unity/TimeDebounceBase.cs b/src/Sentry.Unity/TimeDebounceBase.cs deleted file mode 100644 index ba6a6f42c..000000000 --- a/src/Sentry.Unity/TimeDebounceBase.cs +++ /dev/null @@ -1,55 +0,0 @@ -using System; - -namespace Sentry.Unity; - -public interface IUnityLogMessageDebounce -{ - bool Debounced(); -} - -/// -/// This class is not thread-safe and is designed to be called by Unity non-threaded logger callback -/// -internal class TimeDebounceBase : IUnityLogMessageDebounce -{ - private static DateTimeOffset Now => DateTimeOffset.UtcNow; - - protected TimeSpan DebounceOffset; - - private DateTimeOffset? _barrierOffset; - - public bool Debounced() - { - if (_barrierOffset != null && Now < _barrierOffset) - { - return false; - } - - _barrierOffset = Now.Add(DebounceOffset); - return true; - } -} - -/// -/// This class is not thread-safe and is designed to be called by Unity non-threaded logger callback -/// -internal sealed class LogTimeDebounce : TimeDebounceBase -{ - public LogTimeDebounce(TimeSpan debounceOffset) => DebounceOffset = debounceOffset; -} - -/// -/// This class is not thread-safe and is designed to be called by Unity non-threaded logger callback -/// -internal sealed class ErrorTimeDebounce : TimeDebounceBase -{ - public ErrorTimeDebounce(TimeSpan debounceOffset) => DebounceOffset = debounceOffset; -} - -/// -/// This class is not thread-safe and is designed to be called by Unity non-threaded logger callback -/// -internal sealed class WarningTimeDebounce : TimeDebounceBase -{ - public WarningTimeDebounce(TimeSpan debounceOffset) => DebounceOffset = debounceOffset; -} diff --git a/test/Sentry.Unity.Tests/DebouncerTests.cs b/test/Sentry.Unity.Tests/DebouncerTests.cs index 1602e1845..0e974f6dc 100644 --- a/test/Sentry.Unity.Tests/DebouncerTests.cs +++ b/test/Sentry.Unity.Tests/DebouncerTests.cs @@ -7,51 +7,107 @@ namespace Sentry.Unity.Tests; /// -/// Testing debouncer in realtime. +/// Testing content-based debouncer. /// public sealed class DebouncerTests { - private readonly TimeSpan DefaultOffset = TimeSpan.FromMilliseconds(100); + private readonly TimeSpan DefaultWindow = TimeSpan.FromMilliseconds(500); - [UnityTest] - public IEnumerator LogTimeDebounce() + [Test] + public void ContentDebounce_DifferentMessages_AllowsThrough() { - Assert.Inconclusive("Flaky"); // Ignoring because of flakiness: https://github.com/getsentry/sentry-unity/issues/335 - yield return AssertDefaultDebounce(new LogTimeDebounce(DefaultOffset)); + var debouncer = new ContentDebounce(DefaultWindow); + + // First message should pass + Assert.IsTrue(debouncer.Debounced("Error message 1", "Stacktrace 1", LogType.Error)); + + // Different message should pass immediately + Assert.IsTrue(debouncer.Debounced("Error message 2", "Stacktrace 2", LogType.Error)); + + // Another different message should pass + Assert.IsTrue(debouncer.Debounced("Error message 3", "Stacktrace 3", LogType.Error)); } - [UnityTest] - public IEnumerator ErrorTimeDebounce() + [Test] + public void ContentDebounce_SameMessage_BlocksDuplicate() { - Assert.Inconclusive("Flaky"); // Ignoring because of flakiness: https://github.com/getsentry/sentry-unity/issues/335 - yield return AssertDefaultDebounce(new ErrorTimeDebounce(DefaultOffset)); + var debouncer = new ContentDebounce(DefaultWindow); + + // First message should pass + Assert.IsTrue(debouncer.Debounced("Error message", "Stacktrace", LogType.Error)); + + // Same message should be blocked + Assert.IsFalse(debouncer.Debounced("Error message", "Stacktrace", LogType.Error)); + + // Still blocked + Assert.IsFalse(debouncer.Debounced("Error message", "Stacktrace", LogType.Error)); } [UnityTest] - public IEnumerator WarningTimeDebounce() + public IEnumerator ContentDebounce_SameMessage_AllowsAfterWindow() + { + var debouncer = new ContentDebounce(TimeSpan.FromMilliseconds(100)); + + // First message should pass + Assert.IsTrue(debouncer.Debounced("Error message", "Stacktrace", LogType.Error)); + + // Same message immediately blocked + Assert.IsFalse(debouncer.Debounced("Error message", "Stacktrace", LogType.Error)); + + // Wait for debounce window to expire + yield return new WaitForSeconds(0.15f); + + // Same message should now pass + Assert.IsTrue(debouncer.Debounced("Error message", "Stacktrace", LogType.Error)); + } + + [Test] + public void ContentDebounce_DifferentLogTypes_AllowsThrough() { - Assert.Inconclusive("Flaky"); // Ignoring because of flakiness: https://github.com/getsentry/sentry-unity/issues/335 - yield return AssertDefaultDebounce(new WarningTimeDebounce(DefaultOffset)); + var debouncer = new ContentDebounce(DefaultWindow); + + Assert.IsTrue(debouncer.Debounced("Message", "Stack", LogType.Error)); + Assert.IsTrue(debouncer.Debounced("Message", "Stack", LogType.Warning)); + Assert.IsTrue(debouncer.Debounced("Message", "Stack", LogType.Log)); } - private IEnumerator AssertDefaultDebounce(TimeDebounceBase debouncer) + [Test] + public void ContentDebounce_SameMessageDifferentStacktrace_Deduplicates() { - // pass - Assert.IsTrue(debouncer.Debounced()); + var debouncer = new ContentDebounce(DefaultWindow); - yield return new WaitForSeconds(0.050f); + // First occurrence + Assert.IsTrue(debouncer.Debounced("Error occurred", "at Main() line 10", LogType.Error)); - // skip - Assert.IsFalse(debouncer.Debounced()); + // Same message, slightly different stacktrace (but same first line) + Assert.IsFalse(debouncer.Debounced("Error occurred", "at Main() line 10\nat Foo()", LogType.Error)); + } - yield return new WaitForSeconds(0.02f); + [Test] + public void ContentDebounce_DifferentFirstLineOfStacktrace_AllowsThrough() + { + var debouncer = new ContentDebounce(DefaultWindow); + + // First occurrence + Assert.IsTrue(debouncer.Debounced("Error occurred", "at Main() line 10", LogType.Error)); - // skip - Assert.IsFalse(debouncer.Debounced()); + // Same message but different location (different first line of stacktrace) + Assert.IsTrue(debouncer.Debounced("Error occurred", "at Other() line 5", LogType.Error)); + } + + [Test] + public void ContentDebounce_ManyDifferentMessages_HandlesCorrectly() + { + var debouncer = new ContentDebounce(DefaultWindow); - yield return new WaitForSeconds(0.04f); + // Add many different messages + for (int i = 0; i < 100; i++) + { + Assert.IsTrue(debouncer.Debounced($"Error {i}", $"Stack {i}", LogType.Error)); + } - // pass - Assert.IsTrue(debouncer.Debounced()); + // Duplicates of first messages should still be blocked + Assert.IsFalse(debouncer.Debounced("Error 0", "Stack 0", LogType.Error)); + Assert.IsFalse(debouncer.Debounced("Error 50", "Stack 50", LogType.Error)); } }