Integrate Core logging (#3277)

CHANGELOG.md

@@ -50,28 +50,16 @@
 ### Enhancements
 * Added nullability annotations to the Realm assembly. Now methods returning reference types are correctly annotated to indicate whether the returned value may or may not be null. (Issue [#3248](https://github.com/realm/realm-dotnet/issues/3248))
 * Replacing a value at an index (i.e. `myList[1] = someObj`) will now correctly `CollectionChange` notifications with the `Replace` action. (Issue [#2854](https://github.com/realm/realm-dotnet/issues/2854))
+* It is now possible to change the log level at any point of the application's lifetime. (PR [#3277](https://github.com/realm/realm-dotnet/pull/3277))
+* Some log messages have been added to the Core database. Events, such as opening a Realm or committing a transaction will now be logged. (Issue [#2910](https://github.com/realm/realm-dotnet/issues/2910))
 
 ### Fixed
 
-### Compatibility
-* Realm Studio: 12.0.0 or later.
-
-### Internal
-* Using Core x.y.z.
-
-## vNext (TBD)
-
-### Enhancements
-* None
-
-### Fixed
-* None
-
 ### Compatibility
 * Realm Studio: 13.0.0 or later.
 
 ### Internal
-* Using Core x.y.z.
+* Using Core 13.8.0.
 
 ## 10.21.0 (2023-03-24)
 

Realm/Realm/Handles/AppHandle.cs

@@ -22,7 +22,6 @@
 using System.Linq;
 using System.Runtime.InteropServices;
 using System.Threading.Tasks;
-using Realms.Logging;
 using Realms.Native;
 using Realms.Sync.Exceptions;
 using Realms.Sync.Native;
@@ -35,9 +34,6 @@ internal partial class AppHandle : StandaloneHandle
 
         private static class NativeMethods
         {
-            [UnmanagedFunctionPointer(CallingConvention.Cdecl)]
-            public delegate void LogMessageCallback(IntPtr managed_handler, PrimitiveValue messageValue, LogLevel logLevel);
-
             [UnmanagedFunctionPointer(CallingConvention.Cdecl)]
             public delegate void UserCallback(IntPtr tcs_ptr, IntPtr user_ptr, AppError error);
 
@@ -59,7 +55,7 @@ private static class NativeMethods
                 [MarshalAs(UnmanagedType.LPWStr)] string cpu_arch, IntPtr cpu_arch_len,
                 [MarshalAs(UnmanagedType.LPWStr)] string device_name, IntPtr device_name_len,
                 [MarshalAs(UnmanagedType.LPWStr)] string device_version, IntPtr device_version_len,
-                UserCallback user_callback, VoidTaskCallback void_callback, StringCallback string_callback, LogMessageCallback log_message_callback, ApiKeysCallback api_keys_callback);
+                UserCallback user_callback, VoidTaskCallback void_callback, StringCallback string_callback, ApiKeysCallback api_keys_callback);
 
             [DllImport(InteropConfig.DLL_NAME, EntryPoint = "shared_app_create", CallingConvention = CallingConvention.Cdecl)]
             public static extern IntPtr create_app(Native.AppConfiguration app_config, byte[]? encryptionKey, out NativeException ex);
@@ -152,13 +148,11 @@ static AppHandle()
 
         public static void Initialize()
         {
-            NativeMethods.LogMessageCallback logMessage = HandleLogMessage;
             NativeMethods.UserCallback userLogin = HandleUserCallback;
             NativeMethods.VoidTaskCallback taskCallback = HandleTaskCompletion;
             NativeMethods.StringCallback stringCallback = HandleStringCallback;
             NativeMethods.ApiKeysCallback apiKeysCallback = HandleApiKeysCallback;
 
-            GCHandle.Alloc(logMessage);
             GCHandle.Alloc(userLogin);
             GCHandle.Alloc(taskCallback);
             GCHandle.Alloc(stringCallback);
@@ -191,7 +185,7 @@ public static void Initialize()
                 cpuArch, cpuArch.IntPtrLength(),
                 deviceName, deviceName.IntPtrLength(),
                 deviceVersion, deviceVersion.IntPtrLength(),
-                userLogin, taskCallback, stringCallback, logMessage, apiKeysCallback);
+                userLogin, taskCallback, stringCallback, apiKeysCallback);
         }
 
         internal AppHandle(IntPtr handle) : base(handle)
@@ -341,24 +335,7 @@ public SyncUserHandle GetUserForTesting(string id, string refreshToken, string a
 
         protected override void Unbind() => NativeMethods.destroy(handle);
 
-        [MonoPInvokeCallback(typeof(NativeMethods.LogMessageCallback))]
-        private static void HandleLogMessage(IntPtr managedHandler, PrimitiveValue messageValue, LogLevel level)
-        {
-            try
-            {
-                var message = messageValue.AsString();
-                var logger = (Logger)GCHandle.FromIntPtr(managedHandler).Target!;
-                logger.Log(level, message);
-            }
-            catch (Exception ex)
-            {
-                var errorMessage = $"An error occurred while trying to log a message: {ex}";
-                Logger.LogDefault(LogLevel.Error, errorMessage);
-            }
-        }
-
         [MonoPInvokeCallback(typeof(NativeMethods.UserCallback))]
-        [SuppressMessage("Reliability", "CA2000:Dispose objects before losing scope", Justification = "The user will own its handle.")]
         private static void HandleUserCallback(IntPtr tcs_ptr, IntPtr user_ptr, AppError error)
         {
             var tcsHandle = GCHandle.FromIntPtr(tcs_ptr);

Realm/Realm/Handles/SharedRealmHandle.cs

@@ -65,7 +65,7 @@ private static class NativeMethods
             public delegate void DisposeGCHandleCallback(IntPtr handle);
 
             [UnmanagedFunctionPointer(CallingConvention.Cdecl)]
-            public delegate void LogMessageCallback(PrimitiveValue message, LogLevel level);
+            public delegate void LogMessageCallback(StringValue message, LogLevel level);
 
             [UnmanagedFunctionPointer(CallingConvention.Cdecl)]
             public delegate void HandleTaskCompletionCallback(IntPtr tcs_ptr, [MarshalAs(UnmanagedType.U1)] bool invoke_async, NativeException ex);
@@ -234,6 +234,9 @@ private static class NativeMethods
             [DllImport(InteropConfig.DLL_NAME, EntryPoint = "shared_realm_refresh_async", CallingConvention = CallingConvention.Cdecl)]
             public static extern bool refresh_async(SharedRealmHandle realm, IntPtr tcs_handle, out NativeException ex);
 
+            [DllImport(InteropConfig.DLL_NAME, EntryPoint = "shared_realm_set_log_level", CallingConvention = CallingConvention.Cdecl)]
+            public static extern bool set_log_level(LogLevel level);
+
 #pragma warning restore SA1121 // Use built-in type alias
 #pragma warning restore IDE0049 // Use built-in type alias
         }
@@ -272,6 +275,8 @@ public static void Initialize()
             NativeMethods.install_callbacks(notifyRealm, getNativeSchema, openRealm, disposeGCHandle, logMessage, notifyObject, notifyDictionary, onMigration, shouldCompact, handleTaskCompletion, onInitialization);
         }
 
+        public static void SetLogLevel(LogLevel level) => NativeMethods.set_log_level(level);
+
         [Preserve]
         public SharedRealmHandle(IntPtr handle) : base(handle)
         {
@@ -765,7 +770,6 @@ public static void NotifyRealmChanged(IntPtr stateHandle)
         }
 
         [MonoPInvokeCallback(typeof(NativeMethods.OpenRealmCallback))]
-        [SuppressMessage("Reliability", "CA2000:Dispose objects before losing scope", Justification = "Realm will be owned by the creator of the tcs")]
         private static void HandleOpenRealmCallback(IntPtr taskCompletionSource, IntPtr realm_reference, NativeException ex)
         {
             var handleTcs = GCHandle.FromIntPtr(taskCompletionSource);
@@ -793,9 +797,9 @@ public static void DisposeGCHandleCallback(IntPtr handle)
         }
 
         [MonoPInvokeCallback(typeof(NativeMethods.LogMessageCallback))]
-        private static void LogMessage(PrimitiveValue message, LogLevel level)
+        private static void LogMessage(StringValue message, LogLevel level)
         {
-            Logger.LogDefault(level, message.AsString());
+            Logger.LogDefault(level, message!);
         }
 
         [MonoPInvokeCallback(typeof(NativeMethods.MigrationCallback))]

Realm/Realm/Logging/LogLevel.cs

@@ -28,49 +28,49 @@ public enum LogLevel
         /// Log everything. This will seriously harm the performance of the
         /// sync client and should never be used in production scenarios.
         /// </summary>
-        All,
+        All = 0,
 
         /// <summary>
         /// A version of 'debug' that allows for very high volume output.
         /// This may seriously affect the performance of the sync client.
         /// </summary>
-        Trace,
+        Trace = 1,
 
         /// <summary>
         /// Reveal information that can aid debugging, no longer paying
         /// attention to efficiency.
         /// </summary>
-        Debug,
+        Debug = 2,
 
         /// <summary>
         /// Same as 'Info', but prioritize completeness over minimalism.
         /// </summary>
-        Detail,
+        Detail = 3,
 
         /// <summary>
         /// Log operational sync client messages, but in a minimalistic fashion to
         /// avoid general overhead from logging and to keep volume down.
         /// </summary>
-        Info,
+        Info = 4,
 
         /// <summary>
         /// Log errors and warnings.
         /// </summary>
-        Warn,
+        Warn = 5,
 
         /// <summary>
         /// Log errors only.
         /// </summary>
-        Error,
+        Error = 6,
 
         /// <summary>
         /// Log only fatal errors.
         /// </summary>
-        Fatal,
+        Fatal = 7,
 
         /// <summary>
         /// Log nothing.
         /// </summary>
-        Off
+        Off = 8,
     }
 }

Realm/Realm/Logging/Logger.cs

@@ -36,6 +36,7 @@ public abstract class Logger
         private readonly Lazy<GCHandle> _gcHandle;
 
         private static Logger? _defaultLogger;
+        private static LogLevel _logLevel = LogLevel.Info;
 
         /// <summary>
         /// Gets a <see cref="ConsoleLogger"/> that outputs messages to the default console. For most project types, that will be
@@ -86,7 +87,15 @@ public abstract class Logger
         /// Gets or sets the verbosity of log messages.
         /// </summary>
         /// <value>The log level for Realm-originating messages.</value>
-        public static LogLevel LogLevel { get; set; } = LogLevel.Info;
+        public static LogLevel LogLevel
+        {
+            get => _logLevel;
+            set
+            {
+                _logLevel = value;
+                SharedRealmHandle.SetLogLevel(value);
+            }
+        }
 
         /// <summary>
         /// Gets or sets a custom <see cref="Logger"/> implementation that will be used by

Realm/Realm/Native/AppConfiguration.cs

@@ -18,7 +18,6 @@
 
 using System;
 using System.Runtime.InteropServices;
-using Realms.Logging;
 
 namespace Realms.Sync.Native
 {
@@ -106,10 +105,6 @@ internal string BaseUrl
             }
         }
 
-        internal LogLevel log_level;
-
-        internal IntPtr managed_logger;
-
         internal IntPtr managed_http_client;
 
         internal UInt64 sync_connect_timeout_ms;

Realm/Realm/Sync/App.cs

@@ -23,7 +23,6 @@
 using System.Runtime.InteropServices;
 using System.Threading.Tasks;
 using Realms.Helpers;
-using Realms.Logging;
 
 namespace Realms.Sync
 {
@@ -110,7 +109,6 @@ public class App
         /// Gets the currently user. If none exists, null is returned.
         /// </summary>
         /// <value>Valid user or <c>null</c> to indicate nobody logged in.</value>
-        [SuppressMessage("Reliability", "CA2000:Dispose objects before losing scope", Justification = "The User instance will own its handle.")]
         public User? CurrentUser => Handle.TryGetCurrentUser(out var userHandle) ? new User(userHandle, this) : null;
 
         /// <summary>
@@ -167,7 +165,6 @@ public static App Create(AppConfiguration config)
                 sync_fast_reconnect_limit = (ulong)syncTimeouts.FastReconnectLimit.TotalMilliseconds,
                 sync_ping_keep_alive_period_ms = (ulong)syncTimeouts.PingKeepAlivePeriod.TotalMilliseconds,
                 sync_pong_keep_alive_timeout_ms = (ulong)syncTimeouts.PongKeepAliveTimeout.TotalMilliseconds,
-                managed_logger = Logger.Default != null ? GCHandle.ToIntPtr(Logger.Default.GCHandle) : IntPtr.Zero,
             };
 
             var handle = AppHandle.CreateApp(nativeConfig, config.MetadataEncryptionKey);

Tests/Realm.Tests/Database/GuidRepresentationMigrationTests.cs

@@ -83,7 +83,7 @@ public void Migration_FromLittleEndianGuidFile([Values(true, false)] bool useLeg
 
             if (useLegacyRepresentation)
             {
-                Assert.That(logger.GetLog(), Is.Empty);
+                Assert.That(logger.GetLog(), Does.Not.Contain("Guid"));
             }
             else
             {
@@ -123,7 +123,7 @@ public void PopulatingANewFile([Values(true, false)] bool useLegacyRepresentatio
                 Assert.That(actualObj, Is.EqualTo(actualFound));
             }
 
-            Assert.That(logger.GetLog(), Is.Empty);
+            Assert.That(logger.GetLog(), Does.Not.Contain("Guid"));
         }
 
         [Test]
@@ -200,7 +200,7 @@ public void UnmigratedRealm_WhenOpenedAsReadonly_LogsAMessageAndDoesntChangeFile
                 Assert.That(realm.Find<GuidType>(flippedId), Is.EqualTo(actualObj));
             }
 
-            Assert.That(logger.GetLog(), Does.Contain("may contain legacy guid values but is opened as readonly so it cannot be migrated"));
+            Assert.That(logger.GetLog(), Does.Contain("may contain legacy Guid values but is opened as readonly so it cannot be migrated"));
         }
 
         [Test]
