Logging interceptor (#649)

* - Added `NativeLogConfig` which allows overriding the llama.cpp log callback
 - Delaying binding of this into llama.cpp until after `NativeLibraryConfig` has loaded

* Using the log callback to show loading log messages during loading.

* Registering log callbacks before any calls to llama.cpp except `llama_empty_call`, this is specifically selected to be a method that does nothing and is just there for triggering DLL loading.

* - Removed much of the complexity of logging from `NativeApi.Load`. It always call whatever log callbacks you have registered.
 - Removed alternative path for `ILogger` in NativeLibraryConfig, instead it redirects to wrapping it in a delegate.

* Saving a GC handle to keep the log callback alive

* Removed prefix, logger should already do that.

* Buffering up messages until a newline is encountered before passing log message to ILogger.

* - Added trailing `\n` to log messages from loading.
 - Using `ThreadLocal<StringBuilder>` to ensure messages from separate threads don't get mixed together.
This commit is contained in:
Martin Evans 2024-04-05 16:42:27 +01:00 committed by GitHub
parent fa73c8f07c
commit 58107bb5b9
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
7 changed files with 197 additions and 115 deletions

View File

@ -16,11 +16,20 @@ AnsiConsole.MarkupLineInterpolated(
""");
// Configure native library to use
// Configure native library to use. This must be done before any other llama.cpp methods are called!
NativeLibraryConfig
.Instance
.WithCuda()
.WithLogs(LLamaLogLevel.Info);
.WithCuda();
// Configure logging. Change this to `true` to see log messages from llama.cpp
var showLLamaCppLogs = false;
NativeLibraryConfig
.Instance
.WithLogCallback((level, message) =>
{
if (showLLamaCppLogs)
Console.WriteLine($"[llama {level}]: {message.TrimEnd('\n')}");
});
// Calling this method forces loading to occur now.
NativeApi.llama_empty_call();

View File

@ -8,3 +8,5 @@ using System.Diagnostics.CodeAnalysis;
[assembly: SuppressMessage("Interoperability", "CA1401:P/Invokes should not be visible", Justification = "LLamaSharp intentionally exports the native llama.cpp API")]
[assembly: SuppressMessage("Style", "IDE0070:Use 'System.HashCode'", Justification = "Not compatible with netstandard2.0")]
[assembly: SuppressMessage("Interoperability", "SYSLIB1054:Use 'LibraryImportAttribute' instead of 'DllImportAttribute' to generate P/Invoke marshalling code at compile time", Justification = "Not compatible with netstandard2.0")]

View File

@ -1,4 +1,7 @@
namespace LLama.Native
using System;
using Microsoft.Extensions.Logging;
namespace LLama.Native
{
/// <summary>
/// Severity level of a log message
@ -25,4 +28,19 @@
/// </summary>
Debug = 5,
}
internal static class LLamaLogLevelExtensions
{
public static LogLevel ToLogLevel(this LLamaLogLevel llama)
{
return (llama) switch
{
LLamaLogLevel.Error => LogLevel.Error,
LLamaLogLevel.Warning => LogLevel.Warning,
LLamaLogLevel.Info => LogLevel.Information,
LLamaLogLevel.Debug => LogLevel.Debug,
_ => throw new ArgumentOutOfRangeException(nameof(llama), llama, null)
};
}
}
}

View File

@ -17,6 +17,9 @@ namespace LLama.Native
// which llama.dll is used.
SetDllImportResolver();
// Set flag to indicate that this point has been passed. No native library config can be done after this point.
NativeLibraryConfig.LibraryHasLoaded = true;
// Immediately make a call which requires loading the llama DLL. This method call
// can't fail unless the DLL hasn't been loaded.
try
@ -34,6 +37,10 @@ namespace LLama.Native
"to specify it at the very beginning of your code. For more informations about compilation, please refer to LLamaSharp repo on github.\n");
}
// Now that the "loaded" flag is set configure logging in llama.cpp
if (NativeLibraryConfig.Instance.LogCallback != null)
NativeLogConfig.llama_log_set(NativeLibraryConfig.Instance.LogCallback);
// Init llama.cpp backend
llama_backend_init();
}
@ -80,47 +87,10 @@ namespace LLama.Native
private static void Log(string message, LLamaLogLevel level)
{
if (!enableLogging)
return;
if (!message.EndsWith("\n"))
message += "\n";
if ((int)level > (int)logLevel)
return;
var fg = Console.ForegroundColor;
var bg = Console.BackgroundColor;
try
{
ConsoleColor color;
string levelPrefix;
if (level == LLamaLogLevel.Debug)
{
color = ConsoleColor.Cyan;
levelPrefix = "[Debug]";
}
else if (level == LLamaLogLevel.Info)
{
color = ConsoleColor.Green;
levelPrefix = "[Info]";
}
else if (level == LLamaLogLevel.Error)
{
color = ConsoleColor.Red;
levelPrefix = "[Error]";
}
else
{
color = ConsoleColor.Yellow;
levelPrefix = "[UNK]";
}
Console.ForegroundColor = color;
Console.WriteLine($"{loggingPrefix} {levelPrefix} {message}");
}
finally
{
Console.ForegroundColor = fg;
Console.BackgroundColor = bg;
}
NativeLibraryConfig.Instance.LogCallback?.Invoke(level, message);
}
#region CUDA version
@ -362,8 +332,6 @@ namespace LLama.Native
{
#if NET6_0_OR_GREATER
var configuration = NativeLibraryConfig.CheckAndGatherDescription(lib);
enableLogging = configuration.Logging;
logLevel = configuration.LogLevel;
// Set the flag to ensure the NativeLibraryConfig can no longer be modified
NativeLibraryConfig.LibraryHasLoaded = true;
@ -455,8 +423,5 @@ namespace LLama.Native
internal const string libraryName = "llama";
internal const string llavaLibraryName = "llava_shared";
private const string cudaVersionFile = "version.json";
private const string loggingPrefix = "[LLamaSharp Native]";
private static bool enableLogging = false;
private static LLamaLogLevel logLevel = LLamaLogLevel.Info;
}
}

View File

@ -5,13 +5,6 @@ using System.Runtime.InteropServices;
namespace LLama.Native
{
/// <summary>
/// Callback from llama.cpp with log messages
/// </summary>
/// <param name="level"></param>
/// <param name="message"></param>
public delegate void LLamaLogCallback(LLamaLogLevel level, string message);
/// <summary>
/// Direct translation of the llama.cpp API
/// </summary>
@ -364,8 +357,11 @@ namespace LLama.Native
/// Register a callback to receive llama log messages
/// </summary>
/// <param name="logCallback"></param>
[DllImport(libraryName, CallingConvention = CallingConvention.Cdecl)]
public static extern void llama_log_set(LLamaLogCallback logCallback);
[Obsolete("Use `NativeLogConfig.llama_log_set` instead")]
public static void llama_log_set(NativeLogConfig.LLamaLogCallback logCallback)
{
NativeLogConfig.llama_log_set(logCallback);
}
/// <summary>
/// Clear the KV cache

View File

@ -1,6 +1,7 @@
using System;
using System.Collections.Generic;
using System.Linq;
using Microsoft.Extensions.Logging;
namespace LLama.Native
{
@ -9,18 +10,8 @@ namespace LLama.Native
/// Allows configuration of the native llama.cpp libraries to load and use.
/// All configuration must be done before using **any** other LLamaSharp methods!
/// </summary>
public sealed class NativeLibraryConfig
public sealed partial class NativeLibraryConfig
{
/// <summary>
/// Get the config instance
/// </summary>
public static NativeLibraryConfig Instance { get; } = new();
/// <summary>
/// Check if the native library has already been loaded. Configuration cannot be modified if this is true.
/// </summary>
public static bool LibraryHasLoaded { get; internal set; } = false;
private string? _libraryPath;
private string? _libraryPathLLava;
@ -28,20 +19,12 @@ namespace LLama.Native
private AvxLevel _avxLevel;
private bool _allowFallback = true;
private bool _skipCheck = false;
private bool _logging = false;
private LLamaLogLevel _logLevel = LLamaLogLevel.Info;
/// <summary>
/// search directory -> priority level, 0 is the lowest.
/// </summary>
private readonly List<string> _searchDirectories = new List<string>();
private static void ThrowIfLoaded()
{
if (LibraryHasLoaded)
throw new InvalidOperationException("NativeLibraryConfig must be configured before using **any** other LLamaSharp methods!");
}
#region configurators
/// <summary>
/// Load a specified native library as backend for LLamaSharp.
@ -117,35 +100,6 @@ namespace LLama.Native
return this;
}
/// <summary>
/// Whether to output the logs to console when loading the native library with your configuration.
/// </summary>
/// <param name="enable"></param>
/// <returns></returns>
/// <exception cref="InvalidOperationException">Thrown if `LibraryHasLoaded` is true.</exception>
public NativeLibraryConfig WithLogs(bool enable)
{
ThrowIfLoaded();
_logging = enable;
return this;
}
/// <summary>
/// Enable console logging with the specified log logLevel.
/// </summary>
/// <param name="logLevel"></param>
/// <returns></returns>
/// <exception cref="InvalidOperationException">Thrown if `LibraryHasLoaded` is true.</exception>
public NativeLibraryConfig WithLogs(LLamaLogLevel logLevel = LLamaLogLevel.Info)
{
ThrowIfLoaded();
_logging = true;
_logLevel = logLevel;
return this;
}
/// <summary>
/// Add self-defined search directories. Note that the file stucture of the added
/// directories must be the same as the default directory. Besides, the directory
@ -196,8 +150,6 @@ namespace LLama.Native
Instance._avxLevel,
Instance._allowFallback,
Instance._skipCheck,
Instance._logging,
Instance._logLevel,
Instance._searchDirectories.Concat(new[] { "./" }).ToArray()
);
}
@ -279,7 +231,7 @@ namespace LLama.Native
Avx512,
}
internal record Description(string? Path, LibraryName Library, bool UseCuda, AvxLevel AvxLevel, bool AllowFallback, bool SkipCheck, bool Logging, LLamaLogLevel LogLevel, string[] SearchDirectories)
internal record Description(string? Path, LibraryName Library, bool UseCuda, AvxLevel AvxLevel, bool AllowFallback, bool SkipCheck, string[] SearchDirectories)
{
public override string ToString()
{
@ -301,14 +253,61 @@ namespace LLama.Native
$"- PreferredAvxLevel: {avxLevelString}\n" +
$"- AllowFallback: {AllowFallback}\n" +
$"- SkipCheck: {SkipCheck}\n" +
$"- Logging: {Logging}\n" +
$"- LogLevel: {LogLevel}\n" +
$"- SearchDirectories and Priorities: {searchDirectoriesString}";
}
}
}
#endif
public sealed partial class NativeLibraryConfig
{
/// <summary>
/// Get the config instance
/// </summary>
public static NativeLibraryConfig Instance { get; } = new();
/// <summary>
/// Check if the native library has already been loaded. Configuration cannot be modified if this is true.
/// </summary>
public static bool LibraryHasLoaded { get; internal set; }
internal NativeLogConfig.LLamaLogCallback? LogCallback;
private static void ThrowIfLoaded()
{
if (LibraryHasLoaded)
throw new InvalidOperationException("NativeLibraryConfig must be configured before using **any** other LLamaSharp methods!");
}
/// <summary>
/// Set the log callback that will be used for all llama.cpp log messages
/// </summary>
/// <param name="callback"></param>
/// <exception cref="NotImplementedException"></exception>
public NativeLibraryConfig WithLogCallback(NativeLogConfig.LLamaLogCallback? callback)
{
ThrowIfLoaded();
LogCallback = callback;
return this;
}
/// <summary>
/// Set the log callback that will be used for all llama.cpp log messages
/// </summary>
/// <param name="logger"></param>
/// <exception cref="NotImplementedException"></exception>
public NativeLibraryConfig WithLogCallback(ILogger? logger)
{
ThrowIfLoaded();
// Redirect to llama_log_set. This will wrap the logger in a delegate and bind that as the log callback instead.
NativeLogConfig.llama_log_set(logger);
return this;
}
}
internal enum LibraryName
{
Llama,

View File

@ -0,0 +1,93 @@
using System.Runtime.InteropServices;
using System.Text;
using System.Threading;
using Microsoft.Extensions.Logging;
namespace LLama.Native;
/// <summary>
/// Configure llama.cpp logging
/// </summary>
public static class NativeLogConfig
{
/// <summary>
/// Callback from llama.cpp with log messages
/// </summary>
/// <param name="level"></param>
/// <param name="message"></param>
public delegate void LLamaLogCallback(LLamaLogLevel level, string message);
/// <summary>
/// Register a callback to receive llama log messages
/// </summary>
/// <param name="logCallback"></param>
[DllImport(NativeApi.libraryName, CallingConvention = CallingConvention.Cdecl, EntryPoint = "llama_log_set")]
private static extern void native_llama_log_set(LLamaLogCallback? logCallback);
/// <summary>
/// A GC handle for the current log callback to ensure the callback is not collected
/// </summary>
private static GCHandle? _currentLogCallbackHandle;
/// <summary>
/// Register a callback to receive llama log messages
/// </summary>
/// <param name="logCallback"></param>
#pragma warning disable IDE1006 // Naming Styles (name imitates llama.cpp)
public static void llama_log_set(LLamaLogCallback? logCallback)
#pragma warning restore IDE1006 // Naming Styles
{
if (NativeLibraryConfig.LibraryHasLoaded)
{
// The library is loaded, just pass the callback directly to llama.cpp
native_llama_log_set(logCallback);
// Save a GC handle, to ensure the callback is not collected
_currentLogCallbackHandle?.Free();
_currentLogCallbackHandle = null;
if (logCallback != null)
_currentLogCallbackHandle = GCHandle.Alloc(logCallback);
}
else
{
// We can't set the log method yet since that would cause the llama.dll to load.
// Instead configure it to be set when the native library loading is done
NativeLibraryConfig.Instance.WithLogCallback(logCallback);
}
}
/// <summary>
/// Register a callback to receive llama log messages
/// </summary>
/// <param name="logger"></param>
#pragma warning disable IDE1006 // Naming Styles (name imitates llama.cpp)
public static void llama_log_set(ILogger? logger)
#pragma warning restore IDE1006 // Naming Styles
{
// Clear the logger
if (logger == null)
{
llama_log_set((LLamaLogCallback?)null);
return;
}
var builderThread = new ThreadLocal<StringBuilder>(() => new StringBuilder());
// Bind a function that combines messages until a newline is encountered, then logs it all as one message
llama_log_set((level, message) =>
{
var builder = builderThread.Value!;
builder.Append(message);
if (!message.EndsWith("\n"))
return;
// Remove the newline from the end
builder.Remove(builder.Length - 1, 1);
logger.Log(level.ToLogLevel(), "{message}", builder.ToString());
builder.Clear();
});
}
}