Skip to content

Commit

Permalink
.Net: Fix function result logging exception (#5745)
Browse files Browse the repository at this point in the history
Fix for the issues:
- #5631
- #5264

### Description
Instead of serializing function result of kernel content type, we try to
get it as a string first, and only if the attempt fails we fallback to
serialization.

Note: Later, the serializer should use kernel serializer options when
they are available.

Co-authored-by: Mark Wallace <127216156+markwallace-microsoft@users.noreply.github.com>
  • Loading branch information
SergeyMenshykh and markwallace-microsoft committed Apr 3, 2024
1 parent ca9e3ae commit 2321a45
Show file tree
Hide file tree
Showing 3 changed files with 69 additions and 7 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -221,7 +221,7 @@ internal KernelFunction(string name, string? pluginName, string description, IRe
}

logger.LogFunctionInvokedSuccess(this.Name);
logger.LogFunctionResultValue(functionResult.Value);
logger.LogFunctionResultValue(functionResult);

return functionResult;
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -71,20 +71,27 @@ public static void LogFunctionArguments(this ILogger logger, KernelArguments arg
logLevel: LogLevel.Trace, // Sensitive data, logging as trace, disabled by default
eventId: 0,
"Function result: {ResultValue}");
public static void LogFunctionResultValue(this ILogger logger, object? resultValue)
[System.Diagnostics.CodeAnalysis.SuppressMessage("Design", "CA1031:Do not catch general exception types", Justification = "By design. See comment below.")]
public static void LogFunctionResultValue(this ILogger logger, FunctionResult? resultValue)
{
if (logger.IsEnabled(LogLevel.Trace))
{
// Attempt to convert the result value to string using the GetValue heuristic
try
{
var jsonString = resultValue?.GetType() == typeof(string)
? resultValue.ToString()
: JsonSerializer.Serialize(resultValue);
s_logFunctionResultValue(logger, jsonString ?? string.Empty, null);
s_logFunctionResultValue(logger, resultValue?.GetValue<string>() ?? string.Empty, null);
return;
}
catch { }

// Falling back to Json serialization
try
{
s_logFunctionResultValue(logger, JsonSerializer.Serialize(resultValue?.Value), null);
}
catch (NotSupportedException ex)
{
s_logFunctionResultValue(logger, "Failed to serialize result value to Json", ex);
s_logFunctionResultValue(logger, "Failed to log function result value", ex);
}
}
}
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,55 @@
// Copyright (c) Microsoft. All rights reserved.

using System;
using System.Text.Json.Serialization;
using Microsoft.Extensions.Logging;
using Microsoft.SemanticKernel;
using Microsoft.SemanticKernel.ChatCompletion;
using Moq;
using Xunit;

namespace SemanticKernel.UnitTests.Functions;
public class KernelFunctionLogMessagesTests
{
[Theory]
[InlineData(typeof(string))]
[InlineData(typeof(int))]
[InlineData(typeof(bool))]
[InlineData(typeof(ChatMessageContent))]
[InlineData(typeof(User))]
public void ItShouldLogFunctionResultOfAnyType(Type resultType)
{
// Arrange
(object FunctionResult, string LogMessage) testData = resultType switch
{
Type t when t == typeof(string) => ("test-string", "Function result: test-string"),
Type t when t == typeof(int) => (6, "Function result: 6"),
Type t when t == typeof(bool) => (true, "Function result: true"),
Type t when t == typeof(ChatMessageContent) => (new ChatMessageContent(AuthorRole.Assistant, "test-content"), "Function result: test-content"),
Type t when t == typeof(User) => (new User { Name = "test-user-name" }, "Function result: {\"name\":\"test-user-name\"}"),
_ => throw new ArgumentException("Invalid type")
};

var logger = new Mock<ILogger>();
logger.Setup(l => l.IsEnabled(It.IsAny<LogLevel>())).Returns(true);

var functionResult = new FunctionResult(KernelFunctionFactory.CreateFromMethod(() => { }), testData.FunctionResult);

// Act
logger.Object.LogFunctionResultValue(functionResult);

// Assert
logger.Verify(l => l.Log(
LogLevel.Trace,
0,
It.Is<It.IsAnyType>((o, _) => o.ToString() == testData.LogMessage),
null,
It.IsAny<Func<It.IsAnyType, Exception?, string>>()));
}

private sealed class User
{
[JsonPropertyName("name")]
public string? Name { get; set; }
}
}

0 comments on commit 2321a45

Please sign in to comment.