@@ -235,7 +235,7 @@ public void MigratedRealm_WhenOpenedAsReadonly_DoesntDoAnything()
                 Assert.That(actualObj, Is.EqualTo(actualFound));
             }
 
-            Assert.That(logger.GetLog(), Is.Empty);
+            Assert.That(logger.GetLog(), Does.Not.Contain("Guid"));
         }
 
         [Test]

Tests/Realm.Tests/Database/InstanceTests.cs

@@ -23,9 +23,11 @@
 using System.Linq;
 using System.Reflection;
 using System.Runtime.InteropServices;
+using System.Text.RegularExpressions;
 using System.Threading.Tasks;
 using NUnit.Framework;
 using Realms.Exceptions;
+using Realms.Logging;
 using Realms.Schema;
 #if TEST_WEAVER
 using TestRealmObject = Realms.RealmObject;
@@ -1267,6 +1269,51 @@ public void RealmDispose_DisposesActiveTransaction()
             Assert.That(ts.State, Is.EqualTo(TransactionState.RolledBack));
         }
 
+        [Test]
+        public void Logger_ChangeLevel_ReflectedImmediately()
+        {
+            var logger = new Logger.InMemoryLogger();
+            Logger.Default = logger;
+
+            using var realm = GetRealm(Guid.NewGuid().ToString());
+
+            var expectedLog = new Regex("Info: DB: [^ ]* Thread [^ ]*: Open file");
+            TestHelpers.AssertRegex(logger.GetLog(), expectedLog);
+            Assert.That(logger.GetLog(), Does.Not.Contain("Debug"));
+
+            // We're at info level, so we don't expect any statements.
+            WriteAndVerifyLogs();
+
+            Logger.LogLevel = LogLevel.Debug;
+
+            // We're at Debug level now, so we should see the write message.
+            var expectedWriteLog = new Regex("Debug: DB: .* Commit of size [^ ]* done in [^ ]* us");
+            WriteAndVerifyLogs(expectedWriteLog);
+
+            // Revert back to Info level and make sure we don't log anything
+            Logger.LogLevel = LogLevel.Info;
+            WriteAndVerifyLogs();
+
+            void WriteAndVerifyLogs(Regex? expectedRegex = null)
+            {
+                logger.Clear();
+
+                realm.Write(() =>
+                {
+                    realm.Add(new IntPropertyObject());
+                });
+
+                if (expectedRegex == null)
+                {
+                    Assert.That(logger.GetLog(), Is.Empty);
+                }
+                else
+                {
+                    TestHelpers.AssertRegex(logger.GetLog(), expectedRegex);
+                }
+            }
+        }
+
         private const int DummyDataSize = 200;
 
         private static void AddDummyData(Realm realm)

Tests/Realm.Tests/Generated/Realm.SourceGenerator/Realms.SourceGenerator.RealmGenerator/LoneClass_generated.cs

@@ -4,6 +4,7 @@
 using NUnit.Framework;
 using Realms;
 using Realms.Exceptions;
+using Realms.Logging;
 using Realms.Schema;
 using Realms.Tests.Database;
 using Realms.Weaving;
@@ -17,6 +18,7 @@
 using System.Runtime.CompilerServices;
 using System.Runtime.InteropServices;
 using System.Runtime.Serialization;
+using System.Text.RegularExpressions;
 using System.Threading.Tasks;
 using System.Xml.Serialization;
 using TestRealmObject = Realms.IRealmObject;