diff --git a/Libraries/src/Amazon.Lambda.Core/Amazon.Lambda.Core.csproj b/Libraries/src/Amazon.Lambda.Core/Amazon.Lambda.Core.csproj index 9ec52a364..fd299bccb 100644 --- a/Libraries/src/Amazon.Lambda.Core/Amazon.Lambda.Core.csproj +++ b/Libraries/src/Amazon.Lambda.Core/Amazon.Lambda.Core.csproj @@ -6,7 +6,7 @@ netstandard2.0;net6.0;net8.0 Amazon Lambda .NET Core support - Core package. Amazon.Lambda.Core - 2.2.0 + 2.3.0 Amazon.Lambda.Core Amazon.Lambda.Core AWS;Amazon;Lambda diff --git a/Libraries/src/Amazon.Lambda.Core/ILambdaLogger.cs b/Libraries/src/Amazon.Lambda.Core/ILambdaLogger.cs index 7afa10348..7f1cac273 100644 --- a/Libraries/src/Amazon.Lambda.Core/ILambdaLogger.cs +++ b/Libraries/src/Amazon.Lambda.Core/ILambdaLogger.cs @@ -1,3 +1,6 @@ +using System; +using System.Runtime.Versioning; + namespace Amazon.Lambda.Core { #if NET6_0_OR_GREATER @@ -62,7 +65,7 @@ public interface ILambdaLogger #if NET6_0_OR_GREATER /// - /// Log message catagorized by the given log level + /// Log message categorized by the given log level /// /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". @@ -73,7 +76,7 @@ public interface ILambdaLogger void Log(string level, string message) => LogLine(message); /// - /// Log message catagorized by the given log level + /// Log message categorized by the given log level /// /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". @@ -142,6 +145,222 @@ public interface ILambdaLogger /// /// void LogCritical(string message) => Log(LogLevel.Critical.ToString(), message); + + + private const string ParameterizedPreviewMessage = + "Parameterized logging is in preview till a new version of .NET Lambda runtime client that supports parameterized logging " + + "has been deployed to the .NET Lambda managed runtime. Till deployment has been made the feature can be used by deploying as an " + + "executable including the latest version of Amazon.Lambda.RuntimeSupport and setting the \"EnablePreviewFeatures\" in the Lambda " + + "project file to \"true\""; + + /// + /// Log message categorized by the given log level + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Log level of the message. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void Log(string level, string message, params object[] args) => Log(level, message, args); + + /// + /// Log message categorized by the given log level + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Log level of the message. + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void Log(string level, Exception exception, string message, params object[] args) + { + Log(level, message, args); + Log(level, exception.ToString(), args); + } + + /// + /// Log message categorized by the given log level + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Log level of the message. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void Log(LogLevel level, string message, params object[] args) => Log(level.ToString(), message, args); + + /// + /// Log message categorized by the given log level + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Log level of the message. + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void Log(LogLevel level, Exception exception, string message, params object[] args) => Log(level.ToString(), exception, message, args); + + /// + /// Log trace message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogTrace(string message, params object[] args) => Log(LogLevel.Trace.ToString(), message, args); + + /// + /// Log trace message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogTrace(Exception exception, string message, params object[] args) => Log(LogLevel.Trace.ToString(), exception, message, args); + + /// + /// Log debug message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogDebug(string message, params object[] args) => Log(LogLevel.Debug.ToString(), message, args); + + /// + /// Log debug message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogDebug(Exception exception, string message, params object[] args) => Log(LogLevel.Debug.ToString(), exception, message, args); + + /// + /// Log information message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogInformation(string message, params object[] args) => Log(LogLevel.Information.ToString(), message, args); + + /// + /// Log information message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogInformation(Exception exception, string message, params object[] args) => Log(LogLevel.Information.ToString(), exception, message, args); + + /// + /// Log warning message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogWarning(string message, params object[] args) => Log(LogLevel.Warning.ToString(), message, args); + + /// + /// Log warning message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogWarning(Exception exception, string message, params object[] args) => Log(LogLevel.Warning.ToString(), exception, message, args); + + /// + /// Log error message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogError(string message, params object[] args) => Log(LogLevel.Error.ToString(), message, args); + + /// + /// Log error message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogError(Exception exception, string message, params object[] args) => Log(LogLevel.Error.ToString(), exception, message, args); + + /// + /// Log critical message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogCritical(string message, params object[] args) => Log(LogLevel.Critical.ToString(), message, args); + + /// + /// Log critical message. + /// + /// To configure the minimum log level set the AWS_LAMBDA_HANDLER_LOG_LEVEL environment variable. The value should be set + /// to one of the values in the LogLevel enumeration. The default minimum log level is "Information". + /// + /// + /// Exception to include with the logging. + /// Message to log. + /// Values to be replaced in log messages that are parameterized. + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + void LogCritical(Exception exception, string message, params object[] args) => Log(LogLevel.Critical.ToString(), exception, message, args); + #endif } diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Amazon.Lambda.RuntimeSupport.csproj b/Libraries/src/Amazon.Lambda.RuntimeSupport/Amazon.Lambda.RuntimeSupport.csproj index 0d0b09549..052425369 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Amazon.Lambda.RuntimeSupport.csproj +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Amazon.Lambda.RuntimeSupport.csproj @@ -4,7 +4,7 @@ netstandard2.0;net5.0;net6.0;net8.0 - 1.10.0 + 1.11.0 Provides a bootstrap and Lambda Runtime API Client to help you to develop custom .NET Core Lambda Runtimes. Amazon.Lambda.RuntimeSupport Amazon.Lambda.RuntimeSupport @@ -13,6 +13,7 @@ README.md true true + 9.0 @@ -23,7 +24,6 @@ IL2026,IL2067,IL2075 true true - true diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/Constants.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/Constants.cs index e1e582a77..e3ef794f3 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/Constants.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/Constants.cs @@ -33,6 +33,14 @@ internal class Constants internal const string AWS_LAMBDA_INITIALIZATION_TYPE_PC = "provisioned-concurrency"; internal const string AWS_LAMBDA_INITIALIZATION_TYPE_ON_DEMAND = "on-demand"; + internal const string NET_RIC_LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_LEVEL"; + internal const string NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_FORMAT"; + + internal const string LAMBDA_LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_LOG_LEVEL"; + internal const string LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_LOG_FORMAT"; + + internal const string LAMBDA_LOG_FORMAT_JSON = "Json"; + internal enum AwsLambdaDotNetPreJit { Never, diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/LambdaBootstrap.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/LambdaBootstrap.cs index e3989d1f9..c7e78835b 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/LambdaBootstrap.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/LambdaBootstrap.cs @@ -18,6 +18,7 @@ using System.Net.Http; using System.Threading; using System.Threading.Tasks; +using Amazon.Lambda.Core; using Amazon.Lambda.RuntimeSupport.Bootstrap; using Amazon.Lambda.RuntimeSupport.Helpers; @@ -252,9 +253,11 @@ public static HttpClient ConstructHttpClient() private void WriteUnhandledExceptionToLog(Exception exception) { - // Console.Error.WriteLine are redirected to the IConsoleLoggerWriter which - // will take care of writing to the function's log stream. +#if NET6_0_OR_GREATER + Client.ConsoleLogger.FormattedWriteLine(LogLevel.Error.ToString(), exception, null); +#else Console.Error.WriteLine(exception); +#endif } #if NET8_0_OR_GREATER diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/IRuntimeApiClient.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/IRuntimeApiClient.cs index 1eeef4ecd..34b0162ec 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/IRuntimeApiClient.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/IRuntimeApiClient.cs @@ -13,6 +13,7 @@ * permissions and limitations under the License. */ +using Amazon.Lambda.RuntimeSupport.Helpers; using System; using System.IO; using System.Threading; @@ -25,6 +26,11 @@ namespace Amazon.Lambda.RuntimeSupport /// public interface IRuntimeApiClient { + /// + /// Logger used for formatting log messages into the user's CloudWatch Log stream. + /// + IConsoleLoggerWriter ConsoleLogger { get; } + /// /// Report an initialization error as an asynchronous operation. /// diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/RuntimeApiClient.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/RuntimeApiClient.cs index c07578740..2cbc4cb83 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/RuntimeApiClient.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Client/RuntimeApiClient.cs @@ -39,6 +39,9 @@ public class RuntimeApiClient : IRuntimeApiClient internal Func ExceptionConverter { get; set; } internal LambdaEnvironment LambdaEnvironment { get; set; } + /// + public IConsoleLoggerWriter ConsoleLogger => _consoleLoggerRedirector; + /// /// Create a new RuntimeApiClient /// diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Context/LambdaConsoleLogger.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Context/LambdaConsoleLogger.cs index f8f492995..6a82d4765 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Context/LambdaConsoleLogger.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Context/LambdaConsoleLogger.cs @@ -15,6 +15,7 @@ using Amazon.Lambda.Core; using Amazon.Lambda.RuntimeSupport.Helpers; using System; +using System.Runtime.Versioning; namespace Amazon.Lambda.RuntimeSupport { @@ -44,6 +45,24 @@ public void Log(string level, string message) { _consoleLoggerRedirector.FormattedWriteLine(level, message); } + + private const string ParameterizedPreviewMessage = + "Parameterized logging is in preview till a new version of .NET Lambda runtime client that supports parameterized logging " + + "has been deployed to the .NET Lambda managed runtime. Till deployment has been made the feature can be used by deploying as an " + + "executable including the latest version of Amazon.Lambda.RuntimeSupport and setting the \"LangVersion\" in the Lambda " + + "project file to \"preview\""; + + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + public void Log(string level, string message, params object[] args) + { + _consoleLoggerRedirector.FormattedWriteLine(level, message, args); + } + + [RequiresPreviewFeatures(ParameterizedPreviewMessage)] + public void Log(string level, Exception exception, string message, params object[] args) + { + _consoleLoggerRedirector.FormattedWriteLine(level, exception, message, args); + } #endif } } diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs index cf9193a12..15d577060 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs @@ -21,6 +21,11 @@ using System.Threading; using System.Threading.Tasks; + +#if NET6_0_OR_GREATER +using Amazon.Lambda.RuntimeSupport.Helpers.Logging; +#endif + namespace Amazon.Lambda.RuntimeSupport.Helpers { /// @@ -31,21 +36,31 @@ public interface IConsoleLoggerWriter /// /// The current aws request id /// - /// + /// The AWS request id for the function invocation added to each log message. void SetCurrentAwsRequestId(string awsRequestId); /// /// Format message with default log level /// - /// + /// Message to log. void FormattedWriteLine(string message); /// /// Format message with given log level /// - /// - /// - void FormattedWriteLine(string level, string message); + /// The level of the log message. + /// Message to log. + /// Arguments to be applied to the log message. + void FormattedWriteLine(string level, string message, params object[] args); + + /// + /// Format message with given log level + /// + /// The level of the log message. + /// Exception to log. + /// Message to log. + /// Arguments to be applied to the log message. + void FormattedWriteLine(string level, Exception exception, string message, params object[] args); } /// @@ -55,6 +70,9 @@ public class SimpleLoggerWriter : IConsoleLoggerWriter { TextWriter _writer; + /// + /// Default Constructor + /// public SimpleLoggerWriter() { // Look to see if Lambda's telemetry log file descriptor is available. If so use that for logging. @@ -80,19 +98,32 @@ public SimpleLoggerWriter() } } + /// public void SetCurrentAwsRequestId(string awsRequestId) { } + /// public void FormattedWriteLine(string message) { _writer.WriteLine(message); } - public void FormattedWriteLine(string level, string message) + /// + public void FormattedWriteLine(string level, string message, params object[] args) { _writer.WriteLine(message); } + + /// + public void FormattedWriteLine(string level, Exception exception, string message, params object[] args) + { + _writer.WriteLine(message); + if (exception != null) + { + _writer.WriteLine(exception.ToString()); + } + } } #if NET6_0_OR_GREATER @@ -107,7 +138,7 @@ public class LogLevelLoggerWriter : IConsoleLoggerWriter /// Amazon.Lambda.Core can not be relied on because the Lambda Function could be using /// an older version of Amazon.Lambda.Core before LogLevel existed in Amazon.Lambda.Core. /// - enum LogLevel + public enum LogLevel { /// /// Trace level logging @@ -186,6 +217,11 @@ public LogLevelLoggerWriter() ConfigureLoggingActionField(); } + /// + /// Construct an instance wrapping std out and std error. + /// + /// + /// public LogLevelLoggerWriter(TextWriter stdOutWriter, TextWriter stdErrorWriter) { Initialize(stdOutWriter, stdErrorWriter); @@ -216,20 +252,29 @@ private void ConfigureLoggingActionField() loggingActionField.SetValue(null, callback); } + /// public void SetCurrentAwsRequestId(string awsRequestId) { _wrappedStdOutWriter.CurrentAwsRequestId = awsRequestId; _wrappedStdErrorWriter.CurrentAwsRequestId = awsRequestId; } + /// public void FormattedWriteLine(string message) { _wrappedStdOutWriter.FormattedWriteLine(message); } - public void FormattedWriteLine(string level, string message) + /// + public void FormattedWriteLine(string level, string message, params object[] args) + { + _wrappedStdOutWriter.FormattedWriteLine(level, (Exception)null, message, args); + } + + /// + public void FormattedWriteLine(string level, Exception exception, string message, params object[] args) { - _wrappedStdOutWriter.FormattedWriteLine(level, message); + _wrappedStdOutWriter.FormattedWriteLine(level, exception, message, args); } @@ -243,15 +288,14 @@ class WrapperTextWriter : TextWriter private readonly TextWriter _innerWriter; private string _defaultLogLevel; - const string LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_LEVEL"; - const string LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_FORMAT"; - private LogLevel _minmumLogLevel = LogLevel.Information; - enum LogFormatType { Default, Unformatted } + enum LogFormatType { Default, Unformatted, Json } private LogFormatType _logFormatType = LogFormatType.Default; + private ILogMessageFormatter _logMessageFormatter; + public string CurrentAwsRequestId { get; set; } = string.Empty; /// @@ -262,21 +306,39 @@ enum LogFormatType { Default, Unformatted } /// internal object LockObject { get; set; } = new object(); + /// + /// Create an instance + /// + /// + /// public WrapperTextWriter(TextWriter innerWriter, string defaultLogLevel) { _innerWriter = innerWriter; _defaultLogLevel = defaultLogLevel; - var envLogLevel = Environment.GetEnvironmentVariable(LOG_LEVEL_ENVIRONMENT_VARIABLE); + var envLogLevel = GetEnvironmentVariable(Constants.NET_RIC_LOG_LEVEL_ENVIRONMENT_VARIABLE, Constants.LAMBDA_LOG_LEVEL_ENVIRONMENT_VARIABLE); if (!string.IsNullOrEmpty(envLogLevel)) { - if (Enum.TryParse(envLogLevel, true, out var result)) + // Map Lambda's fatal logging level to the .NET RIC critical + if(string.Equals(envLogLevel, "fatal", StringComparison.InvariantCultureIgnoreCase)) + { + _minmumLogLevel = LogLevel.Critical; + } + else if (string.Equals(envLogLevel, "warn", StringComparison.InvariantCultureIgnoreCase)) + { + _minmumLogLevel = LogLevel.Warning; + } + else if (Enum.TryParse(envLogLevel, true, out var result)) { _minmumLogLevel = result; } + else + { + InternalLogger.GetDefaultLogger().LogInformation($"Failed to parse log level enum value: {envLogLevel}"); + } } - var envLogFormat = Environment.GetEnvironmentVariable(LOG_FORMAT_ENVIRONMENT_VARIABLE); + var envLogFormat = GetEnvironmentVariable(Constants.NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE, Constants.LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE); if (!string.IsNullOrEmpty(envLogFormat)) { if (Enum.TryParse(envLogFormat, true, out var result)) @@ -284,14 +346,34 @@ public WrapperTextWriter(TextWriter innerWriter, string defaultLogLevel) _logFormatType = result; } } + + if(_logFormatType == LogFormatType.Json) + { + _logMessageFormatter = new JsonLogMessageFormatter(); + } + else + { + _logMessageFormatter = new DefaultLogMessageFormatter(_logFormatType != LogFormatType.Unformatted); + } + } + + private string GetEnvironmentVariable(string envName, string fallbackEnvName) + { + var value = Environment.GetEnvironmentVariable(envName); + if(string.IsNullOrEmpty(value) && fallbackEnvName != null) + { + value = Environment.GetEnvironmentVariable(fallbackEnvName); + } + + return value; } internal void FormattedWriteLine(string message) { - FormattedWriteLine(_defaultLogLevel, message); + FormattedWriteLine(_defaultLogLevel, (Exception)null, message); } - internal void FormattedWriteLine(string level, string message) + internal void FormattedWriteLine(string level, Exception exeception, string messageTemplate, params object[] args) { lock(LockObject) { @@ -300,28 +382,20 @@ internal void FormattedWriteLine(string level, string message) { if (levelEnum < _minmumLogLevel) return; - - displayLevel = ConvertLogLevelToLabel(levelEnum); } - if (_logFormatType == LogFormatType.Unformatted) - { - _innerWriter.WriteLine(message); - } - else - { - string line; - if (!string.IsNullOrEmpty(displayLevel)) - { - line = $"{DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ss.fffZ")}\t{CurrentAwsRequestId}\t{displayLevel}\t{message ?? string.Empty}"; - } - else - { - line = $"{DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ss.fffZ")}\t{CurrentAwsRequestId}\t{message ?? string.Empty}"; - } - - _innerWriter.WriteLine(line); - } + var messageState = new MessageState(); + + messageState.MessageTemplate = messageTemplate; + messageState.MessageArguments = args; + messageState.TimeStamp = DateTime.UtcNow; + messageState.AwsRequestId = CurrentAwsRequestId; + messageState.TraceId = Environment.GetEnvironmentVariable(LambdaEnvironment.EnvVarTraceId); + messageState.Level = levelEnum; + messageState.Exception = exeception; + + var message = _logMessageFormatter.FormatMessage(messageState); + _innerWriter.WriteLine(message); } } @@ -331,32 +405,6 @@ private Task FormattedWriteLineAsync(string message) return Task.CompletedTask; } - /// - /// Convert LogLevel enums to the the same string label that console provider for Microsoft.Extensions.Logging.ILogger uses. - /// - /// - /// - private string ConvertLogLevelToLabel(LogLevel level) - { - switch (level) - { - case LogLevel.Trace: - return "trce"; - case LogLevel.Debug: - return "dbug"; - case LogLevel.Information: - return "info"; - case LogLevel.Warning: - return "warn"; - case LogLevel.Error: - return "fail"; - case LogLevel.Critical: - return "crit"; - } - - return level.ToString(); - } - #region WriteLine redirects to formatting [CLSCompliant(false)] public override void WriteLine(ulong value) => FormattedWriteLine(value.ToString(FormatProvider)); diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/FileDescriptorLogStream.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/FileDescriptorLogStream.cs index 0186f7f94..2510c421a 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/FileDescriptorLogStream.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/FileDescriptorLogStream.cs @@ -19,6 +19,7 @@ using System.Text; using Microsoft.Win32.SafeHandles; using System.Collections.Concurrent; +using Amazon.Lambda.RuntimeSupport.Bootstrap; namespace Amazon.Lambda.RuntimeSupport.Helpers { @@ -33,7 +34,8 @@ public static class FileDescriptorLogFactory // max cloudwatch log event size, 256k - 26 bytes of overhead. internal const int MaxCloudWatchLogEventSize = 256 * 1024 - 26; internal const int LambdaTelemetryLogHeaderLength = 16; - internal const uint LambdaTelemetryLogHeaderFrameType = 0xa55a0003; + internal const uint LambdaTelemetryLogHeaderFrameTypeText = 0xa55a0003; + internal const uint LambdaTelemetryLogHeaderFrameTypeJson = 0xa55a0002; internal static readonly DateTimeOffset UnixEpoch = new DateTimeOffset(1970, 1, 1, 0, 0, 0, TimeSpan.Zero); /// @@ -84,12 +86,19 @@ private class FileDescriptorLogStream : Stream { private readonly Stream _fileDescriptorStream; private readonly byte[] _frameTypeBytes; + private readonly uint _frameType; public FileDescriptorLogStream(Stream logStream) { + var logFormat = Environment.GetEnvironmentVariable(Constants.LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE); + _frameType = string.Equals(logFormat, Constants.LAMBDA_LOG_FORMAT_JSON, StringComparison.InvariantCultureIgnoreCase) + ? LambdaTelemetryLogHeaderFrameTypeJson : LambdaTelemetryLogHeaderFrameTypeText; + + InternalLogger.GetDefaultLogger().LogDebug("FileDescriptorLogStream FrameType: " + _frameType); + _fileDescriptorStream = logStream; - _frameTypeBytes = BitConverter.GetBytes(LambdaTelemetryLogHeaderFrameType); + _frameTypeBytes = BitConverter.GetBytes(_frameType); if (BitConverter.IsLittleEndian) { Array.Reverse(_frameTypeBytes); diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/AbstractLogMessageFormatter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/AbstractLogMessageFormatter.cs new file mode 100644 index 000000000..b400b494f --- /dev/null +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/AbstractLogMessageFormatter.cs @@ -0,0 +1,288 @@ +#if NET6_0_OR_GREATER +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Globalization; +using System.Text; + +namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging +{ + /// + /// Base class of log message formatters. + /// + public abstract class AbstractLogMessageFormatter : ILogMessageFormatter + { + /// + /// Use a cache to look-up formatter so we don't have to parse the format for every entry. + /// + private static readonly ConcurrentDictionary> MESSAGE_TEMPLATE_PARSE_CACHE = new ConcurrentDictionary>(); + private const int MESSAGE_TEMPLATE_PARSE_CACHE_MAXSIZE = 1024; + + /// + /// States in the log format parser state machine. + /// + private enum LogFormatParserState : byte + { + InMessage, + PossibleParameterOpen, + InParameter + } + + /// + /// Parse the message template for all message properties. + /// + /// The message template users passed in as the log message. + /// List of MessageProperty objects detected by parsing the message template. + public virtual IReadOnlyList ParseProperties(string messageTemplate) + { + // Check to see if this message template has already been parsed before. + if (MESSAGE_TEMPLATE_PARSE_CACHE.TryGetValue(messageTemplate, out var cachedMessageProperties)) + { + return cachedMessageProperties; + } + + var messageProperties = new List(); + var state = LogFormatParserState.InMessage; + + int paramStartIdx = -1; + for (int i = 0, l = messageTemplate.Length; i < l; i++) + { + var c = messageTemplate[i]; + switch (c) + { + case '{': + if (state == LogFormatParserState.InMessage) + { + state = LogFormatParserState.PossibleParameterOpen; + } + else if (state == LogFormatParserState.PossibleParameterOpen) + { + // this is an escaped brace + state = LogFormatParserState.InMessage; + } + break; + case '}': + if (state != LogFormatParserState.InMessage) + { + if(paramStartIdx != -1) + { + // Since we have a closing bracket and there is at least a start to a message property label + // then we know we have hit the end of the message property. + messageProperties.Add(new MessageProperty(messageTemplate.AsSpan().Slice(paramStartIdx, i - paramStartIdx))); + } + + state = LogFormatParserState.InMessage; + paramStartIdx = -1; + } + break; + default: + if (state == LogFormatParserState.PossibleParameterOpen) + { + // non-brace character after '{', transition to InParameter + paramStartIdx = i; + state = LogFormatParserState.InParameter; + } + break; + } + } + + var readonlyMessagesProperties = messageProperties.AsReadOnly(); + + // If there is a room in the message template cache then cache the parse results for + // later logging performance increase. + if (MESSAGE_TEMPLATE_PARSE_CACHE.Count < MESSAGE_TEMPLATE_PARSE_CACHE_MAXSIZE) + { + MESSAGE_TEMPLATE_PARSE_CACHE.TryAdd(messageTemplate, readonlyMessagesProperties); + } + + return readonlyMessagesProperties; + } + + /// + /// Subclasses to implement to format the message given the requirements of the subclass. + /// + /// The state of the message to log. + /// The full log message to send to CloudWatch Logs. + public abstract string FormatMessage(MessageState state); + + internal const string DateFormat = "yyyy-MM-ddTHH:mm:ss.fffZ"; + + internal const string DateOnlyFormat = "yyyy-MM-dd"; + + internal const string TimeOnlyFormat = "HH:mm:ss.fff"; + + /// + /// Format the timestamp of the log message in format Lambda service prefers. + /// + /// The state of the message to log. + /// Timestamp formatted for logging. + protected string FormatTimestamp(MessageState state) + { + return state.TimeStamp.ToString(DateFormat, CultureInfo.InvariantCulture); + } + + /// + /// Replace all message properties in message templates with formatted values from the arguments passed in. + /// + /// + /// + /// + /// The log message with logging arguments replaced with the values. + public string ApplyMessageProperties(string messageTemplate, IReadOnlyList messageProperties, object[] messageArguments) + { + if(messageProperties.Count == 0 || messageArguments == null || messageArguments.Length == 0) + { + return messageTemplate; + } + + // Check to see if the message template is using positions instead of names. For example + // "User bought {0} of {1}" is positional as opposed to "User bought {count} of {product"}. + var usePositional = UsingPositionalArguments(messageProperties); + + var state = LogFormatParserState.InMessage; + + // Builder used to create the message with the properties replaced. Set the initial capacity + // to the size of the message template plus 10% to give room for the values of message properties + // to be larger then the message property in the message themselves. + StringBuilder messageBuilder = new StringBuilder(capacity: (int)(messageTemplate.Length * 1.1)); + + // Builder used store potential message properties as we parse through the message. If the + // it turns out the potential message property is not a message property the contents of this + // builder are written back to the messageBuilder. + StringBuilder propertyBuilder = new StringBuilder(); + + int propertyIndex = 0; + for (int i = 0, l = messageTemplate.Length; i < l; i++) + { + var c = messageTemplate[i]; + + // If not using positional properties and we have hit the point there are more message properties then arguments + // then just add the rest of the message template onto the messageBuilder. + if (!usePositional && (messageProperties.Count <= propertyIndex || messageArguments.Length <= propertyIndex)) + { + messageBuilder.Append(c); + continue; + } + + switch (c) + { + case '{': + if (state == LogFormatParserState.InMessage) + { + // regardless of whether this is the opening of a parameter we'd still need to add { + propertyBuilder.Append(c); + state = LogFormatParserState.PossibleParameterOpen; + } + else if (state == LogFormatParserState.PossibleParameterOpen) + { + // We have hit an escaped "{" by the user using "{{". Since we now know we are + // not in a message properties write back the propertiesBuilder into + // messageBuilder and reset the propertyBuilder. + messageBuilder.Append(propertyBuilder.ToString()); + propertyBuilder.Clear(); + messageBuilder.Append(c); + state = LogFormatParserState.InMessage; + } + else + { + propertyBuilder.Append(c); + } + break; + case '}': + if (state == LogFormatParserState.InMessage) + { + messageBuilder.Append(c); + } + else + { + var property = messageProperties[propertyIndex]; + object argument = null; + if(usePositional) + { + // If usePositional is true then we have confirmed the `Name` property is an int + var index = int.Parse(property.Name, CultureInfo.InvariantCulture); + if (index < messageArguments.Length) + { + argument = messageArguments[index]; + } + } + else + { + argument = messageArguments[propertyIndex]; + } + messageBuilder.Append(property.FormatForMessage(argument)); + + propertyIndex++; + propertyBuilder.Clear(); + state = LogFormatParserState.InMessage; + } + break; + default: + if (state == LogFormatParserState.InMessage) + { + messageBuilder.Append(c); + } + else if (state == LogFormatParserState.PossibleParameterOpen) + { + // non-brace character after '{', transition to InParameter + propertyBuilder.Append(c); + state = LogFormatParserState.InParameter; + } + break; + } + } + + return messageBuilder.ToString(); + } + + /// + /// Check to see if the properties in a message are using a position instead of names. + /// Positional example: + /// Log Message: "{0} {1} {0}" + /// Arguments: "Arg1", "Arg2" + /// Formatted Message: "Arg1 Arg2 Arg1" + /// Name example: + /// Log Message: "{name} {age} {home} + /// Arguments: "Lewis", 15, "Washington + /// Formatted Message: "Lewis 15 Washington" + /// + /// + /// True of the logging arguments are positional + public bool UsingPositionalArguments(IReadOnlyList messageProperties) + { + var min = int.MaxValue; + int max = int.MinValue; + HashSet positions = new HashSet(); + foreach(var property in messageProperties) + { + // If any logging arguments use non-numeric identifier then they are not using positional arguments. + if (!int.TryParse(property.Name, NumberStyles.Integer, CultureInfo.InvariantCulture, out var position)) + { + return false; + } + + positions.Add(position); + if(position < min) + { + min = position; + } + if (max < position) + { + max = position; + } + } + + // At this point the HashSet is the collection of all of the int logging arguments. + // If there are no gaps or duplicates in the logging statement then the smallest value + // in the hashset should be 0 and the max value equals the count of the hashset. If + // either of those conditions are not true then it can't be positional arguments. + if(positions.Count != (max + 1) || min != 0) + { + return false; + } + + return true; + } + } +} +#endif \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/DefaultLogMessageFormatter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/DefaultLogMessageFormatter.cs new file mode 100644 index 000000000..13bdca8ad --- /dev/null +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/DefaultLogMessageFormatter.cs @@ -0,0 +1,123 @@ +#if NET6_0_OR_GREATER + +using System.Text; + +namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging +{ + /// + /// The default log message formatter that log the message as a simple string. Replacing any message properties + /// in the message with provided arguments. The message will be prefixed with the timestamp, request id and + /// log level unless constructed passing in false for addPrefix. + /// + /// This formatter matches is the logging format introduced as part of the .NET 6 managed runtime. + /// + public class DefaultLogMessageFormatter : AbstractLogMessageFormatter + { + /// + /// If true timestamp, request id and log level are added as a prefix to every log message. + /// + public bool AddPrefix { get; } + + /// + /// Constructs an instance of DefaultLogMessageFormatter. + /// + /// If true timestamp, request id and log level are added as a prefix to every log message. + public DefaultLogMessageFormatter(bool addPrefix) + { + AddPrefix = addPrefix; + } + + /// + /// Format the log message applying in message property replacements and adding a prefix unless disabled. + /// + /// + /// + public override string FormatMessage(MessageState state) + { + string message; + + // If there are no arguments then this is not a parameterized log message so skip parsing logic. + if(state.MessageArguments?.Length == 0) + { + message = state.MessageTemplate; + } + else + { + // Parse the message template for any message properties like "{count}". + var messageProperties = ParseProperties(state.MessageTemplate); + + // Replace any message properties in the message template with the provided argument values. + message = ApplyMessageProperties(state.MessageTemplate, messageProperties, state.MessageArguments); + } + + var displayLevel = state.Level != null ? ConvertLogLevelToLabel(state.Level.Value) : null; + + var sb = new StringBuilder( + 25 + // Length for timestamp + (state.AwsRequestId?.Length).GetValueOrDefault() + + displayLevel.Length + + (message?.Length).GetValueOrDefault() + + 5 // Padding for tabs + ); + + if (AddPrefix) + { + sb.Append(FormatTimestamp(state)); + sb.Append('\t'); + sb.Append(state.AwsRequestId); + + if (!string.IsNullOrEmpty(displayLevel)) + { + sb.Append('\t'); + sb.Append(displayLevel); + } + + sb.Append('\t'); + } + + + if (!string.IsNullOrEmpty(message)) + { + sb.Append(message); + } + + if (state.Exception != null) + { + if (!string.IsNullOrEmpty(message)) + { + sb.Append('\n'); + } + sb.Append(state.Exception.ToString()); + } + + return sb.ToString(); + } + + /// + /// Convert LogLevel enums to the the same string label that console provider for Microsoft.Extensions.Logging.ILogger uses. + /// + /// + /// + private string ConvertLogLevelToLabel(LogLevelLoggerWriter.LogLevel level) + { + switch (level) + { + case LogLevelLoggerWriter.LogLevel.Trace: + return "trce"; + case LogLevelLoggerWriter.LogLevel.Debug: + return "dbug"; + case LogLevelLoggerWriter.LogLevel.Information: + return "info"; + case LogLevelLoggerWriter.LogLevel.Warning: + return "warn"; + case LogLevelLoggerWriter.LogLevel.Error: + return "fail"; + case LogLevelLoggerWriter.LogLevel.Critical: + return "crit"; + } + + return level.ToString(); + } + } +} +#endif \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ILogMessageFormatter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ILogMessageFormatter.cs new file mode 100644 index 000000000..732fe7f3d --- /dev/null +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ILogMessageFormatter.cs @@ -0,0 +1,19 @@ +#if NET6_0_OR_GREATER + +namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging +{ + /// + /// The interface for defining log formatters that the ConsoleLogFormatter will use to format the incoming log messages + /// before sending the log message to the Lambda service. + /// + public interface ILogMessageFormatter + { + /// + /// Format the log message + /// + /// + /// + string FormatMessage(MessageState state); + } +} +#endif \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs new file mode 100644 index 000000000..e0e7f2b09 --- /dev/null +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs @@ -0,0 +1,313 @@ +#if NET6_0_OR_GREATER +using System; +using System.Buffers; +using System.Collections; +using System.Collections.Generic; +using System.Globalization; +using System.Runtime.InteropServices; +using System.Text; +using System.Text.Json; +using System.Text.Json.Serialization; + +namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging +{ + /// + /// Formats the log message as a structured JSON log message. + /// + public class JsonLogMessageFormatter : AbstractLogMessageFormatter + { + private static readonly UTF8Encoding UTF8NoBomNoThrow = new UTF8Encoding(encoderShouldEmitUTF8Identifier: false, throwOnInvalidBytes: false); + + // Options used when serializing any message property values as a JSON to be added to the structured log message. + private JsonSerializerOptions _jsonSerializationOptions; + + /// + /// Constructs an instance of JsonLogMessageFormatter. + /// + public JsonLogMessageFormatter() + { + _jsonSerializationOptions = new JsonSerializerOptions + { + DefaultIgnoreCondition = JsonIgnoreCondition.WhenWritingNull, + WriteIndented = false + }; + } + + private static readonly IReadOnlyList _emptyMessageProperties = new List(); + + /// + /// Format the log message as a structured JSON log message. + /// + /// + /// + public override string FormatMessage(MessageState state) + { + IReadOnlyList messageProperties; + string message; + // If there are no arguments then this is not a parameterized log message so skip parsing logic. + if (state.MessageArguments?.Length == 0) + { + messageProperties = _emptyMessageProperties; + message = state.MessageTemplate; + } + else + { + // Parse the message template for any message properties like "{count}". + messageProperties = ParseProperties(state.MessageTemplate); + + // Replace any message properties in the message template with the provided argument values. + message = ApplyMessageProperties(state.MessageTemplate, messageProperties, state.MessageArguments); + } + + + var bufferWriter = new ArrayBufferWriter(); + using var writer = new Utf8JsonWriter(bufferWriter, new JsonWriterOptions + { + Indented = false + }); + writer.WriteStartObject(); + + writer.WriteString("timestamp", FormatTimestamp(state)); + + // Following Serilog's example and use the full name of the level instead of the + // abbreviating done DefaultLogMessageFormatter which follows Microsoft's ILogger console format. + // All structured logging should have a log level. If one is not given the default to Information as the log level. + writer.WriteString("level", state.Level?.ToString() ?? LogLevelLoggerWriter.LogLevel.Information.ToString()); + + if (!string.IsNullOrEmpty(state.AwsRequestId)) + { + writer.WriteString("requestId", state.AwsRequestId); + } + + if (!string.IsNullOrEmpty(state.TraceId)) + { + writer.WriteString("traceId", state.TraceId); + } + + writer.WriteString("message", message); + + // Add any message properties as JSON properties to the structured log. + WriteMessageAttributes(writer, messageProperties, state); + + WriteException(writer, state); + + writer.WriteEndObject(); + writer.Flush(); + + return UTF8NoBomNoThrow.GetString(bufferWriter.WrittenSpan); + } + + /// + /// Write any message properties for the log message as top level JSON properties. + /// + /// + /// + /// + private void WriteMessageAttributes(Utf8JsonWriter writer, IReadOnlyList messageProperties, MessageState state) + { + // Check to see if the message template is using positions instead of names. For example + // "User bought {0} of {1}" is positional as opposed to "User bought {count} of {product"}. + var usePositional = UsingPositionalArguments(messageProperties); + + if (messageProperties == null) + { + return; + } + + for (var i = 0; i < messageProperties.Count; i++) + { + object messageArgument; + if(usePositional) + { + // If usePositional is true then we have confirmed the `Name` property is an int. + var index = int.Parse(messageProperties[i].Name, CultureInfo.InvariantCulture); + if (index < state.MessageArguments.Length) + { + // Don't include null JSON properties + if (state.MessageArguments[index] == null) + continue; + + messageArgument = state.MessageArguments[index]; + } + else + { + continue; + } + } + else + { + // There are more message properties in the template then values for the properties. Skip + // adding anymore JSON properties since there are no more values. + if (state.MessageArguments.Length <= i) + break; + + // Don't include null JSON properties + if (state.MessageArguments[i] == null) + continue; + + messageArgument = state.MessageArguments[i]; + + } + + writer.WritePropertyName(messageProperties[i].Name); + + if (messageArgument is IList && messageArgument is not IList) + { + writer.WriteStartArray(); + foreach (var item in ((IList)messageArgument)) + { + FormatJsonValue(writer, item, messageProperties[i].FormatArgument, messageProperties[i].FormatDirective); + } + writer.WriteEndArray(); + } + else if (messageArgument is IDictionary) + { + writer.WriteStartObject(); + foreach (DictionaryEntry entry in ((IDictionary)messageArgument)) + { + writer.WritePropertyName(entry.Key.ToString() ?? string.Empty); + + FormatJsonValue(writer, entry.Value, messageProperties[i].FormatArgument, messageProperties[i].FormatDirective); + } + writer.WriteEndObject(); + } + else + { + FormatJsonValue(writer, messageArgument, messageProperties[i].FormatArgument, messageProperties[i].FormatDirective); + } + } + } + + /// + /// Add the exception information as top level JSON properties + /// + /// + /// + private void WriteException(Utf8JsonWriter writer, MessageState state) + { + if (state.Exception != null) + { + writer.WriteString("errorType", state.Exception.GetType().FullName); + writer.WriteString("errorMessage", state.Exception.Message); + writer.WritePropertyName("stackTrace"); + writer.WriteStartArray(); + foreach(var line in state.Exception.ToString().Split('\n')) + { + writer.WriteStringValue(line.Trim()); + } + writer.WriteEndArray(); + } + } + + /// + /// Format the value to be included in the structured log message. + /// + /// + /// + /// + /// + [System.Diagnostics.CodeAnalysis.UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026", + Justification = "If formatting an object using JSON serialization this will do its best attempt. If the object has trim errors formatting will fall back to ToString for the object.")] + [System.Diagnostics.CodeAnalysis.UnconditionalSuppressMessage("ReflectionAnalysis", "IL3050", + Justification = "If formatting an object using JSON serialization this will do its best attempt. If the object has trim errors formatting will fall back to ToString for the object.")] + private void FormatJsonValue(Utf8JsonWriter writer, object value, string formatArguments, MessageProperty.Directive directive) + { + if(value == null) + { + writer.WriteNullValue(); + } + else if (directive == MessageProperty.Directive.JsonSerialization) + { + try + { + writer.WriteRawValue(JsonSerializer.Serialize(value, _jsonSerializationOptions)); + } + catch + { + // If running in an AOT environment where the code is trimmed it is possible the reflection based serialization might fail due to code being trimmed. + // In that case fallback to writing the ToString version of the object. + writer.WriteStringValue(value.ToString()); + } + } + else if (!string.IsNullOrEmpty(formatArguments)) + { + writer.WriteStringValue(MessageProperty.ApplyFormatArgument(value, formatArguments)); + } + else + { + switch (value) + { + case bool boolValue: + writer.WriteBooleanValue(boolValue); + break; + case byte byteValue: + writer.WriteNumberValue(byteValue); + break; + case sbyte sbyteValue: + writer.WriteNumberValue(sbyteValue); + break; + case char charValue: + writer.WriteStringValue(MemoryMarshal.CreateSpan(ref charValue, 1)); + break; + case decimal decimalValue: + writer.WriteNumberValue(decimalValue); + break; + case double doubleValue: + writer.WriteNumberValue(doubleValue); + break; + case float floatValue: + writer.WriteNumberValue(floatValue); + break; + case int intValue: + writer.WriteNumberValue(intValue); + break; + case uint uintValue: + writer.WriteNumberValue(uintValue); + break; + case long longValue: + writer.WriteNumberValue(longValue); + break; + case ulong ulongValue: + writer.WriteNumberValue(ulongValue); + break; + case short shortValue: + writer.WriteNumberValue(shortValue); + break; + case ushort ushortValue: + writer.WriteNumberValue(ushortValue); + break; + case null: + writer.WriteNullValue(); + break; + case DateTime dateTimeValue: + writer.WriteStringValue(dateTimeValue.ToString(DateFormat, CultureInfo.InvariantCulture)); + break; + case DateTimeOffset dateTimeOffsetValue: + writer.WriteStringValue(dateTimeOffsetValue.ToString(DateFormat, CultureInfo.InvariantCulture)); + break; + case DateOnly dateOnly: + writer.WriteStringValue(dateOnly.ToString(DateOnlyFormat, CultureInfo.InvariantCulture)); + break; + case TimeOnly timeOnly: + writer.WriteStringValue(timeOnly.ToString(TimeOnlyFormat, CultureInfo.InvariantCulture)); + break; + case byte[] byteArrayValue: + writer.WriteStringValue(MessageProperty.FormatByteArray(byteArrayValue)); + break; + case ReadOnlyMemory roByteArrayValue: + writer.WriteStringValue(MessageProperty.FormatByteArray(roByteArrayValue.Span)); + break; + case Memory meByteArrayValue: + writer.WriteStringValue(MessageProperty.FormatByteArray(meByteArrayValue.Span)); + break; + default: + writer.WriteStringValue(ToInvariantString(value)); + break; + } + } + } + + private static string ToInvariantString(object obj) => Convert.ToString(obj, CultureInfo.InvariantCulture); + } +} +#endif \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/MessageProperty.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/MessageProperty.cs new file mode 100644 index 000000000..1d463163a --- /dev/null +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/MessageProperty.cs @@ -0,0 +1,191 @@ +#if NET6_0_OR_GREATER +using System; +using System.Collections; +using System.Globalization; +using System.Text; + +namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging +{ + /// + /// Represents a message property in a message template. For example the message + /// template "User bought {count} of {product}" has count and product as message properties. + /// + /// + public class MessageProperty + { + private static readonly char[] PARAM_FORMAT_DELIMITERS = { ':' }; + + /// + /// Parse the string representation of the message property without the brackets + /// to construct the MessageProperty. + /// + /// + public MessageProperty(ReadOnlySpan messageToken) + { + // messageToken format is: + // : + + this.MessageToken = "{" + messageToken.ToString() + "}"; + + this.FormatDirective = Directive.Default; + + if (messageToken[0] == '@') + { + this.FormatDirective = Directive.JsonSerialization; + messageToken = messageToken.Slice(1); + } + + var idxOfDelimeter = messageToken.IndexOfAny(PARAM_FORMAT_DELIMITERS); + if (idxOfDelimeter < 0) + { + this.Name = messageToken.ToString().Trim(); + this.FormatArgument = null; + } + else + { + this.Name = messageToken.Slice(0, idxOfDelimeter).ToString().Trim(); + this.FormatArgument = messageToken.Slice(idxOfDelimeter + 1).ToString().Trim(); + if(this.FormatArgument == string.Empty) + { + this.FormatArgument = null; + } + } + } + + /// + /// The original text of the message property. + /// + public string MessageToken { get; private set; } + + /// + /// Enum for controlling the formatting of complex logging arguments. + /// + public enum Directive { + /// + /// Perform a string formatting for the logging argument. + /// + Default, + /// + /// Perform a JSON serialization on the logging argument. + /// + JsonSerialization + }; + + /// + /// The Name of the message property. + /// + public string Name { get; private set; } + + /// + /// Optional format argument. If used the value will be formatted using string.Format passing in this format argument. + /// + public string FormatArgument { get; private set; } + + /// + /// Optional format directive. Gives users the ability + /// to indicate when types should be serialized to JSON when using structured logging. + /// + public Directive FormatDirective { get; private set; } + + /// + /// Formats the value as a string that can be used to replace the message property token inside a message template. + /// + /// + /// + public string FormatForMessage(object value) + { + if(value is byte[] bytes) + { + return FormatByteArray(bytes); + } + if (value is ReadOnlyMemory roBytes) + { + return FormatByteArray(roBytes.Span); + } + if (value is Memory meBytes) + { + return FormatByteArray(meBytes.Span); + } + if (value == null || value is IList || value is IDictionary) + { + return this.MessageToken; + } + if(!string.IsNullOrEmpty(this.FormatArgument)) + { + return ApplyFormatArgument(value, this.FormatArgument); + } + if(value is DateTime dt) + { + return dt.ToString(AbstractLogMessageFormatter.DateFormat, CultureInfo.InvariantCulture); + } + if (value is DateTimeOffset dto) + { + return dto.ToString(AbstractLogMessageFormatter.DateFormat, CultureInfo.InvariantCulture); + } + if (value is DateOnly dateOnly) + { + return dateOnly.ToString(AbstractLogMessageFormatter.DateOnlyFormat, CultureInfo.InvariantCulture); + } + if (value is TimeOnly timeOnly) + { + return timeOnly.ToString(AbstractLogMessageFormatter.TimeOnlyFormat, CultureInfo.InvariantCulture); + } + + return value.ToString(); + } + + /// + /// If format argument is provided formats the value using string.Format otherwise returns + /// the ToString value. + /// + /// + /// + /// + public static string ApplyFormatArgument(object value, string formatArgument) + { + if(string.IsNullOrEmpty(formatArgument)) + { + return value.ToString(); + } + + try + { + var formattedValue = string.Format("{0:" + formatArgument + "}", value); + return formattedValue; + } + catch(FormatException ex) + { + InternalLogger.GetDefaultLogger().LogError(ex, "Failed to apply logging format argument: " + formatArgument); + return value.ToString(); + } + } + + /// + /// Formats byte span, including byte arrays, as a hex string. If the byte span is long the hex string + /// will be truncated with a suffix added for the count of the byte span. + /// + /// + /// + public static string FormatByteArray(ReadOnlySpan bytes) + { + // Follow Serilog's example of outputting at 16 bytes before stopping and adding a count suffix + const int MAX_LENGTH = 16; + + var sb = new StringBuilder(); + for(int i = 0; i < bytes.Length; i++) + { + if(i == MAX_LENGTH) + { + sb.Append("... ("); + sb.Append(bytes.Length); + sb.Append(" bytes)"); + break; + } + + sb.Append(bytes[i].ToString("X2")); + } + return sb.ToString(); + } + } +} +#endif \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/MessageState.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/MessageState.cs new file mode 100644 index 000000000..1a0a5d2a9 --- /dev/null +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/MessageState.cs @@ -0,0 +1,49 @@ +#if NET6_0_OR_GREATER +using System; + +namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging +{ + /// + /// The state of the environment for a log message that needs to be logged. + /// + public class MessageState + { + /// + /// The timestamp of the log message. + /// + public DateTime TimeStamp { get; set; } + + /// + /// The AWS request id for the Lambda invocation. This property can be null + /// if logging before the first event. + /// + public string AwsRequestId { get; set; } + + /// + /// The current trace id if available. + /// + public string TraceId { get; set; } + + /// + /// The message template the Lambda function has sent to RuntimeSupport. It may include message properties in the template + /// for example the message template "User bought {count} of {product}" has count and product as message properties. + /// + public string MessageTemplate { get; set; } + + /// + /// The values to replace for any message properties in the message template. + /// + public object[] MessageArguments { get; set; } + + /// + /// The log level of the message being logged. + /// + public LogLevelLoggerWriter.LogLevel? Level { get; set; } + + /// + /// An exception to be logged along with the log message. + /// + public Exception Exception { get; set; } + } +} +#endif \ No newline at end of file diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/Amazon.Lambda.RuntimeSupport.IntegrationTests.csproj b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/Amazon.Lambda.RuntimeSupport.IntegrationTests.csproj index 086a2e226..1e37f5d9b 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/Amazon.Lambda.RuntimeSupport.IntegrationTests.csproj +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/Amazon.Lambda.RuntimeSupport.IntegrationTests.csproj @@ -20,8 +20,8 @@ - - + + @@ -32,7 +32,7 @@ - + diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/BaseCustomRuntimeTest.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/BaseCustomRuntimeTest.cs index 759d0245e..a0a67f242 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/BaseCustomRuntimeTest.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/BaseCustomRuntimeTest.cs @@ -198,9 +198,11 @@ protected async Task InvokeFunctionAsync(IAmazonLambda lambdaCli return await lambdaClient.InvokeAsync(request); } - protected async Task UpdateHandlerAsync(IAmazonLambda lambdaClient, string handler, Dictionary environmentVariables = null) + protected async Task UpdateHandlerAsync(IAmazonLambda lambdaClient, string handler, Dictionary environmentVariables = null, RuntimeLogLevel? logLevel = null) { - if(environmentVariables == null) + await WaitForFunctionToBeReady(lambdaClient); + + if (environmentVariables == null) { environmentVariables = new Dictionary(); } @@ -216,8 +218,30 @@ protected async Task UpdateHandlerAsync(IAmazonLambda lambdaClient, string handl Variables = environmentVariables } }; + + if (logLevel == null) + { + updateFunctionConfigurationRequest.LoggingConfig = new LoggingConfig + { + LogFormat = LogFormat.Text + }; + } + else + { + updateFunctionConfigurationRequest.LoggingConfig = new LoggingConfig + { + ApplicationLogLevel = ConvertRuntimeLogLevel(logLevel.Value), + LogFormat = LogFormat.JSON + }; + } + await lambdaClient.UpdateFunctionConfigurationAsync(updateFunctionConfigurationRequest); + await WaitForFunctionToBeReady(lambdaClient); + } + + private async Task WaitForFunctionToBeReady(IAmazonLambda lambdaClient) + { // Wait for eventual consistency of function change. var getConfigurationRequest = new GetFunctionConfigurationRequest { FunctionName = FunctionName }; GetFunctionConfigurationResponse getConfigurationResponse = null; @@ -344,5 +368,58 @@ protected class NoDeploymentPackageFoundException : Exception { } + + private ApplicationLogLevel ConvertRuntimeLogLevel(RuntimeLogLevel runtimeLogLevel) + { + switch (runtimeLogLevel) + { + case RuntimeLogLevel.Trace: + return ApplicationLogLevel.TRACE; + case RuntimeLogLevel.Debug: + return ApplicationLogLevel.DEBUG; + case RuntimeLogLevel.Information: + return ApplicationLogLevel.INFO; + case RuntimeLogLevel.Warning: + return ApplicationLogLevel.WARN; + case RuntimeLogLevel.Error: + return ApplicationLogLevel.ERROR; + case RuntimeLogLevel.Critical: + return ApplicationLogLevel.FATAL; + default: + throw new ArgumentException("Unknown log level: " + runtimeLogLevel); + } + } + + public enum RuntimeLogLevel + { + /// + /// Trace level logging + /// + Trace = 0, + /// + /// Debug level logging + /// + Debug = 1, + + /// + /// Information level logging + /// + Information = 2, + + /// + /// Warning level logging + /// + Warning = 3, + + /// + /// Error level logging + /// + Error = 4, + + /// + /// Critical level logging + /// + Critical = 5 + } } } diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/CustomRuntimeTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/CustomRuntimeTests.cs index 75491bbe3..e4af2b9bc 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/CustomRuntimeTests.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.IntegrationTests/CustomRuntimeTests.cs @@ -22,6 +22,7 @@ using System; using System.Collections.Generic; using System.IO; +using System.Linq; using System.Net; using System.Threading; using System.Threading.Tasks; @@ -92,7 +93,7 @@ protected virtual async Task TestAllHandlersAsync() roleAlreadyExisted = await PrepareTestResources(s3Client, lambdaClient, iamClient); // .NET API to address setting memory constraint was added for .NET 8 - if(_targetFramework == TargetFramework.NET8) + if (_targetFramework == TargetFramework.NET8) { await RunMaxHeapMemoryCheck(lambdaClient, "GetTotalAvailableMemoryBytes"); await RunWithoutMaxHeapMemoryCheck(lambdaClient, "GetTotalAvailableMemoryBytes"); @@ -102,8 +103,23 @@ protected virtual async Task TestAllHandlersAsync() await RunTestExceptionAsync(lambdaClient, "ExceptionNonAsciiCharacterUnwrappedAsync", "", "Exception", "Unhandled exception with non ASCII character: ♂"); await RunTestSuccessAsync(lambdaClient, "UnintendedDisposeTest", "not-used", "UnintendedDisposeTest-SUCCESS"); await RunTestSuccessAsync(lambdaClient, "LoggingStressTest", "not-used", "LoggingStressTest-success"); - await RunLoggingTestAsync(lambdaClient, "LoggingTest", null); - await RunLoggingTestAsync(lambdaClient, "LoggingTest", "debug"); + + await RunJsonLoggingWithUnhandledExceptionAsync(lambdaClient); + + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Trace, LogConfigSource.LambdaAPI); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Debug, LogConfigSource.LambdaAPI); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Information, LogConfigSource.LambdaAPI); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Warning, LogConfigSource.LambdaAPI); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Error, LogConfigSource.LambdaAPI); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Critical, LogConfigSource.LambdaAPI); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Trace, LogConfigSource.DotnetEnvironment); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Debug, LogConfigSource.DotnetEnvironment); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Information, LogConfigSource.DotnetEnvironment); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Warning, LogConfigSource.DotnetEnvironment); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Error, LogConfigSource.DotnetEnvironment); + await RunLoggingTestAsync(lambdaClient, "LoggingTest", RuntimeLogLevel.Critical, LogConfigSource.DotnetEnvironment); + + await RunUnformattedLoggingTestAsync(lambdaClient, "LoggingTest"); await RunTestSuccessAsync(lambdaClient, "ToUpperAsync", "message", "ToUpperAsync-MESSAGE"); @@ -136,6 +152,18 @@ protected virtual async Task TestAllHandlersAsync() } } + private async Task RunJsonLoggingWithUnhandledExceptionAsync(AmazonLambdaClient lambdaClient) + { + await UpdateHandlerAsync(lambdaClient, "ThrowUnhandledApplicationException", null, RuntimeLogLevel.Information); + var invokeResponse = await InvokeFunctionAsync(lambdaClient, JsonConvert.SerializeObject("")); + + var log = System.Text.UTF8Encoding.UTF8.GetString(Convert.FromBase64String(invokeResponse.LogResult)); + var exceptionLog = log.Split('\n').FirstOrDefault(x => x.Contains("System.ApplicationException")); + + Assert.NotNull(exceptionLog); + Assert.Contains("\"level\":\"Error\"", exceptionLog); + } + private async Task RunMaxHeapMemoryCheck(AmazonLambdaClient lambdaClient, string handler) { await UpdateHandlerAsync(lambdaClient, handler); @@ -207,14 +235,17 @@ private async Task RunTestExceptionAsync(AmazonLambdaClient lambdaClient, string } } - private async Task RunLoggingTestAsync(AmazonLambdaClient lambdaClient, string handler, string logLevel) + // The .NET Lambda runtime has a legacy environment variable for configuring the log level. This enum is used in the test to choose + // whether the legacy environment variable should be set or use the new properties in the update configuration api for setting log level. + enum LogConfigSource { LambdaAPI, DotnetEnvironment} + private async Task RunLoggingTestAsync(AmazonLambdaClient lambdaClient, string handler, RuntimeLogLevel? runtimeLogLevel, LogConfigSource configSource) { var environmentVariables = new Dictionary(); - if(!string.IsNullOrEmpty(logLevel)) + if(runtimeLogLevel.HasValue && configSource == LogConfigSource.DotnetEnvironment) { - environmentVariables["AWS_LAMBDA_HANDLER_LOG_LEVEL"] = logLevel; + environmentVariables["AWS_LAMBDA_HANDLER_LOG_LEVEL"] = runtimeLogLevel.Value.ToString().ToLowerInvariant(); } - await UpdateHandlerAsync(lambdaClient, handler, environmentVariables); + await UpdateHandlerAsync(lambdaClient, handler, environmentVariables, configSource == LogConfigSource.LambdaAPI ? runtimeLogLevel : null); var invokeResponse = await InvokeFunctionAsync(lambdaClient, JsonConvert.SerializeObject("")); Assert.True(invokeResponse.HttpStatusCode == System.Net.HttpStatusCode.OK); @@ -222,22 +253,65 @@ private async Task RunLoggingTestAsync(AmazonLambdaClient lambdaClient, string h var log = System.Text.UTF8Encoding.UTF8.GetString(Convert.FromBase64String(invokeResponse.LogResult)); - Assert.Contains("info\tA information log", log); - Assert.Contains("warn\tA warning log", log); - Assert.Contains("fail\tA error log", log); - Assert.Contains("crit\tA critical log", log); + if (!runtimeLogLevel.HasValue) + runtimeLogLevel = RuntimeLogLevel.Information; + + if (runtimeLogLevel <= RuntimeLogLevel.Trace) + { + Assert.Contains("A trace log", log); + } + else + { + Assert.DoesNotContain("A trace log", log); + } + + if (runtimeLogLevel <= RuntimeLogLevel.Debug) + { + Assert.Contains("A debug log", log); + } + else + { + Assert.DoesNotContain("A debug log", log); + } + + if (runtimeLogLevel <= RuntimeLogLevel.Information) + { + Assert.Contains("A information log", log); + Assert.Contains("A stdout info message", log); + } + else + { + Assert.DoesNotContain("A information log", log); + Assert.DoesNotContain("A stdout info message", log); + } - Assert.Contains("info\tA stdout info message", log); + if (runtimeLogLevel <= RuntimeLogLevel.Warning) + { + Assert.Contains("A warning log", log); + } + else + { + Assert.DoesNotContain("A warning log", log); + } - Assert.Contains("fail\tA stderror error message", log); + if (runtimeLogLevel <= RuntimeLogLevel.Error) + { + Assert.Contains("A error log", log); + Assert.Contains("A stderror error message", log); + } + else + { + Assert.DoesNotContain("A error log", log); + Assert.DoesNotContain("A stderror error message", log); + } - if (string.IsNullOrEmpty(logLevel)) + if (runtimeLogLevel <= RuntimeLogLevel.Critical) { - Assert.DoesNotContain($"a {logLevel} log".ToLower(), log.ToLower()); + Assert.Contains("A critical log", log); } else { - Assert.Contains($"a {logLevel} log".ToLower(), log.ToLower()); + Assert.DoesNotContain("A critical log", log); } } diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs new file mode 100644 index 000000000..74a0fd13c --- /dev/null +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs @@ -0,0 +1,518 @@ +using Amazon.Lambda.RuntimeSupport.Helpers; +using Amazon.Lambda.RuntimeSupport.Helpers.Logging; +using Microsoft.VisualStudio.TestPlatform.CommunicationUtilities; +using System; +using System.Collections.Generic; +using System.Linq; +using System.Runtime.Serialization; +using System.Text.Json; +using Xunit; +using static Amazon.Lambda.RuntimeSupport.UnitTests.LogMessageFormatterTests; + +namespace Amazon.Lambda.RuntimeSupport.UnitTests +{ + public class LogMessageFormatterTests + { + [Fact] + public void ParseLogMessageWithNoProperties() + { + var formatter = new JsonLogMessageFormatter(); + + var properties = formatter.ParseProperties("No message properties here"); + Assert.Empty(properties); + } + + [Fact] + public void ParseLogMessageWithProperties() + { + var formatter = new JsonLogMessageFormatter(); + + var properties = formatter.ParseProperties("User {user} bought {count:000} items of {@product} with an {{escaped}}"); + Assert.Equal(3, properties.Count); + + Assert.Equal("user", properties[0].Name); + Assert.Equal(MessageProperty.Directive.Default, properties[0].FormatDirective); + + Assert.Equal("count", properties[1].Name); + Assert.Equal("000", properties[1].FormatArgument); + Assert.Equal(MessageProperty.Directive.Default, properties[1].FormatDirective); + + Assert.Equal("product", properties[2].Name); + Assert.Equal(MessageProperty.Directive.JsonSerialization, properties[2].FormatDirective); + } + + [Fact] + public void ParseLogMessageWithOpenBracketAndNoClosing() + { + var formatter = new JsonLogMessageFormatter(); + + var properties = formatter.ParseProperties("{hello} before { after"); + Assert.Equal(1, properties.Count); + + Assert.Equal("hello", properties[0].Name); + Assert.Equal(MessageProperty.Directive.Default, properties[0].FormatDirective); + } + + [Fact] + public void FormatJsonWithNoMessageProperties() + { + var timestamp = DateTime.UtcNow; + var formattedTimestamp = timestamp.ToString("yyyy-MM-ddTHH:mm:ss.fffZ"); + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + TraceId = "4321", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Simple Log Message", + MessageArguments = null, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + Assert.Equal("1234", doc.RootElement.GetProperty("requestId").GetString()); + Assert.Equal("4321", doc.RootElement.GetProperty("traceId").GetString()); + Assert.Equal(formattedTimestamp, doc.RootElement.GetProperty("timestamp").GetString()); + Assert.Equal("Warning", doc.RootElement.GetProperty("level").GetString()); + Assert.Equal("Simple Log Message", doc.RootElement.GetProperty("message").GetString()); + } + + [Fact] + public void FormatJsonWithStringMessageProperties() + { + var timestamp = DateTime.UtcNow; + var formattedTimestamp = timestamp.ToString("yyyy-MM-ddTHH:mm:ss.fffZ"); + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Hello {name}", + MessageArguments = new object[] { "AWS" }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + Assert.Equal("1234", doc.RootElement.GetProperty("requestId").GetString()); + Assert.Equal(formattedTimestamp, doc.RootElement.GetProperty("timestamp").GetString()); + Assert.Equal("Warning", doc.RootElement.GetProperty("level").GetString()); + Assert.Equal("Hello AWS", doc.RootElement.GetProperty("message").GetString()); + } + + [Fact] + public void FormatJsonWithAllPossibleTypes() + { + var dateOnly = new DateOnly(2024, 2, 18); + var timeOnly = new TimeOnly(15, 19, 45, 545); + var timestamp = DateTime.UtcNow; + var formattedTimestamp = timestamp.ToString("yyyy-MM-ddTHH:mm:ss.fffZ"); + + var product = new Product() { Name = "Widget", Inventory = 100 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "bool: {bool}, byte: {byte}, char: {char}, decimal: {decimal}, double: {double}, float: {float}, " + + "int: {int}, uint: {uint}, long: {long}, ulong: {ulong}, short: {short}, ushort: {ushort}, null: {null}, " + + "DateTime: {DateTime}, DateTimeOffset: {DateTimeOffset}, default: {default}, DateOnly {DateOnly}, TimeOnly: {TimeOnly}", + MessageArguments = new object[] {true, (byte)1, 'a', (decimal)4.5, (double)5.6, (float)7.7, (int)-10, (uint)10, (long)-100, (ulong)100, (short)-50, (ushort)50, null, timestamp, timestamp, product, dateOnly, timeOnly}, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("bool: True, byte: 1, char: a, decimal: 4.5, double: 5.6, float: 7.7, " + + "int: -10, uint: 10, long: -100, ulong: 100, short: -50, ushort: 50, null: {null}, " + + $"DateTime: {formattedTimestamp}, DateTimeOffset: {formattedTimestamp}, default: Widget 100, DateOnly 2024-02-18, TimeOnly: 15:19:45.545", + doc.RootElement.GetProperty("message").GetString()); + + Assert.True(doc.RootElement.GetProperty("bool").GetBoolean()); + Assert.Equal((byte)1, doc.RootElement.GetProperty("byte").GetByte()); + Assert.Equal("a", doc.RootElement.GetProperty("char").GetString()); + Assert.Equal((decimal)4.5, doc.RootElement.GetProperty("decimal").GetDecimal()); + Assert.Equal((double)5.6, doc.RootElement.GetProperty("double").GetDouble()); + Assert.Equal((float)7.7, doc.RootElement.GetProperty("float").GetSingle()); + Assert.Equal((int)-10, doc.RootElement.GetProperty("int").GetInt32()); + Assert.Equal((uint)10, doc.RootElement.GetProperty("uint").GetUInt32()); + Assert.Equal((long)-100, doc.RootElement.GetProperty("long").GetInt64()); + Assert.Equal((ulong)100, doc.RootElement.GetProperty("ulong").GetUInt64()); + Assert.Equal((short)-50, doc.RootElement.GetProperty("short").GetInt16()); + Assert.Equal((ushort)50, doc.RootElement.GetProperty("ushort").GetUInt16()); + Assert.False(doc.RootElement.TryGetProperty("null", out var _)); + Assert.Equal(formattedTimestamp, doc.RootElement.GetProperty("DateTime").GetString()); + Assert.Equal(formattedTimestamp, doc.RootElement.GetProperty("DateTimeOffset").GetString()); + Assert.Equal("Widget 100", doc.RootElement.GetProperty("default").GetString()); + Assert.Equal("2024-02-18", doc.RootElement.GetProperty("DateOnly").GetString()); + Assert.Equal("15:19:45.545", doc.RootElement.GetProperty("TimeOnly").GetString()); + } + + [Fact] + public void FormatJsonWithPoco() + { + var timestamp = DateTime.UtcNow; + + var product = new Product() { Name = "Widget", Inventory = 100 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Our product is {product}", + MessageArguments = new object[] { product }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("Our product is Widget 100", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal(JsonValueKind.String, doc.RootElement.GetProperty("product").ValueKind); + Assert.Equal("Widget 100", doc.RootElement.GetProperty("product").GetString()); + } + + [Fact] + public void FormatJsonWithPocoSerialized() + { + var timestamp = DateTime.UtcNow; + + var product = new Product() { Name = "Widget", Inventory = 100 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Our product is {@product}", + MessageArguments = new object[] { product }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("Our product is Widget 100", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal(JsonValueKind.Object, doc.RootElement.GetProperty("product").ValueKind); + Assert.Equal("Widget", doc.RootElement.GetProperty("product").GetProperty("Name").GetString()); + Assert.Equal(100, doc.RootElement.GetProperty("product").GetProperty("Inventory").GetInt32()); + } + + [Fact] + public void FormatJsonWithList() + { + var timestamp = DateTime.UtcNow; + + var product1 = new Product() { Name = "Widget", Inventory = 100 }; + var product2 = new Product() { Name = "Doohickey", Inventory = 200 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Our products are {products}", + MessageArguments = new object[] { new Product[] { product1, product2 } }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("Our products are {products}", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal(JsonValueKind.Array, doc.RootElement.GetProperty("products").ValueKind); + Assert.Equal("Widget 100", doc.RootElement.GetProperty("products")[0].GetString()); + Assert.Equal("Doohickey 200", doc.RootElement.GetProperty("products")[1].GetString()); + } + + [Fact] + public void FormatJsonWithListSerialzied() + { + var timestamp = DateTime.UtcNow; + + var product1 = new Product() { Name = "Widget", Inventory = 100 }; + var product2 = new Product() { Name = "Doohickey", Inventory = 200 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Our products are {@products}", + MessageArguments = new object[] { new Product[] { product1, product2 } }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("Our products are {@products}", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal(JsonValueKind.Array, doc.RootElement.GetProperty("products").ValueKind); + Assert.Equal("Widget", doc.RootElement.GetProperty("products")[0].GetProperty("Name").GetString()); + Assert.Equal(100, doc.RootElement.GetProperty("products")[0].GetProperty("Inventory").GetInt32()); + + Assert.Equal("Doohickey", doc.RootElement.GetProperty("products")[1].GetProperty("Name").GetString()); + Assert.Equal(200, doc.RootElement.GetProperty("products")[1].GetProperty("Inventory").GetInt32()); + } + + [Fact] + public void FormatJsonWithDictionary() + { + var timestamp = DateTime.UtcNow; + + var product1 = new Product() { Name = "Widget", Inventory = 100 }; + var product2 = new Product() { Name = "Doohickey", Inventory = 200 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Our products are {products}", + MessageArguments = new object[] { new Dictionary { { product1.Name, product1 }, { product2.Name, product2 } } }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("Our products are {products}", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal(JsonValueKind.Object, doc.RootElement.GetProperty("products").ValueKind); + Assert.Equal("Widget 100", doc.RootElement.GetProperty("products").GetProperty("Widget").GetString()); + Assert.Equal("Doohickey 200", doc.RootElement.GetProperty("products").GetProperty("Doohickey").GetString()); + } + + [Fact] + public void FormatJsonWithDictionarySerialized() + { + var timestamp = DateTime.UtcNow; + + var product1 = new Product() { Name = "Widget", Inventory = 100 }; + var product2 = new Product() { Name = "Doohickey", Inventory = 200 }; + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Our products are {@products}", + MessageArguments = new object[] { new Dictionary { { product1.Name, product1 }, { product2.Name, product2 } } }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("Our products are {@products}", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal(JsonValueKind.Object, doc.RootElement.GetProperty("products").ValueKind); + Assert.Equal("Widget", doc.RootElement.GetProperty("products").GetProperty("Widget").GetProperty("Name").GetString()); + Assert.Equal(100, doc.RootElement.GetProperty("products").GetProperty("Widget").GetProperty("Inventory").GetInt32()); + Assert.Equal("Doohickey", doc.RootElement.GetProperty("products").GetProperty("Doohickey").GetProperty("Name").GetString()); + Assert.Equal(200, doc.RootElement.GetProperty("products").GetProperty("Doohickey").GetProperty("Inventory").GetInt32()); + } + + [Theory] + [InlineData("No Properties", new object[] { }, "No Properties")] + [InlineData("No Properties", null, "No Properties")] + [InlineData("{name}", new object[] { "aws" } , "aws")] + [InlineData("{0}", new object[] { "aws" }, "aws")] + [InlineData("{0} {1}", new object[] { "aws" }, "aws {1}")] + [InlineData("{0}", new object[] { "aws", "s3" }, "aws")] + [InlineData("{{name}} {name}", new object[] { "aws" }, "{{name}} aws")] + [InlineData("Positional test {0} {1} {0}", new object[] {"Arg1", "Arg2" }, "Positional test Arg1 Arg2 Arg1")] + [InlineData("{category}", new object[] { Product.Category.Electronics }, "Electronics")] + [InlineData("{hextest}", new object[] { new byte[] { 1, 2, 3 } }, "010203")] + [InlineData("{}", new object[] { "dummy" }, "{}")] // Log message doesn't really make any sense but we need to make sure we protect ourselves from it. + public void PropertyReplacementVerification(string message, object[] arguments, string expectedMessage) + { + foreach(var formatter in new AbstractLogMessageFormatter[] { new DefaultLogMessageFormatter(false), new DefaultLogMessageFormatter(true), new JsonLogMessageFormatter() }) + { + var timestamp = DateTime.UtcNow; + + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = message, + MessageArguments = arguments, + TimeStamp = timestamp + }; + + var formattedMessage = formatter.FormatMessage(state); + + if(formatter is JsonLogMessageFormatter) + { + var doc = JsonDocument.Parse(formattedMessage); + Assert.Equal(expectedMessage, doc.RootElement.GetProperty("message").GetString()); + } + else if(formatter is DefaultLogMessageFormatter defaultFormatter) + { + if(defaultFormatter.AddPrefix) + { + Assert.EndsWith(expectedMessage, formattedMessage); + } + else + { + Assert.Equal(expectedMessage, formattedMessage); + } + } + } + + if (arguments?.Length == 1 && arguments[0] is byte[] bytes) + { + // Can't create ReadOnlyMemory and Memory as part of the "InlineData" attribute so force check + // if we are doing the byte[] check and if so repeat for ReadonlyMemory and Memory + PropertyReplacementVerification(message, new object[] { new ReadOnlyMemory(bytes) }, expectedMessage); + PropertyReplacementVerification(message, new object[] { new Memory(bytes) }, expectedMessage); + } + } + + [Fact] + public void OutOfOrderPositionalArgumentsWithJson() + { + var timestamp = DateTime.UtcNow; + + + var formatter = new JsonLogMessageFormatter(); + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "{1} {0}", + MessageArguments = new object[] { "arg1", "arg2" }, + TimeStamp = timestamp + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("arg2 arg1", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal("arg1", doc.RootElement.GetProperty("0").GetString()); + Assert.Equal("arg2", doc.RootElement.GetProperty("1").GetString()); ; + + } + + [Fact] + public void FormatLargeByteArray() + { + var timestamp = DateTime.UtcNow; + + var bytes = new byte[10000]; + for (var i = 0; i < bytes.Length; i++) + { + bytes[i] = 1; + } + + foreach (var argument in new object [] { bytes, new ReadOnlyMemory(bytes), new Memory(bytes) }) + { + + + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "Binary data: {bytes}", + MessageArguments = new object[] { argument }, + TimeStamp = timestamp + }; + + var formatter = new JsonLogMessageFormatter(); + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal($"Binary data: 01010101010101010101010101010101... ({bytes.Length} bytes)", doc.RootElement.GetProperty("message").GetString()); + + Assert.Equal($"01010101010101010101010101010101... ({bytes.Length} bytes)", doc.RootElement.GetProperty("bytes").GetString()); + + + } + } + + [Fact] + public void FormatJsonException() + { + try + { + var nre = new NullReferenceException("You got a null"); + throw new ApplicationException("This Will Fail", nre); + } + catch(Exception ex) + { + var timestamp = DateTime.UtcNow; + + var state = new MessageState() + { + AwsRequestId = "1234", + Level = Helpers.LogLevelLoggerWriter.LogLevel.Warning, + MessageTemplate = "What does an error look like?", + MessageArguments = null, + Exception = ex, + TimeStamp = timestamp + }; + + var formatter = new JsonLogMessageFormatter(); + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + Assert.Equal("What does an error look like?", doc.RootElement.GetProperty("message").GetString()); + Assert.Equal("This Will Fail", doc.RootElement.GetProperty("errorMessage").GetString()); + Assert.Equal("System.ApplicationException", doc.RootElement.GetProperty("errorType").GetString()); + Assert.Equal(JsonValueKind.Array, doc.RootElement.GetProperty("stackTrace").ValueKind); + + var stackLines = ex.ToString().Split('\n').Select(x => x.Trim()).ToList(); + var jsonExArray = doc.RootElement.GetProperty("stackTrace"); + Assert.Equal(stackLines.Count, jsonExArray.GetArrayLength()); + for(var i = 0; i < stackLines.Count; i++) + { + Assert.Equal(stackLines[i], jsonExArray[i].GetString()); + } + } + } + + [Theory] + [InlineData("{0}", true)] + [InlineData("{1} {0}", true)] + [InlineData("{1} {10}", false)] + [InlineData("{1} {2}", false)] + [InlineData("{0} {5} {6}", false)] + [InlineData("Arg1 {0} Arg2 {1}", true)] + [InlineData("Test {user}", false)] + [InlineData("Arg1 {0} Arg5 {5}", false)] // Not positional because there is a gap in between the numbers + [InlineData("Arg1 {@0} Arg2 {1:00}", true)] + public void CheckIfPositional(string message, bool expected) + { + var formatter = new DefaultLogMessageFormatter(true); + var properties = formatter.ParseProperties(message); + var isPositional = formatter.UsingPositionalArguments(properties); + Assert.Equal(expected, isPositional); + } + + public class Product + { + public enum Category { Food, Electronics } + public string Name { get; set; } + + public int Inventory { get; set; } + + public Category? Cat { get; set; } + + public override string ToString() + { + return $"{Name} {Inventory}"; + } + } + } +} diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/MessagePropertyTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/MessagePropertyTests.cs new file mode 100644 index 000000000..f49457c0c --- /dev/null +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/MessagePropertyTests.cs @@ -0,0 +1,98 @@ +using Amazon.Lambda.RuntimeSupport.Helpers.Logging; + +using Xunit; + +namespace Amazon.Lambda.RuntimeSupport.UnitTests +{ + + public class MessagePropertyTests + { + [Fact] + public void SimpleName() + { + var property = new MessageProperty("name"); + Assert.Equal(MessageProperty.Directive.Default, property.FormatDirective); + Assert.Equal("name", property.Name); + Assert.Equal("{name}", property.MessageToken); + Assert.Null(property.FormatArgument); + } + + [Fact] + public void WithFormatArgument() + { + var property = new MessageProperty("count:000"); + Assert.Equal(MessageProperty.Directive.Default, property.FormatDirective); + Assert.Equal("count", property.Name); + Assert.Equal("{count:000}", property.MessageToken); + Assert.Equal("000", property.FormatArgument); + } + + [Fact] + public void WithJsonDirective() + { + var property = new MessageProperty("@user"); + Assert.Equal(MessageProperty.Directive.JsonSerialization, property.FormatDirective); + Assert.Equal("user", property.Name); + Assert.Equal("{@user}", property.MessageToken); + Assert.Null(property.FormatArgument); + } + + [Fact] + public void WithJsonDirectiveAndIgnorableFormatArgument() + { + var property = new MessageProperty("@user:000"); + Assert.Equal(MessageProperty.Directive.JsonSerialization, property.FormatDirective); + Assert.Equal("user", property.Name); + Assert.Equal("{@user:000}", property.MessageToken); + Assert.Equal("000", property.FormatArgument); + } + + [Fact] + public void WithFormatArgumentMissingValues() + { + var property = new MessageProperty("count:"); + Assert.Equal(MessageProperty.Directive.Default, property.FormatDirective); + Assert.Equal("count", property.Name); + Assert.Equal("{count:}", property.MessageToken); + Assert.Null(property.FormatArgument); + } + + [Fact] + public void NameWithSpace() + { + var property = new MessageProperty(" first last "); + Assert.Equal(MessageProperty.Directive.Default, property.FormatDirective); + Assert.Equal("first last", property.Name); + Assert.Equal("{ first last }", property.MessageToken); + Assert.Null(property.FormatArgument); + } + + [Fact] + public void NameAndFormatArgumentWithSpace() + { + var property = new MessageProperty(" first last : 000 "); + Assert.Equal(MessageProperty.Directive.Default, property.FormatDirective); + Assert.Equal("first last", property.Name); + Assert.Equal("{ first last : 000 }", property.MessageToken); + Assert.Equal("000", property.FormatArgument); + } + + [Fact] + public void ApplyFormat() + { + var property = new MessageProperty("count:000"); + var formattedValue = MessageProperty.ApplyFormatArgument(10, property.FormatArgument); + Assert.Equal("010", formattedValue); + } + + [Fact] + public void ApplyFormatTriggersFormatException() + { + var property = new MessageProperty("count:0{0"); + + // Since a FormatException was thrown the code should fall back to "ToString()" on the value + var formattedValue = MessageProperty.ApplyFormatArgument(10, property.FormatArgument); + Assert.Equal("10", formattedValue); + } + } +} diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/NativeAOTTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/NativeAOTTests.cs new file mode 100644 index 000000000..ae7f7aaf7 --- /dev/null +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/NativeAOTTests.cs @@ -0,0 +1,100 @@ +using System; +using System.Diagnostics; +using System.Text; +using System.Reflection; + +using Xunit; +using Xunit.Abstractions; +using System.IO; + +#if NET8_0_OR_GREATER +namespace Amazon.Lambda.RuntimeSupport.UnitTests +{ + public class NativeAOTTests + { + private ITestOutputHelper _output; + + public NativeAOTTests(ITestOutputHelper output) + { + _output = output; + } + + [Fact] + public void EnsureNoTrimWarningsDuringPublish() + { + var projectDirectory = FindProject("NativeAOTFunction"); + + _output.WriteLine("dotnet publish " + projectDirectory); + var output = ExecutePublish(projectDirectory); + _output.WriteLine(output.Log); + + Assert.True(output.ExitCode == 0); + Assert.DoesNotContain("AOT analysis warning", output.Log); + } + + private (int ExitCode, string Log) ExecutePublish(string projectDirectory) + { + var buffer = new StringBuilder(); + var handler = (DataReceivedEventHandler)((o, e) => + { + if (string.IsNullOrEmpty(e.Data)) + return; + + buffer.AppendLine(e.Data); + }); + + var startInfo = new ProcessStartInfo + { + FileName = "dotnet", + Arguments = $"publish", + WorkingDirectory = projectDirectory, + RedirectStandardOutput = true, + RedirectStandardError = true, + UseShellExecute = false, + CreateNoWindow = true + }; + + int exitCode; + using (var proc = new Process()) + { + proc.StartInfo = startInfo; + proc.Start(); + + if (startInfo.RedirectStandardOutput) + { + proc.ErrorDataReceived += handler; + proc.OutputDataReceived += handler; + proc.BeginOutputReadLine(); + proc.BeginErrorReadLine(); + + proc.EnableRaisingEvents = true; + } + + proc.WaitForExit(); + + + exitCode = proc.ExitCode; + } + + return (exitCode, buffer.ToString()); + } + + private string FindProject(string projectName) + { + var directory = Assembly.GetExecutingAssembly().Location; + while (directory != null) + { + var fullpath = Path.Combine(directory, projectName); + if (Directory.Exists(fullpath)) + { + return fullpath; + } + + directory = Directory.GetParent(directory)?.FullName; + } + + throw new Exception("Failed to find project directory " + projectName); + } + } +} +#endif \ No newline at end of file diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/TestHelpers/TestRuntimeApiClient.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/TestHelpers/TestRuntimeApiClient.cs index f64993597..bf449e803 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/TestHelpers/TestRuntimeApiClient.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/TestHelpers/TestRuntimeApiClient.cs @@ -12,6 +12,7 @@ * express or implied. See the License for the specific language governing * permissions and limitations under the License. */ +using Amazon.Lambda.RuntimeSupport.Helpers; using Amazon.Lambda.RuntimeSupport.UnitTests.TestHelpers; using System; using System.Collections.Generic; @@ -28,6 +29,8 @@ internal class TestRuntimeApiClient : IRuntimeApiClient private IEnvironmentVariables _environmentVariables; private Dictionary> _headers; + public IConsoleLoggerWriter ConsoleLogger { get; } = new LogLevelLoggerWriter(); + public TestRuntimeApiClient(IEnvironmentVariables environmentVariables, Dictionary> headers) { _environmentVariables = environmentVariables; diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/CustomRuntimeFunctionTest/CustomRuntimeFunction.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/CustomRuntimeFunctionTest/CustomRuntimeFunction.cs index 60f6a3418..c803a20f6 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/CustomRuntimeFunctionTest/CustomRuntimeFunction.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/CustomRuntimeFunctionTest/CustomRuntimeFunction.cs @@ -98,6 +98,10 @@ private static async Task Main(string[] args) case nameof(GetTimezoneNameAsync): bootstrap = new LambdaBootstrap(GetTimezoneNameAsync); break; + case nameof(ThrowUnhandledApplicationException): + handlerWrapper = HandlerWrapper.GetHandlerWrapper((Action)ThrowUnhandledApplicationException); + bootstrap = new LambdaBootstrap(handlerWrapper); + break; default: throw new Exception($"Handler {handler} is not supported."); } @@ -374,6 +378,11 @@ private static void AggregateExceptionNotUnwrapped() throw new AggregateException("AggregateException thrown from a synchronous handler."); } + private static void ThrowUnhandledApplicationException() + { + throw new ApplicationException("Function fail"); + } + private static Task TooLargeResponseBodyAsync(InvocationRequest invocation) { return Task.FromResult(GetInvocationResponse(nameof(TooLargeResponseBodyAsync), SevenMBString.Value)); diff --git a/Libraries/test/NativeAOTFunction/Function.cs b/Libraries/test/NativeAOTFunction/Function.cs new file mode 100644 index 000000000..0baf56ce7 --- /dev/null +++ b/Libraries/test/NativeAOTFunction/Function.cs @@ -0,0 +1,60 @@ +using Amazon.Lambda.Core; +using Amazon.Lambda.RuntimeSupport; +using Amazon.Lambda.Serialization.SystemTextJson; +using System.Text.Json.Serialization; + +namespace StructureAOTTest; + +public class Function +{ + /// + /// The main entry point for the Lambda function. The main function is called once during the Lambda init phase. It + /// initializes the .NET Lambda runtime client passing in the function handler to invoke for each Lambda event and + /// the JSON serializer to use for converting Lambda JSON format to the .NET types. + /// + private static async Task Main() + { + Func handler = FunctionHandler; + await LambdaBootstrapBuilder.Create(handler, new SourceGeneratorLambdaJsonSerializer()) + .Build() + .RunAsync(); + } + + /// + /// A simple function that takes a string and does a ToUpper. + /// + /// To use this handler to respond to an AWS event, reference the appropriate package from + /// https://github.com/aws/aws-lambda-dotnet#events + /// and change the string input parameter to the desired event type. When the event type + /// is changed, the handler type registered in the main method needs to be updated and the LambdaFunctionJsonSerializerContext + /// defined below will need the JsonSerializable updated. If the return type and event type are different then the + /// LambdaFunctionJsonSerializerContext must have two JsonSerializable attributes, one for each type. + /// + // When using Native AOT extra testing with the deployed Lambda functions is required to ensure + // the libraries used in the Lambda function work correctly with Native AOT. If a runtime + // error occurs about missing types or methods the most likely solution will be to remove references to trim-unsafe + // code or configure trimming options. This sample defaults to partial TrimMode because currently the AWS + // SDK for .NET does not support trimming. This will result in a larger executable size, and still does not + // guarantee runtime trimming errors won't be hit. + /// + /// The event for the Lambda function handler to process. + /// The ILambdaContext that provides methods for logging and describing the Lambda environment. + /// + public static string FunctionHandler(string input, ILambdaContext context) + { + return input.ToUpper(); + } +} + +/// +/// This class is used to register the input event and return type for the FunctionHandler method with the System.Text.Json source generator. +/// There must be a JsonSerializable attribute for each type used as the input and return type or a runtime error will occur +/// from the JSON serializer unable to find the serialization information for unknown types. +/// +[JsonSerializable(typeof(string))] +public partial class LambdaFunctionJsonSerializerContext : JsonSerializerContext +{ + // By using this partial class derived from JsonSerializerContext, we can generate reflection free JSON Serializer code at compile time + // which can deserialize our class and properties. However, we must attribute this class to tell it what types to generate serialization code for. + // See https://docs.microsoft.com/en-us/dotnet/standard/serialization/system-text-json-source-generation +} \ No newline at end of file diff --git a/Libraries/test/NativeAOTFunction/NativeAOTFunction.csproj b/Libraries/test/NativeAOTFunction/NativeAOTFunction.csproj new file mode 100644 index 000000000..bc83e5d2e --- /dev/null +++ b/Libraries/test/NativeAOTFunction/NativeAOTFunction.csproj @@ -0,0 +1,25 @@ + + + Exe + net8.0 + enable + enable + Lambda + + true + + true + + true + + partial + false + + + + + + + \ No newline at end of file diff --git a/Libraries/test/NativeAOTFunction/aws-lambda-tools-defaults.json b/Libraries/test/NativeAOTFunction/aws-lambda-tools-defaults.json new file mode 100644 index 000000000..f7e8c52a4 --- /dev/null +++ b/Libraries/test/NativeAOTFunction/aws-lambda-tools-defaults.json @@ -0,0 +1,16 @@ +{ + "Information": [ + "This file provides default values for the deployment wizard inside Visual Studio and the AWS Lambda commands added to the .NET Core CLI.", + "To learn more about the Lambda commands with the .NET Core CLI execute the following command at the command line in the project root directory.", + "dotnet lambda help", + "All the command line options for the Lambda command can be specified in this file." + ], + "profile": "default", + "region": "us-west-2", + "configuration": "Release", + "function-runtime": "dotnet8", + "function-memory-size": 512, + "function-timeout": 30, + "function-handler": "NativeAOTFunction", + "msbuild-parameters": "--self-contained true" +} \ No newline at end of file diff --git a/Libraries/test/TestServerlessApp/serverless.template b/Libraries/test/TestServerlessApp/serverless.template index a35892ed3..969ae9c9f 100644 --- a/Libraries/test/TestServerlessApp/serverless.template +++ b/Libraries/test/TestServerlessApp/serverless.template @@ -766,7 +766,7 @@ "Tool": "Amazon.Lambda.Annotations" }, "Properties": { - "MemorySize": 512, + "MemorySize": 256, "Timeout": 30, "Policies": [ "AWSLambdaBasicExecutionRole"