Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: expose extism_log_file on Plugin #34

Merged
merged 5 commits into from
Dec 12, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
48 changes: 18 additions & 30 deletions src/Extism.Sdk/LibExtism.cs
Original file line number Diff line number Diff line change
Expand Up @@ -289,7 +289,7 @@ internal struct ExtismPlugin { }
unsafe internal static extern IntPtr extism_plugin_output_data(ExtismPlugin* plugin);

/// <summary>
/// Set log file and level.
/// Set log file and level for file logger.
/// </summary>
/// <param name="filename"></param>
/// <param name="logLevel"></param>
Expand All @@ -298,40 +298,28 @@ internal struct ExtismPlugin { }
internal static extern bool extism_log_file(string filename, string logLevel);

/// <summary>
/// Get Extism Runtime version.
/// Enable a custom log handler, this will buffer logs until `extism_log_drain` is called.
/// this will buffer logs until `extism_log_drain` is called
/// </summary>
/// <param name="logLevel"></param>
/// <returns></returns>
[DllImport("extism")]
internal static extern IntPtr extism_version();
internal static extern bool extism_log_custom(string logLevel);

internal delegate void LoggingSink(string line, ulong length);

/// <summary>
/// Extism Log Levels
/// Calls the provided callback function for each buffered log line.
/// This is only needed when `extism_log_custom` is used.
/// </summary>
internal static class LogLevels
{
/// <summary>
/// Designates very serious errors.
/// </summary>
internal const string Error = "Error";

/// <summary>
/// Designates hazardous situations.
/// </summary>
internal const string Warn = "Warn";

/// <summary>
/// Designates useful information.
/// </summary>
internal const string Info = "Info";

/// <summary>
/// Designates lower priority information.
/// </summary>
internal const string Debug = "Debug";
/// <param name="callback"></param>
[DllImport("extism")]
internal static extern void extism_log_drain(LoggingSink callback);

/// <summary>
/// Designates very low priority, often extremely verbose, information.
/// </summary>
internal const string Trace = "Trace";
}
/// <summary>
/// Get Extism Runtime version.
/// </summary>
/// <returns></returns>
[DllImport("extism")]
internal static extern IntPtr extism_version();
}
4 changes: 2 additions & 2 deletions src/Extism.Sdk/LogLevel.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,12 +8,12 @@ public enum LogLevel
/// <summary>
/// Designates very serious errors.
/// </summary>
Error,
Error = 1,

/// <summary>
/// Designates hazardous situations.
/// </summary>
Warning,
Warn,

/// <summary>
/// Designates useful information.
Expand Down
42 changes: 41 additions & 1 deletion src/Extism.Sdk/Plugin.cs
Original file line number Diff line number Diff line change
Expand Up @@ -317,4 +317,44 @@ public static string ExtismVersion()
var version = LibExtism.extism_version();
return Marshal.PtrToStringAnsi(version);
}
}

/// <summary>
/// Set log file and level
/// </summary>
/// <param name="path">Log file path</param>
/// <param name="level">Minimum log level</param>
public static void ConfigureFileLogging(string path, LogLevel level)
{
var logLevel = Enum.GetName(typeof(LogLevel), level).ToLowerInvariant();
LibExtism.extism_log_file(path, logLevel);
}

/// <summary>
/// Enable a custom log handler, this will buffer logs until <see cref="DrainCustomLogs(LoggingSink)"/> is called.
/// </summary>
/// <param name="level"></param>
public static void ConfigureCustomLogging(LogLevel level)
{
var logLevel = Enum.GetName(typeof(LogLevel), level).ToLowerInvariant();
LibExtism.extism_log_custom(logLevel);
}

/// <summary>
/// Calls the provided callback function for each buffered log line.
/// This only needed when <see cref="ConfigureCustomLogging(LogLevel)"/> is used.
/// </summary>
/// <param name="callback"></param>
public static void DrainCustomLogs(LoggingSink callback)
{
LibExtism.extism_log_drain((line, length) =>
{
callback(line);
});
}
}

/// <summary>
/// Custom logging callback.
/// </summary>
/// <param name="line"></param>
public delegate void LoggingSink(string line);
47 changes: 47 additions & 0 deletions test/Extism.Sdk/BasicTests.cs
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
using Extism.Sdk.Native;

using Shouldly;

using System.Runtime.InteropServices;
using System.Text;

Expand Down Expand Up @@ -178,6 +180,51 @@ public void HostFunctionsWithMemory()
Encoding.UTF8.GetString(response).ShouldBe("HELLO FRODO!");
}

[Fact]
public void FileLog()
{
var tempFile = Path.GetTempFileName();
Plugin.ConfigureFileLogging(tempFile, LogLevel.Warn);
using (var plugin = Helpers.LoadPlugin("log.wasm"))
{
plugin.Call("run_test", Array.Empty<byte>());
}

// HACK: tempFile gets locked by the Extism runtime
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@zshipko is there any way to make the logger lock less restrictive? Currently I can't read the file even after I dispose the Plugin

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure what kind of locking is happening here but it seems kind of surprising. I'll have to read through the log4rs code, which is handling that log file.

One thing worth noting is that the logging is a global configuration so disposing the Plugin wouldn't have any effect. Maybe there is some configuration about when to flush to disk that we could update?

I also want to take a look at the logging situation this week and see if there are any paths for improvement.

var tempFile2 = Path.GetTempFileName();
File.Copy(tempFile, tempFile2, true);

var content = File.ReadAllText(tempFile2);
content.ShouldContain("warn");
content.ShouldContain("error");
content.ShouldNotContain("info");
content.ShouldNotContain("debug");
content.ShouldNotContain("trace");
}


// [Fact]
// Interferes with FileLog
internal void CustomLog()
{
var builder = new StringBuilder();

Plugin.ConfigureCustomLogging(LogLevel.Warn);
using (var plugin = Helpers.LoadPlugin("log.wasm"))
{
plugin.Call("run_test", Array.Empty<byte>());
}

Plugin.DrainCustomLogs(line => builder.AppendLine(line));

var content = builder.ToString();
content.ShouldContain("warn");
content.ShouldContain("error");
content.ShouldNotContain("info");
content.ShouldNotContain("debug");
content.ShouldNotContain("trace");
}
Comment on lines +206 to +226
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@zshipko I had to comment this test out because it was interfering with the FileLog test (they were eating each others logs). Is there any way to disable Custom/File logging?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, unfortunately it's not possible to replace the current logger once it's set up. I can look into it a bit more tomorrow but it seems like that is the default behavior of tracing-subscriber.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure how hard it is, but I think it would be good if they automatically unsubscribe each other

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We're using something like this: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/fn.try_init.html which expects to be initialized once at the beginning of the program. I will see if there's another way.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I spent some time looking at this today and I think we could use https://docs.rs/tracing-subscriber/latest/tracing_subscriber/reload/index.html but it isn't super straight-forward. I will see if I can come up with a minimally invasive way to use that but haven't had much luck so far.


public class CountVowelsResponse
{
public int Count { get; set; }
Expand Down
2 changes: 1 addition & 1 deletion test/Extism.Sdk/Extism.Sdk.Tests.csproj
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
<Project Sdk="Microsoft.NET.Sdk">
<Project Sdk="Microsoft.NET.Sdk">

<PropertyGroup>
<TargetFramework>net7.0</TargetFramework>
Expand Down
Loading