Skip to content

Commit

Permalink
fix: Logging integration captures tags and messages (#1150)
Browse files Browse the repository at this point in the history
  • Loading branch information
@bitsandfoxes
bitsandfoxes committed Jan 27, 2023
1 parent d33a7de commit 9c6b146
Show file tree
Hide file tree
Showing 14 changed files with 204 additions and 140 deletions.
4 changes: 4 additions & 0 deletions CHANGELOG.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,10 @@

## Unreleased

### Fixes

- Fixed the logging integration only capturing tags and missing the message ([#1150](https://github.com/getsentry/sentry-unity/pull/1150))

### Dependencies

- Bump Native SDK from v0.5.3 to v0.5.4 ([#1157](https://github.com/getsentry/sentry-unity/pull/1157))
Expand Down
4 changes: 2 additions & 2 deletions src/Sentry.Unity.Android/SentryJava.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -151,8 +151,8 @@ public ScopeCallback(Action<AndroidJavaObject> callback) : base("io.sentry.Scope
}
catch (Exception e)
{
// Adding the Sentry logger prefix ensures we don't send this error to Sentry.
UnityEngine.Debug.LogError($"{UnityLogger.LogPrefix}Error in SentryJava.ScopeCallback: {e}");
// Adding the Sentry logger tag ensures we don't send this error to Sentry.
Debug.unityLogger.Log(LogType.Error, UnityLogger.LogTag, $"Error in SentryJava.ScopeCallback: {e}");
}
return null;
}
Expand Down
4 changes: 2 additions & 2 deletions src/Sentry.Unity.Editor/Android/AndroidManifestConfiguration.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,10 +37,10 @@ public AndroidManifestConfiguration()
Func<(SentryUnityOptions?, SentryCliOptions?)> getOptions,
bool isDevelopmentBuild,
ScriptingImplementation scriptingImplementation,
IUnityLoggerInterceptor? interceptor = null)
ILogger? logger = null)
{
(_options, _sentryCliOptions) = getOptions();
_logger = _options?.DiagnosticLogger ?? new UnityLogger(_options ?? new SentryUnityOptions(), interceptor);
_logger = _options?.DiagnosticLogger ?? new UnityLogger(_options ?? new SentryUnityOptions(), logger);

_isDevelopmentBuild = isDevelopmentBuild;
_scriptingImplementation = scriptingImplementation;
Expand Down
19 changes: 4 additions & 15 deletions src/Sentry.Unity/Integrations/UnityLogHandlerIntegration.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -91,24 +91,12 @@ internal void CaptureLogFormat(LogType logType, UnityEngine.Object? context, str
return;
}

// TODO: Is format '{0}' and args.length == 1 guaranteed?
if (args.Length == 0 || !format.Contains("{0}"))
// The SDK sets "Sentry" as tag when logging and we're not capturing SDK internal logs. Expected format: "{0}: {1}"
if (args.Length > 1 && args[0].Equals("Sentry"))
{
return;
}

if (args[0] is not string logMessage)
{
return;
}

// We're not capturing SDK internal logs
if (logMessage.StartsWith(UnityLogger.LogPrefix, StringComparison.Ordinal))
{
// TODO: Maybe color Sentry internal logs (highlight 'Sentry'?)
return;
}

if (_sentryOptions?.EnableLogDebouncing is true)
{
var debounced = logType switch
Expand All @@ -125,10 +113,11 @@ internal void CaptureLogFormat(LogType logType, UnityEngine.Object? context, str
}
}

// TODO: Capture the context (i.e. grab the name if != null and set it as context)
var logMessage = args.Length == 0 ? format : string.Format(format, args);

if (logType is LogType.Error or LogType.Assert)
{
// TODO: Capture the context (i.e. grab the name if != null and set it as context)
_hub.CaptureMessage(logMessage, ToEventTagType(logType));
}

Expand Down
5 changes: 3 additions & 2 deletions src/Sentry.Unity/NativeUtils/CFunctions.cs
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
using System;
using System.Collections.Generic;
using System.Runtime.InteropServices;
using UnityEngine;

namespace Sentry.Unity.NativeUtils
{
Expand Down Expand Up @@ -189,8 +190,8 @@ private static IEnumerable<DebugImage> LoadDebugImages()
}
catch (Exception e)
{
// Adding the Sentry logger prefix ensures we don't send this error to Sentry.
UnityEngine.Debug.LogError($"{UnityLogger.LogPrefix}Error loading the list of debug images: {e}");
// Adding the Sentry logger tag ensures we don't send this error to Sentry.
Debug.unityLogger.Log(LogType.Error, UnityLogger.LogTag, $"Error loading the list of debug images: {e}");
}
return result;
}
Expand Down
43 changes: 14 additions & 29 deletions src/Sentry.Unity/UnityLogger.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,27 +5,22 @@

namespace Sentry.Unity
{
internal interface IUnityLoggerInterceptor
{
void Intercept(SentryLevel logLevel, string logMessage);
}

public class UnityLogger : IDiagnosticLogger
{
public const string LogPrefix = "Sentry: ";
public const string LogTag = "Sentry";

private readonly SentryOptions _sentryOptions;
private readonly IUnityLoggerInterceptor? _interceptor;
private readonly ILogger _logger;

public bool IsEnabled(SentryLevel level) => level >= _sentryOptions.DiagnosticLevel;

public UnityLogger(SentryUnityOptions sentryUnityOptions) : this(sentryUnityOptions, null)
{ }

internal UnityLogger(SentryOptions sentryOptions, IUnityLoggerInterceptor? interceptor = null)
internal UnityLogger(SentryOptions sentryOptions, ILogger? logger = null)
{
_sentryOptions = sentryOptions;
_interceptor = interceptor;
_logger = logger ?? Debug.unityLogger;
}

public void Log(SentryLevel logLevel, string? message, Exception? exception = null, params object?[] args)
Expand All @@ -35,28 +30,18 @@ public void Log(SentryLevel logLevel, string? message, Exception? exception = nu
return;
}

switch (logLevel)
{
case SentryLevel.Debug or SentryLevel.Info:
Debug.Log(GetLog());
break;
case SentryLevel.Warning:
Debug.LogWarning(GetLog());
break;
case SentryLevel.Error or SentryLevel.Fatal:
Debug.LogError(GetLog());
break;
default:
Debug.Log(GetLog());
break;
}
_logger.Log(GetUnityLogType(logLevel), LogTag, $"({logLevel.ToString()}) {Format(message, args)} {exception}");
}

string GetLog()
internal static LogType GetUnityLogType(SentryLevel logLevel)
{
return logLevel switch
{
var log = $"{LogPrefix}({logLevel}) {Format(message, args)} {exception}";
_interceptor?.Intercept(logLevel, log);
return log;
}
SentryLevel.Debug or SentryLevel.Info => LogType.Log,
SentryLevel.Warning => LogType.Warning,
SentryLevel.Error or SentryLevel.Fatal => LogType.Error,
_ => LogType.Log
};
}

public override string ToString() => nameof(UnityLogger);
Expand Down
4 changes: 2 additions & 2 deletions test/Scripts.Integration.Test/Scripts/SmokeTester.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -236,10 +236,10 @@ protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage reques
private void Receive(HttpRequestMessage message)
{
var msgText = message.Content.ReadAsStringAsync().Result;
// Adding "Sentry: " prefix to prevent the UnityLogHandlerIntegration from capturing this message and
// Setting "Sentry" as tag to prevent the UnityLogHandlerIntegration from capturing this message and
// adding it as a breadcrumb, which in turn multiplies it on following (intercepted) HTTP requests...
// Note: remove the prefix once setting breadcrumb log level is possible - https://github.com/getsentry/sentry-unity/issues/60
Debug.Log($"Sentry: {_name} TEST: Intercepted HTTP Request #{_requests.Count} = {msgText}");
Debug.unityLogger.Log(LogType.Log, "Sentry", $"{_name} TEST: Intercepted HTTP Request #{_requests.Count} = {msgText}");
_requests.Enqueue(msgText);
_requestReceived.Set();
}
Expand Down
35 changes: 18 additions & 17 deletions test/Sentry.Unity.Editor.Tests/Android/AndroidManifestConfigurationTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
using System.Reflection;
using NUnit.Framework;
using Sentry.Unity.Editor.Android;
using Sentry.Unity.Tests.SharedClasses;
using UnityEditor;
using UnityEngine;

Expand All @@ -14,13 +15,13 @@ private class Fixture
{
public SentryUnityOptions? SentryUnityOptions { get; set; }
public SentryCliOptions? SentryCliOptions { get; set; }
public TestUnityLoggerInterceptor LoggerInterceptor { get; set; }
public UnityTestLogger UnityTestLogger { get; set; }
public bool IsDevelopmentBuild { get; set; }
public ScriptingImplementation ScriptingImplementation { get; set; } = ScriptingImplementation.IL2CPP;

public Fixture()
{
LoggerInterceptor = new();
UnityTestLogger = new();
// Options configured to initialize the Android SDK, tests will change from there:
SentryUnityOptions = new()
{
Expand All @@ -29,7 +30,7 @@ public Fixture()
AndroidNativeSupportEnabled = true,
Debug = true
};
SentryUnityOptions.DiagnosticLogger = new UnityLogger(SentryUnityOptions, LoggerInterceptor);
SentryUnityOptions.DiagnosticLogger = new UnityLogger(SentryUnityOptions, UnityTestLogger);

SentryCliOptions = ScriptableObject.CreateInstance<SentryCliOptions>();
SentryCliOptions.Auth = "test_auth_token";
Expand All @@ -41,7 +42,7 @@ public Fixture()
new(() => (SentryUnityOptions, SentryCliOptions),
IsDevelopmentBuild,
ScriptingImplementation,
LoggerInterceptor);
UnityTestLogger);
}

[SetUp]
Expand Down Expand Up @@ -71,7 +72,7 @@ public void ModifyManifest_LoadSentryUnityOptions_NullOptions_LogWarningAndDisab
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(
_fixture.UnityTestLogger.AssertLogContains(
SentryLevel.Warning,
"Android native support disabled because Sentry has not been configured. " +
"You can do that through the editor: Tools -> Sentry");
Expand All @@ -88,7 +89,7 @@ public void ModifyManifest_UnityOptions_EnabledFalse_LogDebugAndDisableInit()
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, "Sentry SDK has been disabled.\nYou can disable this log by raising the debug verbosity level above 'Debug'.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, "Sentry SDK has been disabled.\nYou can disable this log by raising the debug verbosity level above 'Debug'.");

Assert.True(manifest.Contains(
"<meta-data android:name=\"io.sentry.auto-init\" android:value=\"false\" />"),
Expand All @@ -105,7 +106,7 @@ public void ModifyManifest_UnityOptions_EnabledWithoutDsn_LogWarningAndDisableIn
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Warning, "No Sentry DSN configured. Sentry will be disabled.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Warning, "No Sentry DSN configured. Sentry will be disabled.");

Assert.True(manifest.Contains(
"<meta-data android:name=\"io.sentry.auto-init\" android:value=\"false\" />"),
Expand All @@ -119,7 +120,7 @@ public void ModifyManifest_UnityOptions_AndroidNativeSupportEnabledFalse_LogDebu
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, "Android native support disabled through the options.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, "Android native support disabled through the options.");

Assert.True(manifest.Contains(
"<meta-data android:name=\"io.sentry.auto-init\" android:value=\"false\" />"),
Expand All @@ -133,7 +134,7 @@ public void ModifyManifest_ManifestHasDsn()
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, $"Setting DSN: {expected}");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, $"Setting DSN: {expected}");

Assert.True(manifest.Contains(
$"<meta-data android:name=\"io.sentry.dsn\" android:value=\"{expected}\" />"),
Expand All @@ -160,7 +161,7 @@ public void ModifyManifest_ReleaseIsNotNull_SetRelease()
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, $"Setting Release: {expected}");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, $"Setting Release: {expected}");

Assert.True(manifest.Contains(
$"<meta-data android:name=\"io.sentry.release\" android:value=\"{expected}\" />"),
Expand All @@ -187,7 +188,7 @@ public void ModifyManifest_EnvironmentIsNotNull_SetEnvironment()
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, $"Setting Environment: {expected}");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, $"Setting Environment: {expected}");

Assert.True(manifest.Contains(
$"<meta-data android:name=\"io.sentry.environment\" android:value=\"{expected}\" />"),
Expand Down Expand Up @@ -217,7 +218,7 @@ public void ModifyManifest_EnvironmentIsNotNull_SetEnvironment()
// Debug message is only logged if level is Debug:
if (levels.SentryLevel == SentryLevel.Debug)
{
_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, $"Setting DiagnosticLevel: {levels.SentryLevel}");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, $"Setting DiagnosticLevel: {levels.SentryLevel}");
}

Assert.True(manifest.Contains(
Expand All @@ -233,7 +234,7 @@ public void ModifyManifest_SampleRate_SetIfNotNull()
var sut = _fixture.GetSut();
var manifest = WithAndroidManifest(basePath => sut.ModifyManifest(basePath));

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, $"Setting SampleRate: {expected}");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, $"Setting SampleRate: {expected}");

Assert.True(manifest.Contains(
$"<meta-data android:name=\"io.sentry.sample-rate\" android:value=\"{expected}\" />"),
Expand Down Expand Up @@ -284,7 +285,7 @@ public void SetupSymbolsUpload_SentryCliOptionsNull_LogsWarningAndReturns()

sut.SetupSymbolsUpload(dsuFixture.UnityProjectPath, dsuFixture.GradleProjectPath);

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Warning, "Failed to load sentry-cli options.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Warning, "Failed to load sentry-cli options.");

Directory.Delete(Path.GetFullPath(dsuFixture.FakeProjectPath), true);
}
Expand All @@ -300,7 +301,7 @@ public void SetupSymbolsUpload_SymbolsUploadDisabled_LogsAndReturns()

sut.SetupSymbolsUpload(dsuFixture.UnityProjectPath, dsuFixture.GradleProjectPath);

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, "Automated symbols upload has been disabled.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, "Automated symbols upload has been disabled.");

Directory.Delete(Path.GetFullPath(dsuFixture.FakeProjectPath), true);
}
Expand All @@ -316,7 +317,7 @@ public void SetupSymbolsUpload_DevelopmentBuildDevUploadDisabled_LogsAndReturns(

sut.SetupSymbolsUpload(dsuFixture.UnityProjectPath, dsuFixture.GradleProjectPath);

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, "Automated symbols upload for development builds has been disabled.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, "Automated symbols upload for development builds has been disabled.");

Directory.Delete(Path.GetFullPath(dsuFixture.FakeProjectPath), true);
}
Expand All @@ -332,7 +333,7 @@ public void SetupSymbolsUpload_SentryCliOptionsInvalid_LogsAndReturns()

