Implemented native logging through serilog instead of directly to stdout

JKMP.Plugin.Multiplayer/MultiplayerPlugin.cs

@@ -16,6 +16,7 @@
 using JKMP.Plugin.Multiplayer.Game.Events;
 using JKMP.Plugin.Multiplayer.Game.UI;
 using JKMP.Plugin.Multiplayer.Matchmaking;
+using JKMP.Plugin.Multiplayer.Native;
 using JKMP.Plugin.Multiplayer.Native.Audio;
 using JKMP.Plugin.Multiplayer.Networking;
 using JKMP.Plugin.Multiplayer.Steam;
@@ -48,6 +49,7 @@ public class MultiplayerPlugin : Core.Plugins.Plugin
         public MultiplayerPlugin()
         {
             Instance = this;
+            Logging.Initialize();
         }
 
         public override void OnLoaded()

native/Multiplayer.Native/Bindings.cs

@@ -232,6 +232,10 @@ public static int opus_context_decompress(IntPtr context, byte[] data, short[] o
             }
         }
 
+        [DllImport(NativeLib, CallingConvention = CallingConvention.Cdecl, EntryPoint = "initialize_logging")]
+        public static extern bool initialize_logging(OnLogCallback on_log);
+
+
     }
 
     public enum CaptureError
@@ -240,6 +244,16 @@ public enum CaptureError
         BackendSpecific = 1,
     }
 
+    public enum LogLevel
+    {
+        Verbose = 0,
+        Debug = 1,
+        Info = 2,
+        Warning = 3,
+        Error = 4,
+        Fatal = 5,
+    }
+
     [Serializable]
     [StructLayout(LayoutKind.Sequential)]
     public partial struct DeviceConfig
@@ -734,6 +748,9 @@ IEnumerator IEnumerable.GetEnumerator()
     [UnmanagedFunctionPointer(CallingConvention.Cdecl)]
     public delegate void OnCapturedDataCallback(Slicei16 x0, float x1);
 
+    [UnmanagedFunctionPointer(CallingConvention.Cdecl)]
+    public delegate void OnLogCallback(LogLevel x0, Sliceu8 x1);
+
 
     public partial class AudioContext : IDisposable
     {

native/Multiplayer.Native/Logging.cs

@@ -0,0 +1,45 @@
+using System;
+using System.Text;
+using Serilog;
+using Serilog.Events;
+
+namespace JKMP.Plugin.Multiplayer.Native
+{
+    public static class Logging
+    {
+        private static readonly OnLogCallback OnLogCallback;
+
+        static Logging()
+        {
+            // We need a reference to the callback to be able to call it from native code
+            // If passed directly to the native function, it will be garbage collected
+            OnLogCallback = OnLog;
+        }
+
+        public static void Initialize()
+        {
+            Bindings.initialize_logging(OnLogCallback);
+        }
+
+        private static void OnLog(LogLevel logLevel, Sliceu8 utf8Message)
+        {
+            string message;
+
+            unsafe
+            {
+                fixed (byte* messagePtr = &utf8Message.ReadOnlySpan.GetPinnableReference())
+                {
+                    message = Encoding.UTF8.GetString(messagePtr, utf8Message.Count);
+                }
+            }
+
+            var logEventLevel = (LogEventLevel)logLevel;
+            NativeLog.Logger.Write(logEventLevel, (Exception?)null, "{nativeMessage}", message);
+        }
+    }
+
+    internal static class NativeLog
+    {
+        public static readonly ILogger Logger = Log.Logger.ForContext(typeof(NativeLog));
+    }
+}

native/Multiplayer.Native/Multiplayer.Native.csproj

@@ -16,6 +16,7 @@
   </ItemGroup>
 
   <ItemGroup>
+    <PackageReference Include="Serilog" Version="2.10.0" />
     <PackageReference Include="System.Memory" Version="4.5.4" />
   </ItemGroup>
 

native/multiplayer_native/Cargo.toml

@@ -15,4 +15,5 @@ cpal = "0.13.5"
 audiopus = "0.3.0-rc.0"
 anyhow = "1.0.53"
 samplerate = "0.2.4"
-ringbuffer = "0.8.2"
+ringbuffer = "0.8.2"
+log = { version = "0.4.14", features = ["std"] }

native/multiplayer_native/src/audio_capture/capture_context.rs

@@ -353,7 +353,7 @@ impl AudioContext {
 
         self.active_device = device;
 
-        println!("Active device set to {:?}, {:?}", device_name, config);
+        log::trace!("Active device set to {:?}, {:?}", device_name, config);
         Ok(())
     }
 

native/multiplayer_native/src/audio_capture/opus_context.rs

@@ -44,7 +44,7 @@ impl OpusContext {
                 return len as i32;
             }
             Err(err) => {
-                println!("Failed to encode: {:?}", err);
+                log::warn!("Failed to encode: {:?}", err);
             }
         }
 
