Added logs for lib loading (#236)

sandrohanea · Oct 27, 2024 · 146f50c · 146f50c
1 parent f896b88
commit 146f50c
Show file tree

Hide file tree

Showing 4 changed files with 47 additions and 6 deletions.
diff --git a/Whisper.net/LibraryLoader/CudaHelper.cs b/Whisper.net/LibraryLoader/CudaHelper.cs
@@ -3,12 +3,14 @@
 using System.Runtime.InteropServices;
 using Whisper.net.Internals.Native;
 using Whisper.net.Internals.Native.Implementations.Cuda;
+using Whisper.net.Logger;
 
 namespace Whisper.net.LibraryLoader;
 internal static class CudaHelper
 {
     public static bool IsCudaAvailable()
     {
+        LogProvider.Log(WhisperLogLevel.Debug, "Checking for CUDA availability.");
         INativeCuda? nativeCuda = null;
         var cudaDevices = 0;
         try
@@ -20,6 +22,7 @@ public static bool IsCudaAvailable()
 
             if (!NativeLibrary.TryLoad(libName, out var library))
             {
+                LogProvider.Log(WhisperLogLevel.Debug, "Cudart library couldn't be loaded.");
                 return false;
             }
             nativeCuda = new NativeLibraryCuda(library);
@@ -34,9 +37,11 @@ public static bool IsCudaAvailable()
             }
             catch
             {
+                LogProvider.Log(WhisperLogLevel.Debug, "Cudart library couldn't be loaded.");
                 return false;
             }
 #endif
+            LogProvider.Log(WhisperLogLevel.Debug, $"NUmber of CUDA devices found: {cudaDevices}");
             return cudaDevices > 0;
         }
         finally

diff --git a/Whisper.net/LibraryLoader/NativeLibraryLoader.cs b/Whisper.net/LibraryLoader/NativeLibraryLoader.cs
@@ -1,5 +1,7 @@
 // Licensed under the MIT license: https://opensource.org/licenses/MIT
 using Whisper.net.Internals.Native.Implementations;
+using Whisper.net.Logger;
+
 #if !IOS && !MACCATALYST && !TVOS && !ANDROID
 #if !NETSTANDARD
 using System.Runtime.Intrinsics.X86;
@@ -14,17 +16,21 @@ public static class NativeLibraryLoader
     internal static LoadResult LoadNativeLibrary()
     {
 #if IOS || MACCATALYST || TVOS
+        LogProvider.Log(WhisperLogLevel.Debug, "Using LibraryImportInternalWhisper for whisper librar for ios.");
         return LoadResult.Success(new LibraryImportInternalWhisper());
 #elif ANDROID       
+        LogProvider.Log(WhisperLogLevel.Debug, "Using LibraryImportLibWhisper for whisper librar for Android.");
         return LoadResult.Success(new LibraryImportLibWhisper());
 #else
         // If the user has handled loading the library themselves, we don't need to do anything.
         if (RuntimeOptions.Instance.BypassLoading
             || RuntimeInformation.OSArchitecture.ToString().Equals("wasm", StringComparison.OrdinalIgnoreCase))
         {
 #if NET8_0_OR_GREATER
+            LogProvider.Log(WhisperLogLevel.Debug, "Using LibraryImportLibWhisper for whisper library with bypassed loading.");
             return LoadResult.Success(new LibraryImportLibWhisper());
 #else
+            LogProvider.Log(WhisperLogLevel.Debug, "Using DllImportsNativeLibWhisper for whisper library with bypassed loading.");
             return LoadResult.Success(new DllImportsNativeLibWhisper());
 #endif
         }
@@ -59,7 +65,6 @@ _ when RuntimeInformation.IsOSPlatform(OSPlatform.OSX) => "macos",
 
         foreach (var (runtimePath, runtimeLibrary) in availableRuntimes)
         {
-
             if (!IsRuntimeSupported(runtimeLibrary, platform, availableRuntimeTypes))
             {
                 continue;
@@ -73,21 +78,30 @@ _ when RuntimeInformation.IsOSPlatform(OSPlatform.OSX) => "macos",
 
             var whisperPath = GetLibraryPath(platform, "whisper", runtimePath);
 
+            LogProvider.Log(WhisperLogLevel.Debug, $"Trying to load ggml library from {ggmlPath}");
             if (!libraryLoader.TryOpenLibrary(ggmlPath, out var ggmlLibraryHandle))
             {
                 lastError = libraryLoader.GetLastError();
+                LogProvider.Log(WhisperLogLevel.Debug, $"Failed to load ggml library from {ggmlPath}. Error: {lastError}");
                 continue;
             }
 
+            LogProvider.Log(WhisperLogLevel.Debug, $"Trying to load whisper library from {whisperPath}");
             // Ggml was loaded, for this runtimePath, we need to load whisper as well
             if (!libraryLoader.TryOpenLibrary(whisperPath, out var whisperHandle))
             {
+                lastError = libraryLoader.GetLastError();
+                LogProvider.Log(WhisperLogLevel.Debug, $"Failed to load whisper library from {whisperPath}. Error: {lastError}");
                 continue;
             }
+
+            LogProvider.Log(WhisperLogLevel.Debug, $"Successfully loaded whisper library from {whisperPath}");
             RuntimeOptions.Instance.SetLoadedLibrary(runtimeLibrary);
 #if NETSTANDARD
+            LogProvider.Log(WhisperLogLevel.Debug, $"Using DllImportsNativeWhisper for whisper library");
             var nativeWhisper = new DllImportsNativeWhisper();
 #else
+            LogProvider.Log(WhisperLogLevel.Debug, $"Using NativeLibraryWhisper for whisper library");
             var nativeWhisper = new NativeLibraryWhisper(whisperHandle, ggmlLibraryHandle);
 #endif
 
@@ -120,10 +134,12 @@ private static string GetLibraryPath(string platform, string libraryName, string
 
     private static bool IsRuntimeSupported(RuntimeLibrary runtime, string platform, List<RuntimeLibrary> runtimeLibraries)
     {
+        LogProvider.Log(WhisperLogLevel.Debug, $"Checking if runtime {runtime} is supported on the platform: {platform}");
 #if !NETSTANDARD
         // If AVX is not supported, we can't use CPU runtime on Windows and linux (we should use noavx runtime instead).
         if (runtime == RuntimeLibrary.Cpu && (platform == "win" || platform == "linux") && !Avx.IsSupported && !Avx2.IsSupported)
         {
+            LogProvider.Log(WhisperLogLevel.Debug, $"No AVX or AVX2 support is identified on this host.");
             // If noavx runtime is not available, we should throw an exception, because we can't use CPU runtime without AVX support.
             if (!runtimeLibraries.Contains(RuntimeLibrary.CpuNoAvx))
             {
@@ -145,9 +161,12 @@ private static bool IsRuntimeSupported(RuntimeLibrary runtime, string platform,
                 // + override the default RuntimeLibraryOrder to have only [ Cuda ].
                 // This way, the user can use Cuda if it's available, otherwise, the CPU runtime will be used.
                 // However, the cudart library should be available in the system.
+                LogProvider.Log(WhisperLogLevel.Debug, "Cuda runtime is not available, but it's the last runtime in the list. " +
+                    "It will be used as a fallback to the CPU runtime.");
                 return true;
             }
 
+            LogProvider.Log(WhisperLogLevel.Debug, "Cuda driver is not available or no cuda device is identified.");
             return false;
         }
 
@@ -178,7 +197,6 @@ private static bool IsRuntimeSupported(RuntimeLibrary runtime, string platform,
         {
             foreach (var assemblySearchPath in assemblySearchPaths)
             {
-
                 var runtimesPath = string.IsNullOrEmpty(assemblySearchPath)
                      ? "runtimes"
                      : Path.Combine(assemblySearchPath, "runtimes");
@@ -192,11 +210,16 @@ private static bool IsRuntimeSupported(RuntimeLibrary runtime, string platform,
                     RuntimeLibrary.OpenVino => Path.Combine(runtimesPath, "openvino", $"{platform}-{architecture}"),
                     _ => throw new InvalidOperationException("Unknown runtime library")
                 };
+                LogProvider.Log(WhisperLogLevel.Debug, $"Searching for runtime directory {library} in {runtimePath}");
 
                 if (Directory.Exists(runtimePath))
                 {
                     yield return (runtimePath, library);
                 }
+                else
+                {
+                    LogProvider.Log(WhisperLogLevel.Debug, $"Runtime directory for {library} not found in {runtimePath}");
+                }
             }
 
         }

diff --git a/Whisper.net/Logger/LogProvider.cs b/Whisper.net/Logger/LogProvider.cs
@@ -20,6 +20,22 @@ private LogProvider()
 
     public event Action<WhisperLogLevel, string?>? OnLog;
 
+    /// <summary>
+    /// Adds a console logger that logs messages with a severity greater than or equal to the specified level.
+    /// </summary>
+    /// <param name="minLevel">The minimum severity level to log.</param>
+    public static void AddConsoleLogging(WhisperLogLevel minLevel = WhisperLogLevel.Info)
+    {
+        Instance.OnLog += (level, message) =>
+        {
+            // Higher values are less severe
+            if (level < minLevel)
+            {
+                Console.WriteLine($"[{level}] {message}");
+            }
+        };
+    }
+
     internal static void InitializeLogging(INativeWhisper nativeWhisper)
     {
         IntPtr funcPointer;

diff --git a/tests/Whisper.net.Tests/FactoryTests.cs b/tests/Whisper.net.Tests/FactoryTests.cs
@@ -11,10 +11,7 @@ public class FactoryTests : IClassFixture<TinyModelFixture>
 
     public FactoryTests(TinyModelFixture model)
     {
-        LogProvider.Instance.OnLog += (level, message) =>
-        {
-            Console.WriteLine($"[{level}] {message}");
-        };
+        LogProvider.AddConsoleLogging(minLevel: WhisperLogLevel.Debug);
         this.model = model;
     }