sut.SetupSymbolsUpload(dsuFixture.UnityProjectPath, dsuFixture.GradleProjectPath);

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Warning, "sentry-cli validation failed. Symbols will not be uploaded." +
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Warning, "sentry-cli validation failed. Symbols will not be uploaded." +
"\nYou can disable this warning by disabling the automated symbols upload under " +
SentryCliOptions.EditorMenuPath);

Expand Down
11 changes: 6 additions & 5 deletions test/Sentry.Unity.Editor.Tests/Android/DebugSymbolUploadTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using System.Reflection;
using NUnit.Framework;
using Sentry.Unity.Editor.Android;
using Sentry.Unity.Tests.SharedClasses;
using Sentry.Unity.Tests.Stubs;
using UnityEditor;

Expand All @@ -13,7 +14,7 @@ public class DebugSymbolUploadTests
{
public class Fixture
{
internal TestUnityLoggerInterceptor LoggerInterceptor { get; set; }
internal UnityTestLogger UnityTestLogger { get; set; }
public string FakeProjectPath { get; set; }
public string UnityProjectPath { get; set; }
public string GradleProjectPath { get; set; }
Expand All @@ -24,7 +25,7 @@ public class Fixture

public Fixture()
{
LoggerInterceptor = new();
UnityTestLogger = new();

FakeProjectPath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString());

Expand All @@ -35,7 +36,7 @@ public Fixture()
Application = new TestApplication(unityVersion: "2019.4");
}

internal DebugSymbolUpload GetSut() => new(new UnityLogger(new SentryOptions(), LoggerInterceptor),
internal DebugSymbolUpload GetSut() => new(new UnityLogger(new SentryOptions(), UnityTestLogger),
null, UnityProjectPath, GradleProjectPath, ScriptingImplementation.IL2CPP, IsExporting, Application);
}

Expand Down Expand Up @@ -148,7 +149,7 @@ public void RemoveUploadTaskFromGradleFile_UploadHasNotBeenAdded_LogsAndReturns(

sut.RemoveUploadFromGradleFile();

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug, "No previous upload task found.");
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug, "No previous upload task found.");
}

[Test]
Expand Down Expand Up @@ -176,7 +177,7 @@ public void TryCopySymbolsToGradleProject_IsNewBuildingBackend_LogsAndReturns()

sut.TryCopySymbolsToGradleProject(_fixture.Application);

_fixture.LoggerInterceptor.AssertLogContains(SentryLevel.Debug,
_fixture.UnityTestLogger.AssertLogContains(SentryLevel.Debug,
"New building backend. Skipping copying of debug symbols.");
}

Expand Down
Loading

0 comments on commit 9c6b146

Please sign in to comment.