@@ -79,7 +79,7 @@ impl OpusContext {
                 return len as i32;
             }
             Err(err) => {
-                println!("Failed to decode: {:?}", err);
+                log::warn!("Failed to decode: {:?}", err);
             }
         }
 

native/multiplayer_native/src/lib.rs

@@ -4,10 +4,11 @@ use audio_capture::capture_context::AudioContext;
 use audio_capture::opus_context::OpusContext;
 
 use interoptopus::{
-    ffi_type, pattern, patterns::result::FFIError, Error, Inventory, InventoryBuilder,
+    ffi_type, function, pattern, patterns::result::FFIError, Error, Inventory, InventoryBuilder,
 };
 
 pub mod audio_capture;
+pub mod logging;
 
 #[ffi_type(patterns(ffi_error))]
 #[repr(C)]
@@ -78,5 +79,6 @@ pub fn ffi_inventory() -> Inventory {
     InventoryBuilder::new()
         .register(pattern!(AudioContext))
         .register(pattern!(OpusContext))
+        .register(function!(logging::initialize_logging))
         .inventory()
 }

native/multiplayer_native/src/logging.rs

@@ -0,0 +1,55 @@
+use interoptopus::patterns::slice::FFISlice;
+use interoptopus::{callback, ffi_function, ffi_type};
+use log::{LevelFilter, Metadata, Record};
+
+// Note that this enum needs to match serilog's enum, otherwise casting will not work correctly
+#[repr(C)]
+#[ffi_type]
+pub enum LogLevel {
+    Verbose,
+    Debug,
+    Info,
+    Warning,
+    Error,
+    Fatal,
+}
+
+callback!(OnLogCallback(log_level: LogLevel, message: FFISlice<u8>));
+
+#[ffi_function]
+#[no_mangle]
+pub extern "C" fn initialize_logging(on_log: OnLogCallback) -> bool {
+    log::set_boxed_logger(Box::new(CallbackLogger {
+        on_log_callback: on_log,
+    }))
+    .map(|()| log::set_max_level(LevelFilter::Trace))
+    .is_ok()
+}
+
+struct CallbackLogger {
+    on_log_callback: OnLogCallback,
+}
+
+impl log::Log for CallbackLogger {
+    fn enabled(&self, _: &Metadata) -> bool {
+        true
+    }
+
+    fn log(&self, record: &Record) {
+        let log_level = match record.level() {
+            log::Level::Error => LogLevel::Error,
+            log::Level::Warn => LogLevel::Warning,
+            log::Level::Info => LogLevel::Info,
+            log::Level::Debug => LogLevel::Debug,
+            log::Level::Trace => LogLevel::Verbose,
+        };
+        let mut message = String::new();
+
+        message.push_str(format!("{}", record.args()).as_str());
+
+        self.on_log_callback
+            .call(log_level, message.as_bytes().into());
+    }
+
+    fn flush(&self) {}
+}