diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.cs index 72e6ae6afce77a..357af5e8600dc4 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.cs +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.cs @@ -6,6 +6,18 @@ namespace Microsoft.Extensions.Logging { + public ref partial struct BufferWriter + { + private object _dummy; + private int _dummyPrimitive; + public BufferWriter(System.Buffers.IBufferWriter bufferWriter) { throw null; } + public System.Span CurrentSpan { get { throw null; } } + public System.Buffers.IBufferWriter Writer { get { throw null; } } + public void Advance(int len) { } + public void EnsureSize(int minSize) { } + public void Flush() { } + public void Grow(int minSize) { } + } public readonly partial struct EventId : System.IEquatable { private readonly object _dummy; @@ -21,11 +33,29 @@ namespace Microsoft.Extensions.Logging public static bool operator !=(Microsoft.Extensions.Logging.EventId left, Microsoft.Extensions.Logging.EventId right) { throw null; } public override string ToString() { throw null; } } + public delegate void FormatPropertyAction(PropType propertyValue, ref Microsoft.Extensions.Logging.BufferWriter bufferWriter); + public delegate void FormatPropertyListAction(in TState state, ref Microsoft.Extensions.Logging.BufferWriter bufferWriter); + public delegate void FormatSpanPropertyAction(System.ReadOnlySpan propertyValue, ref Microsoft.Extensions.Logging.BufferWriter bufferWriter); public partial interface IExternalScopeProvider { void ForEachScope(System.Action callback, TState state); System.IDisposable Push(object? state); } + public partial interface ILogEntryPipelineFactory + { + Microsoft.Extensions.Logging.LogEntryPipeline? GetLoggingPipeline(Microsoft.Extensions.Logging.ILogMetadata? metadata, object? userState); + Microsoft.Extensions.Logging.ScopePipeline? GetScopePipeline(Microsoft.Extensions.Logging.ILogMetadata? metadata, object? userState) where TState : notnull; + } + public partial interface ILogEntryProcessor + { + Microsoft.Extensions.Logging.LogEntryHandler GetLogEntryHandler(Microsoft.Extensions.Logging.ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired); + Microsoft.Extensions.Logging.ScopeHandler GetScopeHandler(Microsoft.Extensions.Logging.ILogMetadata? metadata, out bool enabled) where TState : notnull; + bool IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel); + } + public partial interface ILogEntryProcessorFactory + { + Microsoft.Extensions.Logging.ProcessorContext GetProcessor(); + } public partial interface ILogger { System.IDisposable? BeginScope(TState state) where TState : notnull; @@ -44,6 +74,27 @@ public partial interface ILoggerProvider : System.IDisposable public partial interface ILogger : Microsoft.Extensions.Logging.ILogger { } + public partial interface ILogMetadata + { + Microsoft.Extensions.Logging.EventId EventId { get; } + Microsoft.Extensions.Logging.LogLevel LogLevel { get; } + string OriginalFormat { get; } + int PropertyCount { get; } + void AppendFormattedMessage(in TState state, System.Buffers.IBufferWriter buffer); + System.Action> GetMessageFormatter(Microsoft.Extensions.Logging.PropertyCustomFormatter[] customFormatters); + Microsoft.Extensions.Logging.LogPropertyInfo GetPropertyInfo(int index); + Microsoft.Extensions.Logging.FormatPropertyListAction GetPropertyListFormatter(Microsoft.Extensions.Logging.IPropertyFormatterFactory propertyFormatterFactory); + System.Func GetStringMessageFormatter(); + } + public partial interface IProcessorFactory + { + Microsoft.Extensions.Logging.ILogEntryProcessor GetProcessor(Microsoft.Extensions.Logging.ILogEntryProcessor nextProcessor); + } + public partial interface IPropertyFormatterFactory + { + Microsoft.Extensions.Logging.FormatPropertyAction GetPropertyFormatter(int propertyIndex, Microsoft.Extensions.Logging.LogPropertyInfo metadata); + Microsoft.Extensions.Logging.FormatSpanPropertyAction GetSpanPropertyFormatter(int propertyIndex, Microsoft.Extensions.Logging.LogPropertyInfo metadata); + } public partial interface ISupportExternalScope { void SetScopeProvider(Microsoft.Extensions.Logging.IExternalScopeProvider scopeProvider); @@ -51,8 +102,21 @@ public partial interface ISupportExternalScope public partial class LogDefineOptions { public LogDefineOptions() { } + public object[]?[]? ParameterMetadata { get { throw null; } set { } } public bool SkipEnabledCheck { get { throw null; } set { } } } + public abstract partial class LogEntryHandler + { + protected LogEntryHandler() { } + public abstract void HandleLogEntry(ref Microsoft.Extensions.Logging.Abstractions.LogEntry logEntry); + public abstract bool IsEnabled(Microsoft.Extensions.Logging.LogLevel level); + } + public partial class LogEntryPipeline : Microsoft.Extensions.Logging.Pipeline + { + public LogEntryPipeline(Microsoft.Extensions.Logging.LogEntryHandler handler, object? userState, bool isEnabled, bool isDynamicLevelCheckRequired) : base (default(object), default(bool), default(bool)) { } + public void HandleLogEntry(ref Microsoft.Extensions.Logging.Abstractions.LogEntry logEntry) { } + public bool IsEnabledDynamic(Microsoft.Extensions.Logging.LogLevel level) { throw null; } + } public static partial class LoggerExtensions { public static System.IDisposable? BeginScope(this Microsoft.Extensions.Logging.ILogger logger, string messageFormat, params object?[] args) { throw null; } @@ -107,6 +171,7 @@ public static partial class LoggerMessage public static System.Func DefineScope(string formatString) { throw null; } public static System.Func DefineScope(string formatString) { throw null; } public static System.Func DefineScope(string formatString) { throw null; } + public static Microsoft.Extensions.Logging.LoggerMessage.Log Define(Microsoft.Extensions.Logging.ILogMetadata metadata, Microsoft.Extensions.Logging.LogDefineOptions? options = null) { throw null; } public static System.Action Define(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, string formatString) { throw null; } public static System.Action Define(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, string formatString, Microsoft.Extensions.Logging.LogDefineOptions? options) { throw null; } public static System.Action Define(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, string formatString) { throw null; } @@ -119,6 +184,7 @@ public static partial class LoggerMessage public static System.Action Define(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, string formatString, Microsoft.Extensions.Logging.LogDefineOptions? options) { throw null; } public static System.Action Define(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, string formatString) { throw null; } public static System.Action Define(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, string formatString, Microsoft.Extensions.Logging.LogDefineOptions? options) { throw null; } + public delegate void Log(Microsoft.Extensions.Logging.ILogger logger, ref TState state, System.Exception? exception); } [System.AttributeUsageAttribute(System.AttributeTargets.Method)] public sealed partial class LoggerMessageAttribute : System.Attribute @@ -131,10 +197,12 @@ public LoggerMessageAttribute(int eventId, Microsoft.Extensions.Logging.LogLevel public string Message { get { throw null; } set { } } public bool SkipEnabledCheck { get { throw null; } set { } } } - public partial class Logger : Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.ILogger + public partial class Logger : Microsoft.Extensions.Logging.ILogEntryPipelineFactory, Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.ILogger { public Logger(Microsoft.Extensions.Logging.ILoggerFactory factory) { } - System.IDisposable? Microsoft.Extensions.Logging.ILogger.BeginScope(TState state) { throw null; } + Microsoft.Extensions.Logging.LogEntryPipeline Microsoft.Extensions.Logging.ILogEntryPipelineFactory.GetLoggingPipeline(Microsoft.Extensions.Logging.ILogMetadata? metadata, object? userState) { throw null; } + Microsoft.Extensions.Logging.ScopePipeline Microsoft.Extensions.Logging.ILogEntryPipelineFactory.GetScopePipeline(Microsoft.Extensions.Logging.ILogMetadata? metadata, object? userState) { throw null; } + System.IDisposable Microsoft.Extensions.Logging.ILogger.BeginScope(TState state) { throw null; } bool Microsoft.Extensions.Logging.ILogger.IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel) { throw null; } void Microsoft.Extensions.Logging.ILogger.Log(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, TState state, System.Exception? exception, System.Func formatter) { } } @@ -148,6 +216,54 @@ public enum LogLevel Critical = 5, None = 6, } + public partial struct LogPropertyInfo + { + private object _dummy; + private int _dummyPrimitive; + public LogPropertyInfo(string name, object[]? metadata) { throw null; } + public readonly object[]? Metadata { get { throw null; } } + public readonly string Name { get { throw null; } } + } + public partial class Pipeline + { + public Pipeline(object? userState, bool isEnabled, bool isDynamicLevelCheckRequired) { } + public bool IsDynamicLevelCheckRequired { get { throw null; } } + public bool IsEnabled { get { throw null; } } + public bool IsUpToDate { get { throw null; } set { } } + public object? UserState { get { throw null; } } + } + public readonly partial struct ProcessorContext + { + private readonly object _dummy; + private readonly int _dummyPrimitive; + public ProcessorContext(Microsoft.Extensions.Logging.ILogEntryProcessor processor, System.Threading.CancellationToken cancellationToken) { throw null; } + public System.Threading.CancellationToken CancellationToken { get { throw null; } } + public Microsoft.Extensions.Logging.ILogEntryProcessor Processor { get { throw null; } } + } + public partial class ProcessorFactory : Microsoft.Extensions.Logging.IProcessorFactory where T : Microsoft.Extensions.Logging.ILogEntryProcessor + { + public ProcessorFactory(System.Func getProcessor) { } + public Microsoft.Extensions.Logging.ILogEntryProcessor GetProcessor(Microsoft.Extensions.Logging.ILogEntryProcessor nextProcessor) { throw null; } + } + public abstract partial class PropertyCustomFormatter + { + protected PropertyCustomFormatter() { } + public virtual void AppendFormatted(int index, int value, System.Buffers.IBufferWriter buffer) { } + public virtual void AppendFormatted(int index, System.ReadOnlySpan value, System.Buffers.IBufferWriter buffer) { } + public virtual void AppendFormatted(int index, string value, System.Buffers.IBufferWriter buffer) { } + public abstract void AppendFormatted(int index, T value, System.Buffers.IBufferWriter buffer); + } + public abstract partial class ScopeHandler where TState : notnull + { + protected ScopeHandler() { } + public abstract System.IDisposable? HandleBeginScope(ref TState state); + public abstract bool IsEnabled(Microsoft.Extensions.Logging.LogLevel level); + } + public partial class ScopePipeline : Microsoft.Extensions.Logging.Pipeline where TState : notnull + { + public ScopePipeline(Microsoft.Extensions.Logging.ScopeHandler handler, object? userState, bool isEnabled) : base (default(object), default(bool), default(bool)) { } + public System.IDisposable? HandleScope(ref TState scope) { throw null; } + } } namespace Microsoft.Extensions.Logging.Abstractions { diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.csproj b/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.csproj index 0b3042fa01cbfd..9725fb48a0f444 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.csproj +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/ref/Microsoft.Extensions.Logging.Abstractions.csproj @@ -6,4 +6,9 @@ + + + + + diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/BufferWriter.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/BufferWriter.cs new file mode 100644 index 00000000000000..4e0ebb0f0fd477 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/BufferWriter.cs @@ -0,0 +1,124 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Buffers; + +namespace Microsoft.Extensions.Logging +{ + public ref struct BufferWriter + { + private Span _currentSpan; + private IBufferWriter _writer; + private int _allocated; + + public BufferWriter(IBufferWriter bufferWriter) + { + _writer = bufferWriter; + _currentSpan = bufferWriter.GetSpan(); + _allocated = _currentSpan.Length; + } + + public IBufferWriter Writer => _writer; + public Span CurrentSpan => _currentSpan; + + public void Advance(int len) + { + _currentSpan = _currentSpan.Slice(len); + } + + public void EnsureSize(int minSize) + { + if (_currentSpan.Length < minSize) + { + Grow(minSize); + } + } + + public void Grow(int minSize) + { + if (_allocated != _currentSpan.Length) + { + Flush(); + } + _currentSpan = _writer.GetSpan(minSize); + _allocated = _currentSpan.Length; + } + + public void Flush() + { + _writer.Advance(_allocated - _currentSpan.Length); + _currentSpan = default; + _allocated = 0; + } + } + + internal static class BufferWriterExtensions + { + public static void Write(ref this BufferWriter writer, ReadOnlySpan value) + { + if (!value.TryCopyTo(writer.CurrentSpan)) + { + writer.Grow(value.Length); + value.CopyTo(writer.CurrentSpan); + } + writer.Advance(value.Length); + } + + public static void Write(ref this BufferWriter writer, ReadOnlySpan value, int alignment) + { + int valueLen = value.Length; + bool leftAlign = false; + if (alignment < 0) + { + leftAlign = true; + alignment = -alignment; + } + int lenNeeded = Math.Max(alignment, valueLen); + int paddingNeeded = lenNeeded - valueLen; + if (writer.CurrentSpan.Length < lenNeeded) + { + writer.Grow(lenNeeded); + } + Span currentSpan = writer.CurrentSpan; + if (leftAlign) + { + currentSpan.Slice(0, paddingNeeded).Fill(' '); + value.CopyTo(currentSpan.Slice(paddingNeeded)); + } + else + { + value.CopyTo(currentSpan.Slice(paddingNeeded)); + currentSpan.Slice(valueLen, paddingNeeded).Fill(' '); + } + writer.Advance(lenNeeded); + } + + /* + public void Append(int value) + { + if (_unusedChars.Length < 20) + { + Grow(20); + } + value.TryFormat(_unusedChars, out int written); + _unusedChars = _unusedChars.Slice(written); + } + + public void Append(T value) + { + if (value is string strVal) + { + Append(strVal); + } + else if(value is int intVal) + { + Append(intVal); + } + else if(value != null) + { + Append(value.ToString()); + } + }*/ + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/ByReference.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/ByReference.cs new file mode 100644 index 00000000000000..ef259e1e63db58 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/ByReference.cs @@ -0,0 +1,31 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Runtime.CompilerServices; + +namespace Microsoft.Extensions.Logging +{ + // ByReference is meant to be used to represent "ref T" fields. It is working + // around lack of first class support for byref fields in C# and IL. The JIT and + // type loader has special handling for it that turns it into a thin wrapper around ref T. + internal struct ByReference + { + private IntPtr _value; + + public ByReference(ref T value) + { + // TODO-SPAN: This has GC hole. It needs to be JIT intrinsic instead + unsafe { _value = (IntPtr)Unsafe.AsPointer(ref value); } + } + + public ref T Value + { + get + { + // TODO-SPAN: This has GC hole. It needs to be JIT intrinsic instead + unsafe { return ref Unsafe.As(ref *(IntPtr*)_value); } + } + } + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/CompositeFormat.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/CompositeFormat.cs new file mode 100644 index 00000000000000..0dfd1e8dff5f78 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/CompositeFormat.cs @@ -0,0 +1,357 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Diagnostics.CodeAnalysis; +using System.Runtime.CompilerServices; +using System.Text; + +namespace Microsoft.Extensions.Logging +{ + /// Represents a parsed composite format string. + [DebuggerDisplay("{Format}")] + internal sealed class InternalCompositeFormat + { + /// The parsed segments that make up the composite format string. + /// + /// Every segment represents either a literal or a format hole, based on whether Literal + /// is non-null or ArgIndex is non-negative. + /// + internal readonly (string? Literal, int ArgIndex, int Alignment, string? Format)[] _segments; + /// The sum of the lengths of all of the literals in . + internal readonly int _literalLength; + /// The number of segments in that represent format holes. + internal readonly int _formattedCount; + /// The number of args required to satisfy the format holes. + /// This is equal to one more than the largest index required by any format hole. + internal readonly int _argsRequired; + + /// Initializes the instance. + /// The composite format string that was parsed. + /// The parsed segments. + private InternalCompositeFormat(string format, (string? Literal, int ArgIndex, int Alignment, string? Format)[] segments) + { + // Store the format. + Debug.Assert(format is not null); + Format = format; + + // Store the segments. + Debug.Assert(segments is not null); + _segments = segments; + + // Compute derivative information from the segments. + int literalLength = 0, formattedCount = 0, argsRequired = 0; + foreach ((string? Literal, int ArgIndex, int Alignment, string? Format) segment in segments) + { + Debug.Assert((segment.Literal is not null) ^ (segment.ArgIndex >= 0), "The segment should represent a literal or a format hole, but not both."); + + if (segment.Literal is string literal) + { + literalLength += literal.Length; // no concern about overflow as these were parsed out of a single string + } + else if (segment.ArgIndex >= 0) + { + formattedCount++; + argsRequired = Math.Max(argsRequired, segment.ArgIndex + 1); + } + } + + // Store the derivative information. + Debug.Assert(literalLength >= 0); + Debug.Assert(formattedCount >= 0); + Debug.Assert(formattedCount == 0 || argsRequired > 0); + _literalLength = literalLength; + _formattedCount = formattedCount; + _argsRequired = argsRequired; + } + + /// Parse the composite format string . + /// The string to parse. + /// The parsed . + /// is null. + /// A format item in is invalid. + public static InternalCompositeFormat Parse(string format) + { + ThrowHelper.ThrowIfNull(format); + + if (!TryParse(format, out InternalCompositeFormat? compositeFormat)) + { + throw new FormatException("placeholder InternalCompositeFormat.Parse"); + } + + return compositeFormat; + } + + /// Try to parse the composite format string . + /// The string to parse. + /// The parsed if parsing was successful; otherwise, null. + /// the can be parsed successfully; otherwise, . + public static bool TryParse(string? format, [NotNullWhen(true)] out InternalCompositeFormat? compositeFormat) + { + if (format is not null) + { + var segments = new List<(string? Literal, int ArgIndex, int Alignment, string? Format)>(); + if (TryParseLiterals(format.AsSpan(), segments)) + { + compositeFormat = new InternalCompositeFormat(format, segments.ToArray()); + return true; + } + } + + compositeFormat = null; + return false; + } + + /// Gets the original composite format string used to create this instance. + public string Format { get; } + + /// Throws an exception if the specified number of arguments is fewer than the number required. + /// The number of arguments provided by the caller. + /// An insufficient number of arguments were provided. + internal void ValidateNumberOfArgs(int numArgs) + { + if (numArgs < _argsRequired) + { + throw new FormatException("placeholder InternalCompositeFormat.ValidateNumberOfArgs"); + } + } + + /// Parse the composite format string into segments. + /// The format string. + /// The list into which to store the segments. + /// true if the format string can be parsed successfully; otherwise, false. + private static bool TryParseLiterals(ReadOnlySpan format, List<(string? Literal, int ArgIndex, int Alignment, string? Format)> segments) + { + // This parsing logic is copied from string.Format. It's the same code modified to not format + // as part of parsing and instead store the parsed literals and argument specifiers (alignment + // and format) for later use. + + // Rather than parsing directly into the segments list, literals are parsed into a reusable builder. + // Due to the nature of the parsing logic copied from string.Format, and our desire not to veer from + // it significantly in order to maintain compatibility and accidental regression, multiple literals + // next to each other might be parsed separately due to braces in between them. This builder then + // allows us to merge those segments back together easily prior to their being appended to the list. + var vsb = new ValueStringBuilder(stackalloc char[StackallocCharBufferSizeLimit]); + + // Repeatedly find the next hole and process it. + int pos = 0; + char ch; + while (true) + { + // Skip until either the end of the input or the first unescaped opening brace, whichever comes first. + // Along the way we need to also unescape escaped closing braces. + while (true) + { + // Find the next brace. If there isn't one, the remainder of the input is text to be appended, and we're done. + ReadOnlySpan remainder = format.Slice(pos); + int countUntilNextBrace = remainder.IndexOfAny('{', '}'); + if (countUntilNextBrace < 0) + { + vsb.Append(remainder); + segments.Add((vsb.ToString(), -1, 0, null)); + return true; + } + + // Append the text until the brace. + vsb.Append(remainder.Slice(0, countUntilNextBrace)); + pos += countUntilNextBrace; + + // Get the brace. It must be followed by another character, either a copy of itself in the case of being + // escaped, or an arbitrary character that's part of the hole in the case of an opening brace. + char brace = format[pos]; + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + if (brace == ch) + { + vsb.Append(ch); + pos++; + continue; + } + + // This wasn't an escape, so it must be an opening brace. + if (brace != '{') + { + return false; + } + + // Proceed to parse the hole. + segments.Add((vsb.ToString(), -1, 0, null)); + vsb.Length = 0; + break; + } + + // We're now positioned just after the opening brace of an argument hole, which consists of + // an opening brace, an index, an optional width preceded by a comma, and an optional format + // preceded by a colon, with arbitrary amounts of spaces throughout. + int width = 0; + string? itemFormat = null; // used if itemFormat is null + + // First up is the index parameter, which is of the form: + // at least on digit + // optional any number of spaces + // We've already read the first digit into ch. + Debug.Assert(format[pos - 1] == '{'); + Debug.Assert(ch != '{'); + int index = ch - '0'; + if ((uint)index >= 10u) + { + return false; + } + + // Common case is a single digit index followed by a closing brace. If it's not a closing brace, + // proceed to finish parsing the full hole format. + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + if (ch != '}') + { + // Continue consuming optional additional digits. + while (IsAsciiDigit(ch)) + { + index = index * 10 + ch - '0'; + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + } + + // Consume optional whitespace. + while (ch == ' ') + { + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + } + + // Parse the optional alignment, which is of the form: + // comma + // optional any number of spaces + // optional - + // at least one digit + // optional any number of spaces + if (ch == ',') + { + // Consume optional whitespace. + do + { + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + } + while (ch == ' '); + + // Consume an optional minus sign indicating left alignment. + int leftJustify = 1; + if (ch == '-') + { + leftJustify = -1; + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + } + + // Parse alignment digits. The read character must be a digit. + width = ch - '0'; + if ((uint)width >= 10u) + { + return false; + } + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + while (IsAsciiDigit(ch)) + { + width = width * 10 + ch - '0'; + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + } + width *= leftJustify; + + // Consume optional whitespace + while (ch == ' ') + { + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + } + } + + // The next character needs to either be a closing brace for the end of the hole, + // or a colon indicating the start of the format. + if (ch != '}') + { + if (ch != ':') + { + // Unexpected character + return false; + } + + // Search for the closing brace; everything in between is the format, + // but opening braces aren't allowed. + int startingPos = pos; + while (true) + { + if (!TryMoveNext(format, ref pos, out ch)) + { + return false; + } + + if (ch == '}') + { + // Argument hole closed + break; + } + + if (ch == '{') + { + // Braces inside the argument hole are not supported + return false; + } + } + + startingPos++; + itemFormat = format.Slice(startingPos, pos - startingPos).ToString(); + } + } + + Debug.Assert(format[pos] == '}'); + pos++; + + segments.Add((null, index, width, itemFormat)); + + // Continue parsing the rest of the format string. + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + static bool TryMoveNext(ReadOnlySpan format, ref int pos, out char nextChar) + { + pos++; + if ((uint)pos >= (uint)format.Length) + { + nextChar = '\0'; + return false; + } + + nextChar = format[pos]; + return true; + } + } + + internal const int StackallocCharBufferSizeLimit = 256; + private static bool IsAsciiDigit(char c) => IsBetween(c, '0', '9'); + private static bool IsBetween(char c, char minInclusive, char maxInclusive) => + (uint)(c - minInclusive) <= (uint)(maxInclusive - minInclusive); + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/FormattedLogValues.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/FormattedLogValues.cs index 782f9bce5ab987..037ec63bdcd3ee 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/FormattedLogValues.cs +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/FormattedLogValues.cs @@ -84,7 +84,7 @@ public int Count return 1; } - return _formatter.ValueNames.Count + 1; + return _formatter.PropertyCount + 1; } } diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogDefineOptions.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogDefineOptions.cs index 48016fcd2b7814..b4b99ef57ccfa2 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogDefineOptions.cs +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogDefineOptions.cs @@ -14,5 +14,10 @@ public class LogDefineOptions /// Gets or sets the flag to skip IsEnabled check for the logging method. /// public bool SkipEnabledCheck { get; set; } + + /// + /// Gets or sets a collection of parameter metadata. Items in the collection match parameters to the log message by position. + /// + public object[]?[]? ParameterMetadata { get; set; } } } diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogEntryNew.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogEntryNew.cs new file mode 100644 index 00000000000000..1199146df5800e --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogEntryNew.cs @@ -0,0 +1,108 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Buffers; +using System.Threading; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Logging +{ + public interface ILogEntryProcessorFactory + { + //TODO: should CancellationToken be an IChangeToken or something else? + ProcessorContext GetProcessor(); + } + + public readonly struct ProcessorContext + { + public ILogEntryProcessor Processor { get; } + public CancellationToken CancellationToken { get; } + + public ProcessorContext(ILogEntryProcessor processor, CancellationToken cancellationToken) + { + Processor = processor; + CancellationToken = cancellationToken; + } + } + + public interface ILogEntryProcessor + { + LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired); + ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull; + bool IsEnabled(LogLevel logLevel); + } + + //TODO: Merge with other factory? Handle cancellation? + //Are these factories even needed or could we do it with a Func? + public interface IProcessorFactory + { + ILogEntryProcessor GetProcessor(ILogEntryProcessor nextProcessor); + } + + public class ProcessorFactory : IProcessorFactory where T : ILogEntryProcessor + { + public ProcessorFactory(Func getProcessor) + { + _getProcessor = getProcessor; + } + + private readonly Func _getProcessor; + public ILogEntryProcessor GetProcessor(ILogEntryProcessor nextProcessor) => _getProcessor(nextProcessor); + } + + public abstract class LogEntryHandler + { + public abstract bool IsEnabled(LogLevel level); + public abstract void HandleLogEntry(ref LogEntry logEntry); + } + + public abstract class ScopeHandler where TState : notnull + { + public abstract bool IsEnabled(LogLevel level); + public abstract IDisposable? HandleBeginScope(ref TState state); + } + + public struct LogPropertyInfo + { + public LogPropertyInfo(string name, object[]? metadata) + { + Name = name; + Metadata = metadata; + } + public string Name { get; } + public object[]? Metadata { get; } + } + + public interface ILogMetadata + { + LogLevel LogLevel { get; } + EventId EventId { get; } + string OriginalFormat { get; } + int PropertyCount { get; } + LogPropertyInfo GetPropertyInfo(int index); + void AppendFormattedMessage(in TState state, IBufferWriter buffer); + Action> GetMessageFormatter(PropertyCustomFormatter[] customFormatters); + FormatPropertyListAction GetPropertyListFormatter(IPropertyFormatterFactory propertyFormatterFactory); + Func GetStringMessageFormatter(); + } + + public delegate void FormatPropertyListAction(in TState state, ref BufferWriter bufferWriter); + public delegate void FormatPropertyAction(PropType propertyValue, ref BufferWriter bufferWriter); + public delegate void FormatSpanPropertyAction(scoped ReadOnlySpan propertyValue, ref BufferWriter bufferWriter); + + public interface IPropertyFormatterFactory + { + FormatPropertyAction GetPropertyFormatter(int propertyIndex, LogPropertyInfo metadata); + FormatSpanPropertyAction GetSpanPropertyFormatter(int propertyIndex, LogPropertyInfo metadata); + } + + public abstract class PropertyCustomFormatter + { + //TODO: we can expand this with overrides for other commonly logged value types + public virtual void AppendFormatted(int index, ReadOnlySpan value, IBufferWriter buffer) => AppendFormatted(index, value.ToString(), buffer); + public virtual void AppendFormatted(int index, int value, IBufferWriter buffer) => AppendFormatted(index, value, buffer); + public virtual void AppendFormatted(int index, string value, IBufferWriter buffer) => AppendFormatted(index, value, buffer); + public abstract void AppendFormatted(int index, T value, IBufferWriter buffer); + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogEntryPipeline.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogEntryPipeline.cs new file mode 100644 index 00000000000000..aace472b72ee85 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogEntryPipeline.cs @@ -0,0 +1,57 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Logging +{ + public interface ILogEntryPipelineFactory + { + public LogEntryPipeline? GetLoggingPipeline(ILogMetadata? metadata, object? userState); + public ScopePipeline? GetScopePipeline(ILogMetadata? metadata, object? userState) where TState : notnull; + } + + public class Pipeline + { + public Pipeline(object? userState, bool isEnabled, bool isDynamicLevelCheckRequired) + { + UserState = userState; + IsEnabled = isEnabled; + IsDynamicLevelCheckRequired = isDynamicLevelCheckRequired; + IsUpToDate = true; + } + + public object? UserState { get; } + public bool IsEnabled { get; } + public bool IsDynamicLevelCheckRequired { get; } + public bool IsUpToDate { get; set; } + } + + public class LogEntryPipeline : Pipeline + { + public LogEntryPipeline(LogEntryHandler handler, object? userState, bool isEnabled, bool isDynamicLevelCheckRequired) : + base(userState, isEnabled, isDynamicLevelCheckRequired) + { + _firstHandler = handler; + } + + private readonly LogEntryHandler _firstHandler; + + public bool IsEnabledDynamic(LogLevel level) => _firstHandler.IsEnabled(level); + public void HandleLogEntry(ref LogEntry logEntry) => _firstHandler.HandleLogEntry(ref logEntry); + } + + public class ScopePipeline : Pipeline where TState : notnull + { + public ScopePipeline(ScopeHandler handler, object? userState, bool isEnabled) : + base(userState, isEnabled, isDynamicLevelCheckRequired: false) + { + _firstHandler = handler; + } + + private readonly ScopeHandler _firstHandler; + + public IDisposable? HandleScope(ref TState scope) => _firstHandler.HandleBeginScope(ref scope); + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogValuesFormatter.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogValuesFormatter.cs index a833220ed57fed..4120eebd5cded9 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogValuesFormatter.cs +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LogValuesFormatter.cs @@ -4,37 +4,49 @@ using System; using System.Collections; using System.Collections.Generic; +using System.Diagnostics; using System.Diagnostics.CodeAnalysis; using System.Globalization; +using System.Runtime.CompilerServices; using System.Text; namespace Microsoft.Extensions.Logging { + internal class LogValuesMetadata : LogValuesFormatter + { + public LogValuesMetadata(string format, LogLevel level, EventId eventId, object[]?[]? metadata) : base(format, metadata) + { + LogLevel = level; + EventId = eventId; + } + + public string FinalFormat => CompositeFormat.Format; + public LogLevel LogLevel { get; } + public EventId EventId { get; } + } + /// /// Formatter to convert the named format items like {NamedformatItem} to format. /// - internal sealed class LogValuesFormatter + internal class LogValuesFormatter { private const string NullValue = "(null)"; private static readonly char[] FormatDelimiters = { ',', ':' }; - private readonly List _valueNames = new List(); -#if NET8_0_OR_GREATER - private readonly CompositeFormat _format; -#else - private readonly string _format; -#endif + private readonly LogPropertyInfo[]? _metadata; + private readonly InternalCompositeFormat _format; // NOTE: If this assembly ever builds for netcoreapp, the below code should change to: // - Be annotated as [SkipLocalsInit] to avoid zero'ing the stackalloc'd char span // - Format _valueNames.Count directly into a span - public LogValuesFormatter(string format) + public LogValuesFormatter(string format, object[]?[]? metadata = null) { ThrowHelper.ThrowIfNull(format); OriginalFormat = format; var vsb = new ValueStringBuilder(stackalloc char[256]); + List propertyMetadata = new List(); int scanIndex = 0; int endIndex = format.Length; @@ -44,12 +56,7 @@ public LogValuesFormatter(string format) if (scanIndex == 0 && openBraceIndex == endIndex) { // No holes found. - _format = -#if NET8_0_OR_GREATER - CompositeFormat.Parse(format); -#else - format; -#endif + _format = InternalCompositeFormat.Parse(format); return; } @@ -64,26 +71,28 @@ public LogValuesFormatter(string format) { // Format item syntax : { index[,alignment][ :formatString] }. int formatDelimiterIndex = FindIndexOfAny(format, FormatDelimiters, openBraceIndex, closeBraceIndex); + int colonIndex = format.IndexOf(':', openBraceIndex, closeBraceIndex - openBraceIndex); vsb.Append(format.AsSpan(scanIndex, openBraceIndex - scanIndex + 1)); - vsb.Append(_valueNames.Count.ToString()); - _valueNames.Add(format.Substring(openBraceIndex + 1, formatDelimiterIndex - openBraceIndex - 1)); + vsb.Append(propertyMetadata.Count.ToString()); + string propName = format.Substring(openBraceIndex + 1, formatDelimiterIndex - openBraceIndex - 1); vsb.Append(format.AsSpan(formatDelimiterIndex, closeBraceIndex - formatDelimiterIndex + 1)); - + object[]? propMetadata = metadata != null && metadata.Length >= propertyMetadata.Count ? metadata[propertyMetadata.Count] : null; + propertyMetadata.Add(new LogPropertyInfo(propName, propMetadata)); scanIndex = closeBraceIndex + 1; } } - _format = -#if NET8_0_OR_GREATER - CompositeFormat.Parse(vsb.ToString()); -#else - vsb.ToString(); -#endif + _metadata = propertyMetadata.ToArray(); + _format = InternalCompositeFormat.Parse(vsb.ToString()); } public string OriginalFormat { get; private set; } - public List ValueNames => _valueNames; + public InternalCompositeFormat CompositeFormat => _format; + public int PropertyCount => _metadata != null ? _metadata.Length : 0; + public string GetValueName(int index) => _metadata![index].Name; + + public LogPropertyInfo GetPropertyInfo(int index) => _metadata![index]; private static int FindBraceIndex(string format, char brace, int startIndex, int endIndex) { @@ -163,7 +172,7 @@ public string Format(object?[]? values) } } - return string.Format(CultureInfo.InvariantCulture, _format, formattedValues ?? Array.Empty()); + return string.Format(CultureInfo.InvariantCulture, _format.Format, formattedValues ?? Array.Empty()); } // NOTE: This method mutates the items in the array if needed to avoid extra allocations, and should only be used when caller expects this to happen @@ -177,69 +186,53 @@ internal string FormatWithOverwrite(object?[]? values) } } - return string.Format(CultureInfo.InvariantCulture, _format, values ?? Array.Empty()); + return string.Format(CultureInfo.InvariantCulture, _format.Format, values ?? Array.Empty()); } internal string Format() { -#if NET8_0_OR_GREATER return _format.Format; -#else - return _format; -#endif } - -#if NET8_0_OR_GREATER internal string Format(TArg0 arg0) { - object? arg0String = null; + string? arg0String = null; return !TryFormatArgumentIfNullOrEnumerable(arg0, ref arg0String) ? - string.Format(CultureInfo.InvariantCulture, _format, arg0) : - string.Format(CultureInfo.InvariantCulture, _format, arg0String); + string.Format(CultureInfo.InvariantCulture, _format.Format, arg0) : + string.Format(CultureInfo.InvariantCulture, _format.Format, arg0String); } internal string Format(TArg0 arg0, TArg1 arg1) { - object? arg0String = null, arg1String = null; + string? arg0String = null, arg1String = null; return !TryFormatArgumentIfNullOrEnumerable(arg0, ref arg0String) && !TryFormatArgumentIfNullOrEnumerable(arg1, ref arg1String) ? - string.Format(CultureInfo.InvariantCulture, _format, arg0, arg1) : - string.Format(CultureInfo.InvariantCulture, _format, arg0String ?? arg0, arg1String ?? arg1); + string.Format(CultureInfo.InvariantCulture, _format.Format, arg0, arg1) : + string.Format(CultureInfo.InvariantCulture, _format.Format, (object?)arg0String ?? arg0, (object?)arg1String ?? arg1); } internal string Format(TArg0 arg0, TArg1 arg1, TArg2 arg2) { - object? arg0String = null, arg1String = null, arg2String = null; + string? arg0String = null, arg1String = null, arg2String = null; return !TryFormatArgumentIfNullOrEnumerable(arg0, ref arg0String) && !TryFormatArgumentIfNullOrEnumerable(arg1, ref arg1String) && !TryFormatArgumentIfNullOrEnumerable(arg2, ref arg2String) ? - string.Format(CultureInfo.InvariantCulture, _format, arg0, arg1, arg2) : - string.Format(CultureInfo.InvariantCulture, _format, arg0String ?? arg0, arg1String ?? arg1, arg2String ?? arg2); + string.Format(CultureInfo.InvariantCulture, _format.Format, arg0, arg1, arg2) : + string.Format(CultureInfo.InvariantCulture, _format.Format, (object?)arg0String ?? arg0, (object?)arg1String ?? arg1, (object?)arg2String ?? arg2); } -#else - internal string Format(object? arg0) => - string.Format(CultureInfo.InvariantCulture, _format, FormatArgument(arg0)); - - internal string Format(object? arg0, object? arg1) => - string.Format(CultureInfo.InvariantCulture, _format, FormatArgument(arg0), FormatArgument(arg1)); - - internal string Format(object? arg0, object? arg1, object? arg2) => - string.Format(CultureInfo.InvariantCulture, _format, FormatArgument(arg0), FormatArgument(arg1), FormatArgument(arg2)); -#endif public KeyValuePair GetValue(object?[] values, int index) { - if (index < 0 || index > _valueNames.Count) + if (index < 0 || index > PropertyCount) { throw new IndexOutOfRangeException(nameof(index)); } - if (_valueNames.Count > index) + if (PropertyCount > index) { - return new KeyValuePair(_valueNames[index], values[index]); + return new KeyValuePair(_metadata![index].Name, values[index]); } return new KeyValuePair("{OriginalFormat}", OriginalFormat); @@ -248,22 +241,165 @@ internal string Format(object? arg0, object? arg1, object? arg2) => public IEnumerable> GetValues(object[] values) { var valueArray = new KeyValuePair[values.Length + 1]; - for (int index = 0; index != _valueNames.Count; ++index) + for (int index = 0; index != PropertyCount; ++index) { - valueArray[index] = new KeyValuePair(_valueNames[index], values[index]); + valueArray[index] = new KeyValuePair(_metadata![index].Name, values[index]); } valueArray[valueArray.Length - 1] = new KeyValuePair("{OriginalFormat}", OriginalFormat); return valueArray; } + [MethodImpl(MethodImplOptions.AggressiveInlining)] + protected static void AppendFormattedPropertyValue(T value, ref BufferWriter bufferWriter, int alignment, string? format) + { + if (value is string valueString) + { + if (alignment == 0) + { + bufferWriter.Write(valueString.AsSpan()); + } + else + { + AppendFormattedPropertyValueAligned(valueString, ref bufferWriter, alignment, format); + } + } + else + { + AppendFormattedPropertyValueNonString(value, ref bufferWriter, alignment, format); + } + } + + + protected static void AppendFormattedPropertyValueNonString(T value, ref BufferWriter bufferWriter, int alignment, string? format) + { + if (alignment == 0) + { +#if NET8_0_OR_GREATER + if (value is ISpanFormattable) + { + bufferWriter.EnsureSize(32); + if (((ISpanFormattable)value).TryFormat(bufferWriter.CurrentSpan, out int charsWritten, format, null)) + { + bufferWriter.Advance(charsWritten); + return; + } + } +#endif + bufferWriter.Write(FormatPropertyValue(value, format).AsSpan()); + } + else + { + AppendFormattedPropertyValueAligned(value, ref bufferWriter, alignment, format); + } + } + + protected static void AppendFormattedPropertyValueAligned(T value, ref BufferWriter bufferWriter, int alignment, string? format) + { + bool leftAlign = false; + int paddingNeeded; + Span span; + if (alignment < 0) + { + leftAlign = true; + alignment = -alignment; + } +#if NET8_0_OR_GREATER + if (value is ISpanFormattable) + { + bufferWriter.EnsureSize(Math.Max(32, alignment)); + span = bufferWriter.CurrentSpan; + if (((ISpanFormattable)value).TryFormat(span, out int charsWritten, format, CultureInfo.InvariantCulture)) + { + paddingNeeded = alignment - charsWritten; + if (paddingNeeded <= 0) + { + bufferWriter.Advance(charsWritten); + return; + } + if (leftAlign) + { + span.Slice(charsWritten, paddingNeeded).Fill(' '); + } + else + { + span.Slice(0, charsWritten).CopyTo(span.Slice(paddingNeeded)); + span.Slice(0, paddingNeeded).Fill(' '); + } + bufferWriter.Advance(alignment); + return; + } + } +#endif + + string unpadded = FormatPropertyValue(value, format); + paddingNeeded = alignment - unpadded.Length; + bufferWriter.EnsureSize(Math.Max(unpadded.Length, alignment)); + span = bufferWriter.CurrentSpan; + if (paddingNeeded <= 0) + { + bufferWriter.Write(unpadded.AsSpan()); + return; + } + + if (leftAlign) + { + unpadded.AsSpan().CopyTo(span); + span.Slice(unpadded.Length, paddingNeeded).Fill(' '); + } + else + { + span.Slice(0, paddingNeeded).Fill(' '); + unpadded.AsSpan().CopyTo(span.Slice(paddingNeeded)); + } + bufferWriter.Advance(alignment); + + } + + protected static string FormatPropertyValue(T value, string? format) + { + string? s; + if (value is IFormattable) + { + s = ((IFormattable)value).ToString(format, null); + } + else if (value is not string && value is IEnumerable enumerable) + { + var vsb = new ValueStringBuilder(stackalloc char[256]); + bool first = true; + foreach (object? e in enumerable) + { + if (!first) + { + vsb.Append(", "); + } + + vsb.Append(e != null ? e.ToString() : NullValue); + first = false; + } + return vsb.ToString(); + } + else + { + s = value?.ToString(); + } + if (s == null) + { + return NullValue; + } + else + { + return s; + } + } + private static object FormatArgument(object? value) { - object? stringValue = null; + string? stringValue = null; return TryFormatArgumentIfNullOrEnumerable(value, ref stringValue) ? stringValue : value!; } - private static bool TryFormatArgumentIfNullOrEnumerable(object? value, [NotNullWhen(true)] ref object? stringValue) + private static bool TryFormatArgumentIfNullOrEnumerable(object? value, [NotNullWhen(true)] ref string? stringValue) { if (value == null) { diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerMessage.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerMessage.cs index 1f010e66470328..b18ea26d1fe4a4 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerMessage.cs +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerMessage.cs @@ -2,9 +2,11 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; +using System.Buffers; using System.Collections; using System.Collections.Generic; using Microsoft.Extensions.Logging.Abstractions; +using static Microsoft.Extensions.Logging.LoggerMessage; namespace Microsoft.Extensions.Logging { @@ -51,7 +53,10 @@ public static class LoggerMessage { LogValuesFormatter formatter = CreateLogValuesFormatter(formatString, expectedNamedParameterCount: 2); - return (logger, arg1, arg2) => logger.BeginScope(new LogValues(formatter, arg1, arg2)); + return (logger, arg1, arg2) => + { + return logger.BeginScope(new LogValues(formatter, arg1, arg2)); + }; } /// @@ -204,6 +209,56 @@ void Log(ILogger logger, T1 arg1, Exception? exception) }; } + public delegate void Log(ILogger logger, ref TState state, Exception? exception); + + public static Log Define(ILogMetadata metadata, LogDefineOptions? options = null) + { + LogEntryPipeline? pipeline = null; + bool needFullEnabledCheck = (options == null || !options.SkipEnabledCheck); + return Log; + + void Log(ILogger logger, ref TState state, Exception? exception) + { + LogEntryPipeline? pipelineSnapshot = pipeline; + if (pipelineSnapshot != null && pipelineSnapshot.UserState == logger && pipelineSnapshot.IsUpToDate) + { + if (!pipelineSnapshot.IsEnabled || + (pipelineSnapshot.IsDynamicLevelCheckRequired && needFullEnabledCheck && !pipelineSnapshot.IsEnabledDynamic(metadata.LogLevel))) + return; + LogEntry entry = new LogEntry(metadata.LogLevel, category: null!, metadata.EventId, state, exception, null!); + pipelineSnapshot.HandleLogEntry(ref entry); + } + else + { + LogSlowPath(logger, ref state, exception); + } + } + + void LogSlowPath(ILogger logger, ref TState state, Exception? exception) + { + LogEntryPipeline? pipelineSnapshot = null; + LogEntry entry = new LogEntry(metadata.LogLevel, category: null!, metadata.EventId, state, exception, null!); + if (logger is ILogEntryPipelineFactory) + { + pipelineSnapshot = ((ILogEntryPipelineFactory)logger).GetLoggingPipeline(metadata, logger); + pipeline = pipelineSnapshot; + } + if (pipelineSnapshot != null) + { + if (!pipelineSnapshot.IsEnabled || + (pipelineSnapshot.IsDynamicLevelCheckRequired && needFullEnabledCheck && !pipelineSnapshot.IsEnabledDynamic(metadata.LogLevel))) + return; + pipelineSnapshot.HandleLogEntry(ref entry); + } + else + { + if (needFullEnabledCheck && logger.IsEnabled(metadata.LogLevel)) + return; + logger.Log(entry.LogLevel, entry.EventId, entry.State, entry.Exception, metadata.GetStringMessageFormatter()); + } + } + } + /// /// Creates a delegate which can be invoked for logging a message. /// @@ -228,25 +283,54 @@ void Log(ILogger logger, T1 arg1, Exception? exception) /// A delegate which when invoked creates a log message. public static Action Define(LogLevel logLevel, EventId eventId, string formatString, LogDefineOptions? options) { - LogValuesFormatter formatter = CreateLogValuesFormatter(formatString, expectedNamedParameterCount: 2); + LogValuesMetadata metadata = LogValues.CreateMetadata(logLevel, eventId, formatString, options?.ParameterMetadata); + LogEntryPipeline>? pipeline = null; + bool needFullEnabledCheck = (options == null || !options.SkipEnabledCheck); + return Log; void Log(ILogger logger, T1 arg1, T2 arg2, Exception? exception) { - logger.Log(logLevel, eventId, new LogValues(formatter, arg1, arg2), exception, LogValues.Callback); - } - - if (options != null && options.SkipEnabledCheck) - { - return Log; + LogEntryPipeline>? pipelineSnapshot = pipeline; + if (pipelineSnapshot != null && pipelineSnapshot.UserState == logger && pipelineSnapshot.IsUpToDate) + { + if (!pipelineSnapshot.IsEnabled || + (pipelineSnapshot.IsDynamicLevelCheckRequired && needFullEnabledCheck && !pipelineSnapshot.IsEnabledDynamic(logLevel))) + return; + LogValues state = new LogValues(metadata, arg1, arg2); + LogEntry> entry = new LogEntry>(logLevel, category: null!, eventId, state, exception, LogValues.Callback); + pipelineSnapshot.HandleLogEntry(ref entry); + } + else + { + LogSlowPath(logger, arg1, arg2, exception); + } } - return (logger, arg1, arg2, exception) => + void LogSlowPath(ILogger logger, T1 arg1, T2 arg2, Exception? exception) { - if (logger.IsEnabled(logLevel)) + LogEntryPipeline>? pipelineSnapshot = null; + if (logger is ILogEntryPipelineFactory) { - Log(logger, arg1, arg2, exception); + pipelineSnapshot = ((ILogEntryPipelineFactory)logger).GetLoggingPipeline(metadata, logger); + pipeline = pipelineSnapshot; } - }; + if (pipelineSnapshot != null) + { + if (!pipelineSnapshot.IsEnabled || + (pipelineSnapshot.IsDynamicLevelCheckRequired && needFullEnabledCheck && !pipelineSnapshot.IsEnabledDynamic(logLevel))) + return; + LogValues state = new LogValues(metadata, arg1, arg2); + LogEntry> entry = new LogEntry>(logLevel, category: null!, eventId, state, exception, LogValues.Callback); + pipelineSnapshot.HandleLogEntry(ref entry); + } + else + { + if (needFullEnabledCheck && !logger.IsEnabled(logLevel)) + return; + LogValues state = new LogValues(metadata, arg1, arg2); + logger.Log(logLevel, eventId, state, exception, LogValues.Callback); + } + } } /// @@ -453,14 +537,18 @@ private static LogValuesFormatter CreateLogValuesFormatter(string formatString, { var logValuesFormatter = new LogValuesFormatter(formatString); - int actualCount = logValuesFormatter.ValueNames.Count; + ValidateFormatStringParameterCount(formatString, expectedNamedParameterCount, logValuesFormatter.PropertyCount); + + return logValuesFormatter; + } + + private static void ValidateFormatStringParameterCount(string formatString, int expectedNamedParameterCount, int actualCount) + { if (actualCount != expectedNamedParameterCount) { throw new ArgumentException( SR.Format(SR.UnexpectedNumberOfNamedParameters, formatString, expectedNamedParameterCount, actualCount)); } - - return logValuesFormatter; } private readonly struct LogValues : IReadOnlyList> @@ -521,7 +609,7 @@ public LogValues(LogValuesFormatter formatter, T0 value0) switch (index) { case 0: - return new KeyValuePair(_formatter.ValueNames[0], _value0); + return new KeyValuePair(_formatter.GetValueName(0), _value0); case 1: return new KeyValuePair("{OriginalFormat}", _formatter.OriginalFormat); default: @@ -549,13 +637,104 @@ IEnumerator IEnumerable.GetEnumerator() } } - private readonly struct LogValues : IReadOnlyList> + internal class LogValuesMetadata : LogValuesMetadata, ILogMetadata> + { + public LogValuesMetadata(string format, LogLevel level, EventId eventId, object[]?[]? metadata = null) : base(format, level, eventId, metadata) { } + + public void AppendFormattedMessage(in LogValues state, IBufferWriter buffer) + { + BufferWriter writer = new BufferWriter(buffer); + foreach ((string? Literal, int ArgIndex, int Alignment, string? Format) segment in CompositeFormat._segments) + { + int index = segment.ArgIndex; + switch (index) + { + case 0: + AppendFormattedPropertyValue(state._value0, ref writer, segment.Alignment, segment.Format); + break; + case 1: + AppendFormattedPropertyValue(state._value1, ref writer, segment.Alignment, segment.Format); + break; + default: + writer.Write(segment.Literal.AsSpan()); + break; + } + } + writer.Flush(); + } + + public FormatPropertyListAction> GetPropertyListFormatter(IPropertyFormatterFactory propertyFormatterFactory) + { + FormatPropertyAction formatter0 = propertyFormatterFactory.GetPropertyFormatter(0, GetPropertyInfo(0)); + FormatPropertyAction formatter1 = propertyFormatterFactory.GetPropertyFormatter(1, GetPropertyInfo(1)); + return FormatPropertyList; + + void FormatPropertyList(in LogValues tstate, ref BufferWriter writer) + { + formatter0(tstate._value0, ref writer); + formatter1(tstate._value1, ref writer); + } + } + + public Action, IBufferWriter> GetMessageFormatter(PropertyCustomFormatter[] customPropertyFormatters) => + (state, buffer) => AppendFormattedMessage(state, buffer, customPropertyFormatters); + + private void AppendFormattedMessage(in LogValues state, IBufferWriter buffer, PropertyCustomFormatter[] customFormatters) + { + BufferWriter writer = new BufferWriter(buffer); + foreach ((string? Literal, int ArgIndex, int Alignment, string? Format) segment in CompositeFormat._segments) + { + int index = segment.ArgIndex; + switch (index) + { + case 0: + AppendCustomFormattedProperty(index, state._value0, ref writer, segment.Alignment, segment.Format, customFormatters[index]); + break; + case 1: + AppendCustomFormattedProperty(index, state._value1, ref writer, segment.Alignment, segment.Format, customFormatters[index]); + break; + default: + writer.Write(segment.Literal.AsSpan()); + break; + } + } + writer.Flush(); + } + + private static void AppendCustomFormattedProperty(int index, T value, ref BufferWriter writer, int alignment, string? format, PropertyCustomFormatter? formatter) + { + if (formatter == null) + { + AppendFormattedPropertyValue(value, ref writer, alignment, format); + } + else + { + writer.Flush(); + if (value is string strVal) + { + formatter.AppendFormatted(index, strVal, writer.Writer); + } + else if (value is int intVal) + { + formatter.AppendFormatted(index, intVal, writer.Writer); + } + else + { + formatter.AppendFormatted(index, value, writer.Writer); + } + } + } + + public Func, Exception?, string> GetStringMessageFormatter() => LogValues.Callback; + } + + internal readonly struct LogValues : IReadOnlyList> { public static readonly Func, Exception?, string> Callback = (state, exception) => state.ToString(); private readonly LogValuesFormatter _formatter; - private readonly T0 _value0; - private readonly T1 _value1; + internal readonly T0 _value0; + internal readonly T1 _value1; public LogValues(LogValuesFormatter formatter, T0 value0, T1 value1) { @@ -564,6 +743,8 @@ public LogValues(LogValuesFormatter formatter, T0 value0, T1 value1) _value1 = value1; } + public ILogMetadata>? Metadata => _formatter as LogValuesMetadata; + public KeyValuePair this[int index] { get @@ -571,9 +752,9 @@ public LogValues(LogValuesFormatter formatter, T0 value0, T1 value1) switch (index) { case 0: - return new KeyValuePair(_formatter.ValueNames[0], _value0); + return new KeyValuePair(_formatter.GetValueName(0), _value0); case 1: - return new KeyValuePair(_formatter.ValueNames[1], _value1); + return new KeyValuePair(_formatter.GetValueName(1), _value1); case 2: return new KeyValuePair("{OriginalFormat}", _formatter.OriginalFormat); default: @@ -598,6 +779,13 @@ IEnumerator IEnumerable.GetEnumerator() { return GetEnumerator(); } + + public static LogValuesMetadata CreateMetadata(LogLevel level, EventId eventId, string formatString, object[]?[]? parameterMetadata = null) + { + var metadata = new LogValuesMetadata(formatString, level, eventId, parameterMetadata); + ValidateFormatStringParameterCount(formatString, expectedNamedParameterCount: 2, metadata.PropertyCount); + return metadata; + } } private readonly struct LogValues : IReadOnlyList> @@ -618,11 +806,11 @@ IEnumerator IEnumerable.GetEnumerator() switch (index) { case 0: - return new KeyValuePair(_formatter.ValueNames[0], _value0); + return new KeyValuePair(_formatter.GetValueName(0), _value0); case 1: - return new KeyValuePair(_formatter.ValueNames[1], _value1); + return new KeyValuePair(_formatter.GetValueName(1), _value1); case 2: - return new KeyValuePair(_formatter.ValueNames[2], _value2); + return new KeyValuePair(_formatter.GetValueName(2), _value2); case 3: return new KeyValuePair("{OriginalFormat}", _formatter.OriginalFormat); default: @@ -674,13 +862,13 @@ IEnumerator IEnumerable.GetEnumerator() switch (index) { case 0: - return new KeyValuePair(_formatter.ValueNames[0], _value0); + return new KeyValuePair(_formatter.GetValueName(0), _value0); case 1: - return new KeyValuePair(_formatter.ValueNames[1], _value1); + return new KeyValuePair(_formatter.GetValueName(1), _value1); case 2: - return new KeyValuePair(_formatter.ValueNames[2], _value2); + return new KeyValuePair(_formatter.GetValueName(2), _value2); case 3: - return new KeyValuePair(_formatter.ValueNames[3], _value3); + return new KeyValuePair(_formatter.GetValueName(3), _value3); case 4: return new KeyValuePair("{OriginalFormat}", _formatter.OriginalFormat); default: @@ -736,15 +924,15 @@ IEnumerator IEnumerable.GetEnumerator() switch (index) { case 0: - return new KeyValuePair(_formatter.ValueNames[0], _value0); + return new KeyValuePair(_formatter.GetValueName(0), _value0); case 1: - return new KeyValuePair(_formatter.ValueNames[1], _value1); + return new KeyValuePair(_formatter.GetValueName(1), _value1); case 2: - return new KeyValuePair(_formatter.ValueNames[2], _value2); + return new KeyValuePair(_formatter.GetValueName(2), _value2); case 3: - return new KeyValuePair(_formatter.ValueNames[3], _value3); + return new KeyValuePair(_formatter.GetValueName(3), _value3); case 4: - return new KeyValuePair(_formatter.ValueNames[4], _value4); + return new KeyValuePair(_formatter.GetValueName(4), _value4); case 5: return new KeyValuePair("{OriginalFormat}", _formatter.OriginalFormat); default: @@ -802,17 +990,17 @@ IEnumerator IEnumerable.GetEnumerator() switch (index) { case 0: - return new KeyValuePair(_formatter.ValueNames[0], _value0); + return new KeyValuePair(_formatter.GetValueName(0), _value0); case 1: - return new KeyValuePair(_formatter.ValueNames[1], _value1); + return new KeyValuePair(_formatter.GetValueName(1), _value1); case 2: - return new KeyValuePair(_formatter.ValueNames[2], _value2); + return new KeyValuePair(_formatter.GetValueName(2), _value2); case 3: - return new KeyValuePair(_formatter.ValueNames[3], _value3); + return new KeyValuePair(_formatter.GetValueName(3), _value3); case 4: - return new KeyValuePair(_formatter.ValueNames[4], _value4); + return new KeyValuePair(_formatter.GetValueName(4), _value4); case 5: - return new KeyValuePair(_formatter.ValueNames[5], _value5); + return new KeyValuePair(_formatter.GetValueName(5), _value5); case 6: return new KeyValuePair("{OriginalFormat}", _formatter.OriginalFormat); default: diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerT.cs b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerT.cs index b6bf6f882f6990..5f2711dfe6e52a 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerT.cs +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerT.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; +using System.Collections.Generic; using Microsoft.Extensions.Internal; namespace Microsoft.Extensions.Logging @@ -11,8 +12,10 @@ namespace Microsoft.Extensions.Logging /// provided . /// /// The type. - public class Logger : ILogger + public class Logger : ILogger, ILogEntryPipelineFactory { + //private Dictionary _metadataPipelines = new Dictionary(); // metadata -> LogEntryPipeline + //private Dictionary _noMetadataPipelines = new Dictionary(); private readonly ILogger _logger; /// @@ -43,5 +46,65 @@ void ILogger.Log(LogLevel logLevel, EventId eventId, TState state, Excep { _logger.Log(logLevel, eventId, state, exception, formatter); } + + ScopePipeline? ILogEntryPipelineFactory.GetScopePipeline(ILogMetadata? metadata, object? userState) + { + if (_logger is ILogEntryPipelineFactory factory) + { + return factory.GetScopePipeline(metadata, userState); + } + else + { + return null; + } + } + + LogEntryPipeline? ILogEntryPipelineFactory.GetLoggingPipeline(ILogMetadata? metadata, object? userState) + { + if (_logger is ILogEntryPipelineFactory factory) + { + return factory.GetLoggingPipeline(metadata, userState); + } + else + { + return null; + } + + /* + if (_logger is not ILogEntryProcessor) + return null; + object pipeline; + if (metadata != null) + { + lock (_metadataPipelines) + { + if (!_metadataPipelines.TryGetValue(metadata, out pipeline)) + { + pipeline = BuildPipeline(metadata); + _metadataPipelines[metadata] = pipeline; + } + } + } + else + { + lock (_noMetadataPipelines) + { + if (!_noMetadataPipelines.TryGetValue(typeof(TState), out pipeline)) + { + pipeline = BuildPipeline(null); + _noMetadataPipelines[typeof(TState)] = pipeline; + } + } + } + return (LogEntryPipeline)pipeline; + */ + } + + /* + private LogEntryPipeline BuildPipeline(ILogMetadata? metadata) + { + return new LogEntryPipeline(((ILogEntryProcessor)_logger).GetLogEntryHandler(metadata), this, true, false); + }*/ } + } diff --git a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/Microsoft.Extensions.Logging.Abstractions.csproj b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/Microsoft.Extensions.Logging.Abstractions.csproj index afd69709ca517e..15abbdda1651ac 100644 --- a/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/Microsoft.Extensions.Logging.Abstractions.csproj +++ b/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/Microsoft.Extensions.Logging.Abstractions.csproj @@ -34,6 +34,7 @@ Microsoft.Extensions.Logging.Abstractions.NullLogger + diff --git a/src/libraries/Microsoft.Extensions.Logging/ref/Microsoft.Extensions.Logging.cs b/src/libraries/Microsoft.Extensions.Logging/ref/Microsoft.Extensions.Logging.cs index 5b7fade6eaa438..47f6b5ff4969cc 100644 --- a/src/libraries/Microsoft.Extensions.Logging/ref/Microsoft.Extensions.Logging.cs +++ b/src/libraries/Microsoft.Extensions.Logging/ref/Microsoft.Extensions.Logging.cs @@ -26,26 +26,30 @@ public enum ActivityTrackingOptions Tags = 32, Baggage = 64, } + public static partial class EnrichmentExtensions + { + public static Microsoft.Extensions.Logging.ILoggingBuilder Enrich(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string propertyName, System.Func valueFunc) { throw null; } + } public static partial class FilterLoggingBuilderExtensions { public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func levelFilter) { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func categoryLevelFilter) { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func filter) { throw null; } - public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string? category, System.Func levelFilter) { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string? category, Microsoft.Extensions.Logging.LogLevel level) { throw null; } + public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string? category, System.Func levelFilter) { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, System.Func levelFilter) { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, System.Func categoryLevelFilter) { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, System.Func filter) { throw null; } - public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, string? category, System.Func levelFilter) { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, string? category, Microsoft.Extensions.Logging.LogLevel level) { throw null; } + public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, string? category, System.Func levelFilter) { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func levelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func categoryLevelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } - public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string? category, System.Func levelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string? category, Microsoft.Extensions.Logging.LogLevel level) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } + public static Microsoft.Extensions.Logging.ILoggingBuilder AddFilter(this Microsoft.Extensions.Logging.ILoggingBuilder builder, string? category, System.Func levelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, System.Func levelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, System.Func categoryLevelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } - public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, string? category, System.Func levelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, string? category, Microsoft.Extensions.Logging.LogLevel level) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } + public static Microsoft.Extensions.Logging.LoggerFilterOptions AddFilter(this Microsoft.Extensions.Logging.LoggerFilterOptions builder, string? category, System.Func levelFilter) where T : Microsoft.Extensions.Logging.ILoggerProvider { throw null; } } public partial interface ILoggingBuilder { @@ -59,6 +63,7 @@ public LoggerFactory(System.Collections.Generic.IEnumerable providers, Microsoft.Extensions.Options.IOptionsMonitor filterOption) { } public LoggerFactory(System.Collections.Generic.IEnumerable providers, Microsoft.Extensions.Options.IOptionsMonitor filterOption, Microsoft.Extensions.Options.IOptions? options) { } public LoggerFactory(System.Collections.Generic.IEnumerable providers, Microsoft.Extensions.Options.IOptionsMonitor filterOption, Microsoft.Extensions.Options.IOptions? options = null, Microsoft.Extensions.Logging.IExternalScopeProvider? scopeProvider = null) { } + public LoggerFactory(System.Collections.Generic.IEnumerable providers, System.Collections.Generic.IEnumerable processorFactories, Microsoft.Extensions.Options.IOptionsMonitor filterOption, Microsoft.Extensions.Options.IOptions? options = null, Microsoft.Extensions.Logging.IExternalScopeProvider? scopeProvider = null) { } public void AddProvider(Microsoft.Extensions.Logging.ILoggerProvider provider) { } protected virtual bool CheckDisposed() { throw null; } public static Microsoft.Extensions.Logging.ILoggerFactory Create(System.Action configure) { throw null; } @@ -88,6 +93,8 @@ public LoggerFilterRule(string? providerName, string? categoryName, Microsoft.Ex } public static partial class LoggingBuilderExtensions { + public static Microsoft.Extensions.Logging.ILoggingBuilder AddProcessor(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func getProcessor) where T : Microsoft.Extensions.Logging.ILogEntryProcessor { throw null; } + public static Microsoft.Extensions.Logging.ILoggingBuilder AddProcessor(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Func getProcessor) where T : Microsoft.Extensions.Logging.ILogEntryProcessor { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder AddProvider(this Microsoft.Extensions.Logging.ILoggingBuilder builder, Microsoft.Extensions.Logging.ILoggerProvider provider) { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder ClearProviders(this Microsoft.Extensions.Logging.ILoggingBuilder builder) { throw null; } public static Microsoft.Extensions.Logging.ILoggingBuilder Configure(this Microsoft.Extensions.Logging.ILoggingBuilder builder, System.Action action) { throw null; } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/DispatchProcessor.cs b/src/libraries/Microsoft.Extensions.Logging/src/DispatchProcessor.cs new file mode 100644 index 00000000000000..d6d024e176bd1a --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/src/DispatchProcessor.cs @@ -0,0 +1,294 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Linq; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Logging +{ + internal sealed class DispatchProcessor : ILogEntryProcessor + { + private readonly LoggerInformation[] _loggers; + private readonly IExternalScopeProvider? _externalScopeProvider; + + public DispatchProcessor(LoggerInformation[] loggers, IExternalScopeProvider? externalScopeProvider) + { + _loggers = loggers; + _externalScopeProvider = externalScopeProvider; + } + + public LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicCheckRequired) + { + if (metadata != null) + { + LoggerInformation[] filteredLoggers = _loggers.Where(l => l.IsEnabled(metadata.LogLevel)).ToArray(); + if (filteredLoggers.Length == 0) + { + enabled = false; + dynamicCheckRequired = false; + return NullHandler.Instance; + } + else if (filteredLoggers.Length == 1) + { + LoggerInformation loggerInfo = filteredLoggers[0]; + LogEntryHandler? handler = null; + if (loggerInfo.Processor != null) + { + handler = loggerInfo.Processor.GetLogEntryHandler(metadata, out enabled, out dynamicCheckRequired); + if (handler != null) + { + return new DispatchViaHandler(handler); + } + } + } + //TODO: add a more general purpose case that dispatches to N handlers and M loggers + } + + enabled = true; + dynamicCheckRequired = true; + return new DynamicDispatchToLoggers(this, metadata?.GetStringMessageFormatter()); + } + + public ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull + { + enabled = true; + return new DynamicDispatchScopeToLoggers(this); + } + + public bool IsEnabled(LogLevel logLevel) + { + // We could potentially pre-process loggers to remove those with + // MinLevel = None at the cost of another array for every category + LoggerInformation[]? loggers = _loggers; + if (loggers == null) + { + return false; + } + + List? exceptions = null; + int i = 0; + for (; i < loggers.Length; i++) + { + ref readonly LoggerInformation loggerInfo = ref loggers[i]; + if (!loggerInfo.IsEnabled(logLevel)) + { + continue; + } + + if (LoggerIsEnabled(logLevel, loggerInfo.Logger, ref exceptions)) + { + break; + } + } + + if (exceptions != null && exceptions.Count > 0) + { + Logger.ThrowLoggingError(exceptions); + } + + return i < loggers.Length ? true : false; + + static bool LoggerIsEnabled(LogLevel logLevel, ILogger logger, ref List? exceptions) + { + try + { + if (logger.IsEnabled(logLevel)) + { + return true; + } + } + catch (Exception ex) + { + exceptions ??= new List(); + exceptions.Add(ex); + } + + return false; + } + } + + private sealed class NullHandler : LogEntryHandler + { + public static readonly NullHandler Instance = new NullHandler(); + public override void HandleLogEntry(ref LogEntry logEntry) + { + } + public override bool IsEnabled(LogLevel level) => false; + } + + private sealed class NullScopeHandler : ScopeHandler where TState : notnull + { + public static readonly NullScopeHandler Instance = new NullScopeHandler(); + public override IDisposable? HandleBeginScope(ref TState state) => null; + public override bool IsEnabled(LogLevel level) => false; + } + + private sealed class DispatchViaHandler : LogEntryHandler + { + private LogEntryHandler _nestedHandler; + + public DispatchViaHandler(LogEntryHandler handler) + { + _nestedHandler = handler; + } + + public override void HandleLogEntry(ref LogEntry logEntry) + { + try + { + _nestedHandler.HandleLogEntry(ref logEntry); + } + catch (Exception ex) + { + Logger.ThrowLoggingError(new List(new Exception[] { ex })); + } + } + + public override bool IsEnabled(LogLevel level) => _nestedHandler.IsEnabled(level); + } + + private sealed class DispatchViaScopeHandler : ScopeHandler where TState : notnull + { + private ScopeHandler _nestedHandler; + + public DispatchViaScopeHandler(ScopeHandler handler) + { + _nestedHandler = handler; + } + + public override IDisposable? HandleBeginScope(ref TState state) + { + try + { + return _nestedHandler.HandleBeginScope(ref state); + } + catch (Exception ex) + { + Logger.ThrowLoggingError(new List(new Exception[] { ex })); + return null; + } + } + + public override bool IsEnabled(LogLevel level) => _nestedHandler.IsEnabled(level); + } + + private sealed class DynamicDispatchToLoggers : LogEntryHandler + { + private DispatchProcessor _processor; + private Func? _formatter; + + public DynamicDispatchToLoggers(DispatchProcessor processor, Func? formatter) + { + _processor = processor; + _formatter = formatter; + } + + public override void HandleLogEntry(ref LogEntry logEntry) + { + Func? formatter = logEntry.Formatter ?? _formatter; + formatter ??= (TState s, Exception? _) => s == null ? "" : s.ToString() ?? ""; + LoggerInformation[] loggers = _processor._loggers!; + List? exceptions = null; + for (int i = 0; i < loggers.Length; i++) + { + ref readonly LoggerInformation loggerInfo = ref loggers[i]; + if (!loggerInfo.IsEnabled(logEntry.LogLevel)) + { + continue; + } + + try + { + loggerInfo.Logger.Log(logEntry.LogLevel, logEntry.EventId, logEntry.State, logEntry.Exception, formatter); + } + catch (Exception ex) + { + exceptions ??= new List(); + exceptions.Add(ex); + } + } + + if (exceptions != null && exceptions.Count > 0) + { + Logger.ThrowLoggingError(exceptions); + } + } + + public override bool IsEnabled(LogLevel level) => _processor.IsEnabled(level); + } + + private sealed class DynamicDispatchScopeToLoggers : ScopeHandler where TState : notnull + { + private readonly ScopeLogger[] _scopeLoggers; + private readonly DispatchProcessor _processor; + + public DynamicDispatchScopeToLoggers(DispatchProcessor processor) + { + List scopeLoggers = new List(); + + foreach (LoggerInformation loggerInformation in processor._loggers) + { + if (!loggerInformation.ExternalScope && loggerInformation.IsEnabled(LogLevel.Critical)) + { + scopeLoggers.Add(new ScopeLogger(logger: loggerInformation.Logger, externalScopeProvider: null)); + } + } + if (processor._externalScopeProvider is { } scopeProvider) + { + scopeLoggers.Add(new ScopeLogger(logger: null, externalScopeProvider: scopeProvider)); + } + + _scopeLoggers = scopeLoggers.ToArray(); + _processor = processor; + } + + public override IDisposable? HandleBeginScope(ref TState state) + { + ScopeLogger[] loggers = _scopeLoggers; + + if (loggers.Length == 0) + { + return null; + } + if (loggers.Length == 1) + { + return loggers[0].CreateScope(state); + } + + var scope = new Scope(loggers.Length); + List? exceptions = null; + for (int i = 0; i < loggers.Length; i++) + { + ref readonly ScopeLogger loggerInfo = ref loggers[i]; + + try + { + scope.SetDisposable(i, loggerInfo.CreateScope(state)); + } + catch (Exception ex) + { + exceptions ??= new List(); + exceptions.Add(ex); + } + } + + if (exceptions != null && exceptions.Count > 0) + { + ThrowLoggingError(exceptions); + } + + return scope; + } + + private static void ThrowLoggingError(List exceptions) + { + throw new AggregateException( + message: "An error occurred while writing to logger(s).", innerExceptions: exceptions); + } + + public override bool IsEnabled(LogLevel level) => _processor.IsEnabled(level); + } + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/src/EnrichmentExtensions.cs b/src/libraries/Microsoft.Extensions.Logging/src/EnrichmentExtensions.cs new file mode 100644 index 00000000000000..efa1d135a3137a --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/src/EnrichmentExtensions.cs @@ -0,0 +1,646 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Buffers; +using System.Collections; +using System.Collections.Generic; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Logging +{ + public static class EnrichmentExtensions + { + public static ILoggingBuilder Enrich(this ILoggingBuilder builder, string propertyName, Func valueFunc) + { + builder.AddProcessor((sp, next) => + { + IEnumerable props = sp.GetServices(); + EnrichmentPropertiesCollection collection = new EnrichmentPropertiesCollection(); + foreach (var prop in props) + { + collection = prop.AppendTo(collection); + } + return new EnrichmentProcessor(collection, next); + }); + builder.Services.AddSingleton(new EnrichmentProperty(propertyName, valueFunc)); + return builder; + } + + internal abstract class EnrichmentProperty + { + internal abstract EnrichmentPropertiesCollection AppendTo(EnrichmentPropertiesCollection collection); + } + + internal sealed class EnrichmentProperty : EnrichmentProperty + { + public EnrichmentProperty(string name, Func getValue) + { + Name = name; + GetValue = getValue; + } + + public string Name { get; } + public Func GetValue { get; } + + internal override EnrichmentPropertiesCollection AppendTo(EnrichmentPropertiesCollection collection) + { + return collection.AddProperty(Name, GetValue); + } + } + } + + internal sealed class EnrichmentProcessor : ILogEntryProcessor + { + private readonly ILogEntryProcessor _nextProcessor; + private readonly EnrichmentPropertiesCollection _propCollection; + + public EnrichmentProcessor(EnrichmentPropertiesCollection collection, ILogEntryProcessor nextProcessor) + { + _propCollection = collection; + _nextProcessor = nextProcessor; + } + public LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + return _propCollection.GetLogEntryHandler(_nextProcessor, metadata, out enabled, out dynamicEnabledCheckRequired); + } + + public ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull + { + return _nextProcessor.GetScopeHandler(metadata, out enabled); + } + + public bool IsEnabled(LogLevel logLevel) + { + return _nextProcessor.IsEnabled(logLevel); + } + } + + internal class EnrichmentPropertiesCollection + { + internal virtual EnrichmentPropertiesCollection AddProperty(string propertyName, Func getValue) + { + return new EnrichmentPropertiesCollection(propertyName, getValue); + } + + internal virtual LogEntryHandler GetLogEntryHandler(ILogEntryProcessor nextProcessor, ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + return nextProcessor.GetLogEntryHandler(metadata, out enabled, out dynamicEnabledCheckRequired); + } + } + + internal sealed class EnrichmentPropertiesCollection : EnrichmentPropertiesCollection + { + internal readonly string Name0; + internal readonly Func GetValue0; + + public EnrichmentPropertiesCollection(string name0, Func getValue0) + { + Name0 = name0; + GetValue0 = getValue0; + } + + internal override EnrichmentPropertiesCollection AddProperty(string propertyName, Func getValue) + { + return new EnrichmentPropertiesCollection(Name0, GetValue0, propertyName, getValue); + } + + internal override LogEntryHandler GetLogEntryHandler(ILogEntryProcessor nextProcessor, ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + var enrichmentMetadata = metadata != null ? new EnrichmentLogMetadata(metadata, Name0) : null; + LogEntryHandler> nextHandler = + nextProcessor.GetLogEntryHandler>(enrichmentMetadata, out enabled, out dynamicEnabledCheckRequired); + return new EnrichmentHandler(nextHandler, this); + } + + private sealed class EnrichmentHandler : LogEntryHandler + { + private LogEntryHandler> _nextHandler; + private EnrichmentPropertiesCollection _propertyCollection; + + public EnrichmentHandler(LogEntryHandler> nextHandler, EnrichmentPropertiesCollection propertyCollection) + { + _nextHandler = nextHandler; + _propertyCollection = propertyCollection; + } + + public override void HandleLogEntry(ref LogEntry logEntry) + { + EnrichmentPropertyValues enrichmentProperties = new EnrichmentPropertyValues(logEntry.State, new KeyValuePair(_propertyCollection.Name0, _propertyCollection.GetValue0()), logEntry.Formatter); + var newLogEntry = new LogEntry>(logEntry.LogLevel, category: null!, logEntry.EventId, enrichmentProperties, logEntry.Exception, EnrichmentPropertyValues.Format); + _nextHandler.HandleLogEntry(ref newLogEntry); + } + + public override bool IsEnabled(LogLevel level) => _nextHandler.IsEnabled(level); + } + + private sealed class EnrichmentLogMetadata : ILogMetadata> + { + private readonly ILogMetadata _innerMetadata; + private readonly string _name0; + + public EnrichmentLogMetadata(ILogMetadata innerMetadata, string name0) + { + _innerMetadata = innerMetadata; + _name0 = name0; + } + + public LogLevel LogLevel => _innerMetadata.LogLevel; + public EventId EventId => _innerMetadata.EventId; + public string OriginalFormat => _innerMetadata.OriginalFormat; + public int PropertyCount => _innerMetadata.PropertyCount + 1; + public void AppendFormattedMessage(in EnrichmentPropertyValues state, IBufferWriter buffer) => _innerMetadata.AppendFormattedMessage(state.NestedProperties, buffer); + public Action, IBufferWriter> GetMessageFormatter(PropertyCustomFormatter[] customFormatters) + { + var formatter = _innerMetadata.GetMessageFormatter(customFormatters); + return (e, w) => formatter(e.NestedProperties, w); + } + public FormatPropertyListAction> GetPropertyListFormatter(IPropertyFormatterFactory propertyFormatterFactory) + { + FormatPropertyListAction formatter = _innerMetadata.GetPropertyListFormatter(propertyFormatterFactory); + return new FormatPropertyListAction>((in EnrichmentPropertyValues s, ref BufferWriter w) => formatter(in s.NestedProperties, ref w)); + } + public LogPropertyInfo GetPropertyInfo(int index) + { + if (index < _innerMetadata.PropertyCount) + { + return _innerMetadata.GetPropertyInfo(index); + } + var i = index - _innerMetadata.PropertyCount; + if (i == 0) + { + return new LogPropertyInfo(_name0, null); + } + else + { + throw new IndexOutOfRangeException(nameof(index)); + } + } + public Func, Exception?, string> GetStringMessageFormatter() + { + var formatter = _innerMetadata.GetStringMessageFormatter(); + return (e, ex) => formatter(e.NestedProperties, ex); + } + } + } + + internal sealed class EnrichmentPropertiesCollection : EnrichmentPropertiesCollection + { + internal string Name0; + internal Func GetValue0; + internal string Name1; + internal Func GetValue1; + + public EnrichmentPropertiesCollection(string name0, Func getValue0, string name1, Func getValue1) + { + Name0 = name0; + GetValue0 = getValue0; + Name1 = name1; + GetValue1 = getValue1; + } + + internal override EnrichmentPropertiesCollection AddProperty(string propertyName, Func getValue) + { + var overflowProperties = new List<(string, Func)>(); + overflowProperties.Add((propertyName, () => getValue())); + var collection = new UnboundedEnrichmentPropertiesCollection(Name0, GetValue0, Name1, GetValue1, overflowProperties); + return collection; + } + + internal override LogEntryHandler GetLogEntryHandler(ILogEntryProcessor nextProcessor, ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + var enrichmentMetadata = metadata != null ? new EnrichmentLogMetadata(metadata, Name0, Name1) : null; + LogEntryHandler> nextHandler = + nextProcessor.GetLogEntryHandler>(enrichmentMetadata, out enabled, out dynamicEnabledCheckRequired); + return new EnrichmentHandler(nextHandler, this); + } + + private sealed class EnrichmentHandler : LogEntryHandler + { + private readonly LogEntryHandler> _nextHandler; + private readonly EnrichmentPropertiesCollection _propertyCollection; + + public EnrichmentHandler(LogEntryHandler> nextHandler, EnrichmentPropertiesCollection propertyCollection) + { + _nextHandler = nextHandler; + _propertyCollection = propertyCollection; + } + + public override void HandleLogEntry(ref LogEntry logEntry) + { + EnrichmentPropertyValues enrichmentProperties = new EnrichmentPropertyValues( + logEntry.State, + new KeyValuePair(_propertyCollection.Name0, _propertyCollection.GetValue0()), + new KeyValuePair(_propertyCollection.Name1, _propertyCollection.GetValue1()), + logEntry.Formatter); + var newLogEntry = new LogEntry>(logEntry.LogLevel, category: null!, logEntry.EventId, enrichmentProperties, logEntry.Exception, EnrichmentPropertyValues.Format); + _nextHandler.HandleLogEntry(ref newLogEntry); + } + + public override bool IsEnabled(LogLevel level) => _nextHandler.IsEnabled(level); + } + + private sealed class EnrichmentLogMetadata : ILogMetadata> + { + private readonly ILogMetadata _innerMetadata; + private readonly string _name0; + private readonly string _name1; + + public EnrichmentLogMetadata(ILogMetadata innerMetadata, string name0, string name1) + { + _innerMetadata = innerMetadata; + _name0 = name0; + _name1 = name1; + } + + public LogLevel LogLevel => _innerMetadata.LogLevel; + public EventId EventId => _innerMetadata.EventId; + public string OriginalFormat => _innerMetadata.OriginalFormat; + public int PropertyCount => _innerMetadata.PropertyCount + 2; + public void AppendFormattedMessage(in EnrichmentPropertyValues state, IBufferWriter buffer) => _innerMetadata.AppendFormattedMessage(state.NestedProperties, buffer); + public Action, IBufferWriter> GetMessageFormatter(PropertyCustomFormatter[] customFormatters) + { + var formatter = _innerMetadata.GetMessageFormatter(customFormatters); + return (e, w) => formatter(e.NestedProperties, w); + } + public FormatPropertyListAction> GetPropertyListFormatter(IPropertyFormatterFactory propertyFormatterFactory) + { + FormatPropertyListAction formatter = _innerMetadata.GetPropertyListFormatter(propertyFormatterFactory); + return new FormatPropertyListAction>((in EnrichmentPropertyValues s, ref BufferWriter w) => formatter(in s.NestedProperties, ref w)); + } + public LogPropertyInfo GetPropertyInfo(int index) + { + if (index < _innerMetadata.PropertyCount) + { + return _innerMetadata.GetPropertyInfo(index); + } + var i = index - _innerMetadata.PropertyCount; + if (i == 0) + { + return new LogPropertyInfo(_name0, null); + } + else if (i == 1) + { + return new LogPropertyInfo(_name1, null); + } + else + { + throw new IndexOutOfRangeException(nameof(index)); + } + } + public Func, Exception?, string> GetStringMessageFormatter() + { + var formatter = _innerMetadata.GetStringMessageFormatter(); + return (e, ex) => formatter(e.NestedProperties, ex); + } + } + } + + internal sealed class UnboundedEnrichmentPropertiesCollection : EnrichmentPropertiesCollection + { + internal readonly string Name0; + internal readonly Func GetValue0; + internal readonly string Name1; + internal readonly Func GetValue1; + internal readonly List<(string, Func)> OverflowProperties; + + public UnboundedEnrichmentPropertiesCollection(string name0, Func getValue0, string name1, Func getValue1, List<(string, Func)> overflowProperties) + { + Name0 = name0; + GetValue0 = getValue0; + Name1 = name1; + GetValue1 = getValue1; + OverflowProperties = overflowProperties; + } + + internal override EnrichmentPropertiesCollection AddProperty(string propertyName, Func getValue) + { + OverflowProperties.Add((propertyName, () => getValue())); + return this; + } + + internal override LogEntryHandler GetLogEntryHandler(ILogEntryProcessor nextProcessor, ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + var enrichmentMetadata = metadata != null ? new EnrichmentLogMetadata(metadata, Name0, Name1, OverflowProperties) : null; + LogEntryHandler> nextHandler = + nextProcessor.GetLogEntryHandler>(enrichmentMetadata, out enabled, out dynamicEnabledCheckRequired); + return new EnrichmentHandler(nextHandler, this); + } + + private sealed class EnrichmentHandler : LogEntryHandler + { + private readonly LogEntryHandler> _nextHandler; + private readonly UnboundedEnrichmentPropertiesCollection _propertyCollection; + + public EnrichmentHandler(LogEntryHandler> nextHandler, UnboundedEnrichmentPropertiesCollection propertyCollection) + { + _nextHandler = nextHandler; + _propertyCollection = propertyCollection; + } + + public override void HandleLogEntry(ref LogEntry logEntry) + { + int overflowProps = _propertyCollection.OverflowProperties.Count; + var extraValues = new KeyValuePair[overflowProps]; + for (int i = 0; i < overflowProps; i++) + { + var property = _propertyCollection.OverflowProperties[i]; + extraValues[i] = new KeyValuePair(property.Item1, property.Item2()); + } + + UnboundedEnrichmentPropertyValues enrichmentProperties = new UnboundedEnrichmentPropertyValues( + logEntry.State, + new KeyValuePair(_propertyCollection.Name0, _propertyCollection.GetValue0()), + new KeyValuePair(_propertyCollection.Name1, _propertyCollection.GetValue1()), + extraValues, + logEntry.Formatter); + var newLogEntry = new LogEntry>(logEntry.LogLevel, category: null!, logEntry.EventId, enrichmentProperties, logEntry.Exception, UnboundedEnrichmentPropertyValues.Format); + _nextHandler.HandleLogEntry(ref newLogEntry); + } + + public override bool IsEnabled(LogLevel level) => _nextHandler.IsEnabled(level); + } + + private sealed class EnrichmentLogMetadata : ILogMetadata> + { + private ILogMetadata _innerMetadata { get; } + private readonly string _name0; + private readonly string _name1; + private readonly List<(string, Func)> _overflowProperties; + + public EnrichmentLogMetadata(ILogMetadata innerMetadata, string name0, string name1, List<(string, Func)> overflowProperties) + { + _innerMetadata = innerMetadata; + _name0 = name0; + _name1 = name1; + _overflowProperties = overflowProperties; + } + + public LogLevel LogLevel => _innerMetadata.LogLevel; + public EventId EventId => _innerMetadata.EventId; + public string OriginalFormat => _innerMetadata.OriginalFormat; + public int PropertyCount => _innerMetadata.PropertyCount + 2 + _overflowProperties.Count; + public void AppendFormattedMessage(in UnboundedEnrichmentPropertyValues state, IBufferWriter buffer) => _innerMetadata.AppendFormattedMessage(state.NestedProperties, buffer); + public Action, IBufferWriter> GetMessageFormatter(PropertyCustomFormatter[] customFormatters) + { + var formatter = _innerMetadata.GetMessageFormatter(customFormatters); + return (e, w) => formatter(e.NestedProperties, w); + } + public FormatPropertyListAction> GetPropertyListFormatter(IPropertyFormatterFactory propertyFormatterFactory) + { + FormatPropertyListAction formatter = _innerMetadata.GetPropertyListFormatter(propertyFormatterFactory); + return new FormatPropertyListAction>((in UnboundedEnrichmentPropertyValues s, ref BufferWriter w) => formatter(in s.NestedProperties, ref w)); + } + public LogPropertyInfo GetPropertyInfo(int index) + { + if (index < _innerMetadata.PropertyCount) + { + return _innerMetadata.GetPropertyInfo(index); + } + var i = index - _innerMetadata.PropertyCount; + if (i == 0) + { + return new LogPropertyInfo(_name0, null); + } + else if (i == 1) + { + return new LogPropertyInfo(_name1, null); + } + else + { + return new LogPropertyInfo(_overflowProperties[i - 2].Item1, null); + } + } + public Func, Exception?, string> GetStringMessageFormatter() + { + var formatter = _innerMetadata.GetStringMessageFormatter(); + return (e, ex) => formatter(e.NestedProperties, ex); + } + } + } + + internal readonly struct EnrichmentPropertyValues : IReadOnlyList> + { + internal readonly TEnrichmentProperties NestedProperties; + internal readonly KeyValuePair Prop0; + internal readonly Func Formatter; + + public EnrichmentPropertyValues(TEnrichmentProperties nestedProperties, KeyValuePair prop0, Func formatter) + { + NestedProperties = nestedProperties; + Prop0 = prop0; + Formatter = formatter; + } + + public int Count + { + get + { + var nested = NestedProperties as IReadOnlyList>; + return (nested?.Count ?? 0) + 1; + } + } + + public KeyValuePair this[int index] + { + get + { + var nested = NestedProperties as IReadOnlyList>; + if (nested != null && index < nested.Count) + { + return nested[index]; + } + + var i = index - nested?.Count ?? 0; + if (i == 0) + { + return Prop0; + } + else + { + throw new IndexOutOfRangeException(nameof(index)); + } + } + } + + public override string ToString() => NestedProperties?.ToString() ?? string.Empty; + + public static string Format(EnrichmentPropertyValues state, Exception? exception) + { + return state.Formatter(state.NestedProperties, exception); + } + + public IEnumerator> GetEnumerator() + { + var nested = NestedProperties as IReadOnlyList>; + if (nested != null) + { + foreach (var item in nested) + { + yield return item; + } + } + + yield return Prop0; + } + + IEnumerator IEnumerable.GetEnumerator() => GetEnumerator(); + } + + internal readonly struct EnrichmentPropertyValues : IReadOnlyList> + { + internal readonly TEnrichmentProperties NestedProperties; + internal readonly KeyValuePair Prop0; + internal readonly KeyValuePair Prop1; + internal readonly Func Formatter; + + public EnrichmentPropertyValues(TEnrichmentProperties nestedProperties, KeyValuePair prop0, KeyValuePair prop1, Func formatter) + { + NestedProperties = nestedProperties; + Prop0 = prop0; + Prop1 = prop1; + Formatter = formatter; + } + + public int Count + { + get + { + var nested = NestedProperties as IReadOnlyList>; + return (nested?.Count ?? 0) + 2; + } + } + + public KeyValuePair this[int index] + { + get + { + var nested = NestedProperties as IReadOnlyList>; + if (nested != null && index < nested.Count) + { + return nested[index]; + } + + var i = index - nested?.Count ?? 0; + if (i == 0) + { + return Prop0; + } + else if (i == 1) + { + return Prop1; + } + else + { + throw new IndexOutOfRangeException(nameof(index)); + } + } + } + + public override string ToString() => NestedProperties?.ToString() ?? string.Empty; + + public static string Format(EnrichmentPropertyValues state, Exception? exception) + { + return state.Formatter(state.NestedProperties, exception); + } + + public IEnumerator> GetEnumerator() + { + var nested = NestedProperties as IReadOnlyList>; + if (nested != null) + { + for (var i = 0; i < nested.Count; i++) + { + yield return nested[i]; + } + } + + yield return Prop0; + yield return Prop1; + } + + IEnumerator IEnumerable.GetEnumerator() => GetEnumerator(); + } + + internal readonly struct UnboundedEnrichmentPropertyValues : IReadOnlyList> + { + internal readonly TEnrichmentProperties NestedProperties; + internal readonly KeyValuePair Prop0; + internal readonly KeyValuePair Prop1; + internal readonly KeyValuePair[] ExtraValues; + internal readonly Func Formatter; + + public UnboundedEnrichmentPropertyValues(TEnrichmentProperties nestedProperties, KeyValuePair prop0, KeyValuePair prop1, KeyValuePair[] extraValues, Func formatter) + { + NestedProperties = nestedProperties; + Prop0 = prop0; + Prop1 = prop1; + ExtraValues = extraValues; + Formatter = formatter; + } + + public int Count + { + get + { + var nested = NestedProperties as IReadOnlyList>; + return (nested?.Count ?? 0) + 2 + ExtraValues.Length; + } + } + + public KeyValuePair this[int index] + { + get + { + var nested = NestedProperties as IReadOnlyList>; + if (nested != null && index < nested.Count) + { + return nested[index]; + } + + var i = index - nested?.Count ?? 0; + if (i == 0) + { + return Prop0; + } + else if (i == 1) + { + return Prop1; + } + else + { + return ExtraValues[i - 2]; + } + } + } + + public override string ToString() => NestedProperties?.ToString() ?? string.Empty; + + public static string Format(UnboundedEnrichmentPropertyValues state, Exception? exception) + { + return state.Formatter(state.NestedProperties, exception); + } + + public IEnumerator> GetEnumerator() + { + var nested = NestedProperties as IReadOnlyList>; + if (nested != null) + { + for (var i = 0; i < nested.Count; i++) + { + yield return nested[i]; + } + } + + yield return Prop0; + yield return Prop1; + for (var i = 0; i < ExtraValues.Length; i++) + { + yield return ExtraValues[i]; + } + } + + IEnumerator IEnumerable.GetEnumerator() => GetEnumerator(); + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs index 86524a2f03d3ff..74d4af9e958dcd 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs @@ -3,201 +3,230 @@ using System; using System.Collections.Generic; +using System.Diagnostics; +using Microsoft.Extensions.Logging.Abstractions; namespace Microsoft.Extensions.Logging { - internal sealed class Logger : ILogger + internal sealed class Logger : ILogger, ILogEntryPipelineFactory { - public Logger(LoggerInformation[] loggers) => Loggers = loggers; + private readonly LoggerFactory _loggerFactory; - public LoggerInformation[] Loggers { get; set; } - public MessageLogger[]? MessageLoggers { get; set; } - public ScopeLogger[]? ScopeLoggers { get; set; } + public Logger(LoggerFactory loggerFactory) + { + _loggerFactory = loggerFactory; + } + + public VersionedLoggerState VersionedState { get; set; } = VersionedLoggerState.Default; + + public Action ProcessorInvalidated => () => _loggerFactory.OnProcessorInvalidated(this); + + public LogEntryPipeline? GetLoggingPipeline(ILogMetadata? metadata, object? userState) + { + return VersionedState.GetLoggingPipeline(metadata, userState); + } + + public ScopePipeline? GetScopePipeline(ILogMetadata? metadata, object? userState) where TState : notnull + { + return VersionedState.GetScopePipeline(metadata, userState); + } public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) { - MessageLogger[]? loggers = MessageLoggers; - if (loggers == null) + LogEntryPipeline pipeline = GetLoggingPipeline(metadata: null, this)!; + if (!pipeline.IsEnabled || (pipeline.IsDynamicLevelCheckRequired && !pipeline.IsEnabledDynamic(logLevel))) { return; } + LogEntry logEntry = new LogEntry(logLevel, category: null!, eventId, state, exception, formatter); + pipeline.HandleLogEntry(ref logEntry); + } - List? exceptions = null; - for (int i = 0; i < loggers.Length; i++) + public bool IsEnabled(LogLevel level) + { + ILogEntryProcessor processor = VersionedState.Processor; + if (processor != null) { - ref readonly MessageLogger loggerInfo = ref loggers[i]; - if (!loggerInfo.IsEnabled(logLevel)) - { - continue; - } - - LoggerLog(logLevel, eventId, loggerInfo.Logger, exception, formatter, ref exceptions, state); + return processor.IsEnabled(level); } + return false; + } - if (exceptions != null && exceptions.Count > 0) + public IDisposable? BeginScope(TState state) where TState : notnull + { + ScopePipeline? pipeline = GetScopePipeline(metadata: null, this); + if (pipeline is null || !pipeline.IsEnabled) { - ThrowLoggingError(exceptions); + return null; } + return pipeline.HandleScope(ref state); + } - static void LoggerLog(LogLevel logLevel, EventId eventId, ILogger logger, Exception? exception, Func formatter, ref List? exceptions, in TState state) - { - try - { - logger.Log(logLevel, eventId, state, exception, formatter); - } - catch (Exception ex) - { - exceptions ??= new List(); - exceptions.Add(ex); - } - } + internal static void ThrowLoggingError(List exceptions) + { + throw new AggregateException( + message: "An error occurred while writing to logger(s).", innerExceptions: exceptions); } + } - public bool IsEnabled(LogLevel logLevel) + internal sealed class Scope : IDisposable + { + private bool _isDisposed; + + private IDisposable? _disposable0; + private IDisposable? _disposable1; + private readonly IDisposable?[]? _disposable; + + public Scope(int count) { - MessageLogger[]? loggers = MessageLoggers; - if (loggers == null) + if (count > 2) { - return false; + _disposable = new IDisposable[count - 2]; } + } - List? exceptions = null; - int i = 0; - for (; i < loggers.Length; i++) + public void SetDisposable(int index, IDisposable? disposable) + { + switch (index) { - ref readonly MessageLogger loggerInfo = ref loggers[i]; - if (!loggerInfo.IsEnabled(logLevel)) - { - continue; - } - - if (LoggerIsEnabled(logLevel, loggerInfo.Logger, ref exceptions)) - { + case 0: + _disposable0 = disposable; + break; + case 1: + _disposable1 = disposable; + break; + default: + _disposable![index - 2] = disposable; break; - } } + } - if (exceptions != null && exceptions.Count > 0) + public void Dispose() + { + if (!_isDisposed) { - ThrowLoggingError(exceptions); - } - - return i < loggers.Length ? true : false; + _disposable0?.Dispose(); + _disposable1?.Dispose(); - static bool LoggerIsEnabled(LogLevel logLevel, ILogger logger, ref List? exceptions) - { - try + if (_disposable != null) { - if (logger.IsEnabled(logLevel)) + int count = _disposable.Length; + for (int index = 0; index != count; ++index) { - return true; + _disposable[index]?.Dispose(); } } - catch (Exception ex) - { - exceptions ??= new List(); - exceptions.Add(ex); - } - return false; + _isDisposed = true; } } + } - public IDisposable? BeginScope(TState state) where TState : notnull + internal sealed class VersionedLoggerState + { + public static readonly VersionedLoggerState Default = new VersionedLoggerState(); + + public VersionedLoggerState() { - ScopeLogger[]? loggers = ScopeLoggers; + Loggers = Array.Empty(); + Processor = NullLogProcessor.Instance; + FilterOptions = new LoggerFilterOptions(); + } - if (loggers == null) - { - return NullScope.Instance; - } + public VersionedLoggerState(LoggerInformation[] loggers, ILogEntryProcessor processor, LoggerFilterOptions filterOptions) + { + Loggers = loggers; + Processor = processor; + FilterOptions = filterOptions; + _isUpToDate = true; + } - if (loggers.Length == 1) - { - return loggers[0].CreateScope(state); - } + private bool _isUpToDate; + public LoggerInformation[] Loggers { get; } + public ILogEntryProcessor Processor { get; } + public LoggerFilterOptions FilterOptions { get; } + public Dictionary Pipelines { get; } = new Dictionary(); - var scope = new Scope(loggers.Length); - List? exceptions = null; - for (int i = 0; i < loggers.Length; i++) - { - ref readonly ScopeLogger scopeLogger = ref loggers[i]; + public LogEntryPipeline? GetLoggingPipeline(ILogMetadata? metadata, object? userState) + { + // The default versioned state should never be used to create pipelines, it is a shared singleton + // that exists just to satisfy nullability checks + Debug.Assert(this != Default); - try - { - scope.SetDisposable(i, scopeLogger.CreateScope(state)); - } - catch (Exception ex) + Pipeline? pipeline; + PipelineKey key = new PipelineKey(isLoggingPipeline: true, (metadata == null) ? typeof(TState) : metadata, terminalProcessor: null, userState: userState); + lock (Pipelines) + { + if (!Pipelines.TryGetValue(key, out pipeline)) { - exceptions ??= new List(); - exceptions.Add(ex); + LogEntryHandler handler = Processor.GetLogEntryHandler(metadata, out bool enabled, out bool dynamicCheckRequired); + pipeline = new LogEntryPipeline(handler, userState, enabled, dynamicCheckRequired); + // in a multi-threaded race it is possible to create new pipelines after the versioned state is already disposed + // if this happens the pipeline is immediately marked as being not up-to-date. + pipeline.IsUpToDate = _isUpToDate; + Pipelines[key] = pipeline; } } - - if (exceptions != null && exceptions.Count > 0) - { - ThrowLoggingError(exceptions); - } - - return scope; - } - - private static void ThrowLoggingError(List exceptions) - { - throw new AggregateException( - message: "An error occurred while writing to logger(s).", innerExceptions: exceptions); + return (LogEntryPipeline?)pipeline; } - private sealed class Scope : IDisposable + public ScopePipeline? GetScopePipeline(ILogMetadata? metadata, object? userState) where TState : notnull { - private bool _isDisposed; + // The default versioned state should never be used to create pipelines, it is a shared singleton + // that exists just to satisfy nullability checks + Debug.Assert(this != Default); - private IDisposable? _disposable0; - private IDisposable? _disposable1; - private readonly IDisposable?[]? _disposable; + if (!FilterOptions.CaptureScopes) + { + return null; + } - public Scope(int count) + Pipeline? pipeline; + PipelineKey key = new PipelineKey(isLoggingPipeline: false, (metadata == null) ? typeof(TState) : metadata, terminalProcessor: null, userState: userState); + lock (Pipelines) { - if (count > 2) + if (!Pipelines.TryGetValue(key, out pipeline)) { - _disposable = new IDisposable[count - 2]; + ScopeHandler handler = Processor.GetScopeHandler(metadata, out bool enabled); + pipeline = new ScopePipeline(handler, userState, enabled); + // in a multi-threaded race it is possible to create new pipelines after the versioned state is already disposed + // if this happens the pipeline is immediately marked as being not up-to-date. + pipeline.IsUpToDate = _isUpToDate; + Pipelines[key] = pipeline; } } + return (ScopePipeline?)pipeline; + } - public void SetDisposable(int index, IDisposable? disposable) + public void MarkNotUpToDate() + { + lock (Pipelines) { - switch (index) + _isUpToDate = false; + foreach (Pipeline pipeline in Pipelines.Values) { - case 0: - _disposable0 = disposable; - break; - case 1: - _disposable1 = disposable; - break; - default: - _disposable![index - 2] = disposable; - break; + pipeline.IsUpToDate = false; } } + } - public void Dispose() + private sealed class NullLogProcessor : ILogEntryProcessor + { + public static readonly NullLogProcessor Instance = new NullLogProcessor(); + + public LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) { - if (!_isDisposed) - { - _disposable0?.Dispose(); - _disposable1?.Dispose(); + throw new NotImplementedException(); + } - if (_disposable != null) - { - int count = _disposable.Length; - for (int index = 0; index != count; ++index) - { - _disposable[index]?.Dispose(); - } - } + public ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull + { + throw new NotImplementedException(); + } - _isDisposed = true; - } + public bool IsEnabled(LogLevel logLevel) + { + return false; } } } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs index eb2a22b2f1a983..72c69cde9ede57 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs @@ -3,12 +3,16 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Diagnostics.CodeAnalysis; +using System.Linq; +using System.Threading; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Options; namespace Microsoft.Extensions.Logging { + /// /// Produces instances of classes based on the given providers. /// @@ -22,6 +26,7 @@ public class LoggerFactory : ILoggerFactory private LoggerFilterOptions _filterOptions; private IExternalScopeProvider? _scopeProvider; private readonly LoggerFactoryOptions _factoryOptions; + private IProcessorFactory[] _processorFactories; /// /// Creates a new instance. @@ -62,7 +67,23 @@ public LoggerFactory(IEnumerable providers, IOptionsMonitorThe providers to use in producing instances. /// The filter option to use. /// The . - public LoggerFactory(IEnumerable providers, IOptionsMonitor filterOption, IOptions? options) : this(providers, filterOption, options, null) + public LoggerFactory(IEnumerable providers, IOptionsMonitor filterOption, IOptions? options) : + this(providers, Array.Empty(), filterOption, options, null) + { + } + + /// + /// Creates a new instance. + /// + /// The providers to use in producing instances. + /// The filter option to use. + /// The . + /// The . + public LoggerFactory(IEnumerable providers, + IOptionsMonitor filterOption, + IOptions? options = null, + IExternalScopeProvider? scopeProvider = null) : + this(providers, Array.Empty(), filterOption, options, scopeProvider) { } @@ -70,10 +91,15 @@ public LoggerFactory(IEnumerable providers, IOptionsMonitor instance. /// /// The providers to use in producing instances. + /// The processor factories to use in the logging pipeline. /// The filter option to use. /// The . /// The . - public LoggerFactory(IEnumerable providers, IOptionsMonitor filterOption, IOptions? options = null, IExternalScopeProvider? scopeProvider = null) + public LoggerFactory(IEnumerable providers, + IEnumerable processorFactories, + IOptionsMonitor filterOption, + IOptions? options = null, + IExternalScopeProvider? scopeProvider = null) { _scopeProvider = scopeProvider; @@ -86,7 +112,7 @@ public LoggerFactory(IEnumerable providers, IOptionsMonitor providers, IOptionsMonitor registeredLogger in _loggers) { Logger logger = registeredLogger.Value; - (logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers); + UpdateLogger(logger); } } } + internal void OnProcessorInvalidated(Logger logger) + { + lock (_sync) + { + UpdateLogger(logger); + } + } + + private void UpdateLogger(Logger logger) + { + Debug.Assert(Monitor.IsEntered(_sync)); + LoggerInformation[] loggerInfos = logger.VersionedState.Loggers; + for (int i = 0; i < loggerInfos.Length; i++) + { + LoggerInformation previousInfo = loggerInfos[i]; + loggerInfos[i] = CreateLoggerInformation(logger, previousInfo.Provider, previousInfo.Category, previousInfo.Logger, previousInfo.Processor, previousInfo.ProcessorCancelRegistration); + } + UpdateLogger(logger, loggerInfos); + } + + private void UpdateLogger(Logger logger, LoggerInformation[] loggerInfos) + { + Debug.Assert(Monitor.IsEntered(_sync)); + VersionedLoggerState oldState = logger.VersionedState; + // Even though we set new versioned state before disposing the old one keep in mind that + // it is still possible for a concurrent operation to capture the versioned state before + // it was replaced and then use it after it was disposed. + logger.VersionedState = new VersionedLoggerState(loggerInfos, GetProcessor(loggerInfos), _filterOptions); + oldState.MarkNotUpToDate(); + } + + private ILogEntryProcessor GetProcessor(LoggerInformation[] loggerInfos) + { + ILogEntryProcessor processor = new DispatchProcessor(loggerInfos, _scopeProvider); + for (int i = _processorFactories.Length - 1; i >= 0; i--) + { + processor = _processorFactories[i].GetProcessor(processor); + } + return processor; + } + /// /// Creates an with the given . /// @@ -142,10 +211,9 @@ public ILogger CreateLogger(string categoryName) { if (!_loggers.TryGetValue(categoryName, out Logger? logger)) { - logger = new Logger(CreateLoggers(categoryName)); - - (logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers); - + logger = new Logger(this); + LoggerInformation[] loggerInfos = CreateLoggers(logger, categoryName); + UpdateLogger(logger, loggerInfos); _loggers[categoryName] = logger; } @@ -164,7 +232,7 @@ public void AddProvider(ILoggerProvider provider) throw new ObjectDisposedException(nameof(LoggerFactory)); } - ThrowHelper.ThrowIfNull(provider); + if (provider == null) throw new ArgumentNullException(nameof(provider)); lock (_sync) { @@ -173,14 +241,12 @@ public void AddProvider(ILoggerProvider provider) foreach (KeyValuePair existingLogger in _loggers) { Logger logger = existingLogger.Value; - LoggerInformation[] loggerInformation = logger.Loggers; - - int newLoggerIndex = loggerInformation.Length; - Array.Resize(ref loggerInformation, loggerInformation.Length + 1); - loggerInformation[newLoggerIndex] = new LoggerInformation(provider, existingLogger.Key); + LoggerInformation[] loggerInformation = logger.VersionedState.Loggers; - logger.Loggers = loggerInformation; - (logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers); + int newLoggerIndex = loggerInformation == null ? 0 : loggerInformation.Length; + Array.Resize(ref loggerInformation, newLoggerIndex + 1); + loggerInformation[newLoggerIndex] = CreateLoggerInformation(logger, provider, existingLogger.Key); + UpdateLogger(logger, loggerInformation); } } } @@ -201,48 +267,55 @@ private void AddProviderRegistration(ILoggerProvider provider, bool dispose) } } - private LoggerInformation[] CreateLoggers(string categoryName) + private LoggerInformation[] CreateLoggers(Logger logger, string categoryName) { var loggers = new LoggerInformation[_providerRegistrations.Count]; for (int i = 0; i < _providerRegistrations.Count; i++) { - loggers[i] = new LoggerInformation(_providerRegistrations[i].Provider, categoryName); + loggers[i] = CreateLoggerInformation(logger, _providerRegistrations[i].Provider, categoryName); } return loggers; } - private (MessageLogger[] MessageLoggers, ScopeLogger[]? ScopeLoggers) ApplyFilters(LoggerInformation[] loggers) + private LoggerInformation CreateLoggerInformation( + Logger logger, + ILoggerProvider provider, + string category, + ILogger? existingLogger = null, + ILogEntryProcessor? existingProcessor = null, + CancellationTokenRegistration? existingProcCancelRegistration = null) { - var messageLoggers = new List(); - List? scopeLoggers = _filterOptions.CaptureScopes ? new List() : null; - - foreach (LoggerInformation loggerInformation in loggers) + LoggerRuleSelector.Select(_filterOptions, + provider.GetType(), + category, + out LogLevel? minLevel, + out Func? filter); + + ILogger loggerSink = existingLogger ?? provider.CreateLogger(category); + minLevel ??= LogLevel.Trace; + + ILogEntryProcessor? processor = existingProcessor; + CancellationTokenRegistration? registration = existingProcCancelRegistration; + // TODO: CancellationTokenRegistration.Token isn't available in .NET Standard 2.0. + //if (registration.HasValue && registration.Value.Token.IsCancellationRequested) + //{ + // processor = null; + // registration.Value.Dispose(); + //} + if (processor == null && loggerSink is ILogEntryProcessorFactory factory) { - LoggerRuleSelector.Select(_filterOptions, - loggerInformation.ProviderType, - loggerInformation.Category, - out LogLevel? minLevel, - out Func? filter); - - if (minLevel is not null and > LogLevel.Critical) + var processorContext = factory.GetProcessor(); + if (processorContext.CancellationToken.IsCancellationRequested) { - continue; + processor = null; } - - messageLoggers.Add(new MessageLogger(loggerInformation.Logger, loggerInformation.Category, loggerInformation.ProviderType.FullName, minLevel, filter)); - - if (!loggerInformation.ExternalScope) + else { - scopeLoggers?.Add(new ScopeLogger(logger: loggerInformation.Logger, externalScopeProvider: null)); + processor = processorContext.Processor; + registration = processorContext.CancellationToken.Register(logger.ProcessorInvalidated); } } - - if (_scopeProvider != null) - { - scopeLoggers?.Add(new ScopeLogger(logger: null, externalScopeProvider: _scopeProvider)); - } - - return (messageLoggers.ToArray(), scopeLoggers?.ToArray()); + return new LoggerInformation(provider, category, loggerSink, processor, registration, minLevel.Value, filter); } /// diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs index 1a0a01acdcb3b1..615ea73f2c82da 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs @@ -3,6 +3,7 @@ using System; using System.Diagnostics; +using System.Threading; namespace Microsoft.Extensions.Logging { @@ -71,20 +72,51 @@ public ScopeLogger(ILogger? logger, IExternalScopeProvider? externalScopeProvide internal readonly struct LoggerInformation { - public LoggerInformation(ILoggerProvider provider, string category) : this() + public LoggerInformation(ILoggerProvider provider, string category, ILogger logger, ILogEntryProcessor? processor, CancellationTokenRegistration? processorCancelRegistration, LogLevel minLevel, Func? filter) : this() { - ProviderType = provider.GetType(); - Logger = provider.CreateLogger(category); + Provider = provider; Category = category; + Logger = logger; + Processor = processor; + ProcessorCancelRegistration = processorCancelRegistration; ExternalScope = provider is ISupportExternalScope; + MinLevel = minLevel; + Filter = filter; + if (filter != null) + { + ProviderTypeFullName = provider.GetType().FullName; + } } - public ILogger Logger { get; } - + public ILoggerProvider Provider { get; } public string Category { get; } - public Type ProviderType { get; } + public ILogger Logger { get; } + + public ILogEntryProcessor? Processor { get; } + public CancellationTokenRegistration? ProcessorCancelRegistration { get; } public bool ExternalScope { get; } + + private LogLevel MinLevel { get; } + + private Func? Filter { get; } + + private string? ProviderTypeFullName { get; } + + public bool IsEnabled(LogLevel level) + { + if (level < MinLevel) + { + return false; + } + + if (Filter != null) + { + return Filter(ProviderTypeFullName, Category, level); + } + + return true; + } } } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggingBuilderExtensions.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggingBuilderExtensions.cs index ea3b7b0cb2b36f..85ea5c78e188aa 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggingBuilderExtensions.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggingBuilderExtensions.cs @@ -60,5 +60,17 @@ public static ILoggingBuilder Configure(this ILoggingBuilder builder, Action(this ILoggingBuilder builder, Func getProcessor) where T : ILogEntryProcessor + { + builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton>(sp => new ProcessorFactory(getProcessor))); + return builder; + } + + public static ILoggingBuilder AddProcessor(this ILoggingBuilder builder, Func getProcessor) where T : ILogEntryProcessor + { + builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton>(sp => new ProcessorFactory((next) => getProcessor(sp, next)))); + return builder; + } } } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/PipelineManager.cs b/src/libraries/Microsoft.Extensions.Logging/src/PipelineManager.cs new file mode 100644 index 00000000000000..355e4d5bdc9319 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/src/PipelineManager.cs @@ -0,0 +1,49 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; + +namespace Microsoft.Extensions.Logging +{ + internal sealed class PipelineManager + { + private readonly Dictionary _pipelines = new Dictionary(); + + public LogEntryPipeline? GetLoggingPipeline(ILogEntryProcessor processor, ILogMetadata? metadata, object? userState) + { + object? pipeline; + PipelineKey key = new PipelineKey(isLoggingPipeline: true, (metadata == null) ? typeof(TState) : metadata, processor, userState); + lock (_pipelines) + { + if (!_pipelines.TryGetValue(key, out pipeline)) + { + pipeline = BuildPipeline(processor, metadata, userState); + _pipelines[key] = pipeline; + } + } + return (LogEntryPipeline?)pipeline; + } + + private static LogEntryPipeline BuildPipeline(ILogEntryProcessor processor, ILogMetadata? metadata, object? userState) + { + LogEntryHandler handler = processor.GetLogEntryHandler(metadata, out bool enabled, out bool dynamicCheckRequired); + return new LogEntryPipeline(handler, userState, enabled, dynamicCheckRequired); + } + } + + internal readonly struct PipelineKey + { + public PipelineKey(bool isLoggingPipeline, object typeOrMetadata, ILogEntryProcessor? terminalProcessor, object? userState) + { + IsLoggingPipeline = isLoggingPipeline; + TypeOrMetadata = typeOrMetadata; + TerminalProcessor = terminalProcessor; + UserState = userState; + } + + public bool IsLoggingPipeline { get; } + public object TypeOrMetadata { get; } + public ILogEntryProcessor? TerminalProcessor { get; } + public object? UserState { get; } + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/EnrichmentTests.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/EnrichmentTests.cs new file mode 100644 index 00000000000000..f604218b0ed120 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/EnrichmentTests.cs @@ -0,0 +1,176 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Linq; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Testing; +using Xunit; + +namespace Microsoft.Extensions.Logging.Test +{ + public class EnrichmentTests + { + [Fact] + public void LogInformation_PropertyAddedToState() + { + // Arrange + var sink = new TestSink(); + var provider = new TestLoggerProvider(sink, isEnabled: true); + + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(builder => + { + builder.SetMinimumLevel(LogLevel.Trace); + builder.AddProvider(provider); + builder.Enrich("prop1", () => "Value!"); + }); + var loggerFactory = serviceCollection.BuildServiceProvider().GetRequiredService(); + var logger = loggerFactory.CreateLogger("Test"); + + // Act + logger.LogInformation("Hello {Name}", "John Doe"); + + // Assert + Assert.Equal(1, sink.Writes.Count()); + Assert.True(sink.Writes.TryTake(out var write)); + Assert.Equal(LogLevel.Information, write.LogLevel); + Assert.Equal("Hello John Doe", write.State.ToString()); + Assert.Equal(0, write.EventId); + Assert.Null(write.Exception); + + Assert.Collection((IReadOnlyList>)write.State, + p => + { + Assert.Equal("Name", p.Key); + Assert.Equal("John Doe", p.Value); + }, + p => + { + Assert.Equal("{OriginalFormat}", p.Key); + Assert.Equal("Hello {Name}", p.Value); + }, + p => + { + Assert.Equal("prop1", p.Key); + Assert.Equal("Value!", p.Value); + }); + } + + [Theory] + [InlineData(0)] + [InlineData(1)] + [InlineData(2)] + [InlineData(3)] + [InlineData(10)] + public void LogInformation_PropertyCount_PropertyAddedToState(int enrichPropertyCount) + { + // Arrange + var sink = new TestSink(); + var provider = new TestLoggerProvider(sink, isEnabled: true); + + var beforeMetadatas = new List(); + var afterMetadatas = new List(); + + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(builder => + { + builder.SetMinimumLevel(LogLevel.Trace); + builder.AddProvider(provider); + + for (var i = 0; i < enrichPropertyCount; i++) + { + var capturedIndex = i; + builder.Enrich($"prop{capturedIndex}", () => $"value{capturedIndex}"); + } + builder.AddProcessor((serviceProvider, processor) => new TestLogMetadataLogEntryProcessor(processor, m => afterMetadatas.Add(m))); + }); + var loggerFactory = serviceCollection.BuildServiceProvider().GetRequiredService(); + var logger = loggerFactory.CreateLogger("Test"); + + var definedLog = LoggerMessage.Define( + LogLevel.Information, + new EventId(1, "Test"), + "Hello {Name}. You are {Age} years old."); + + // Act + definedLog(logger, "John Doe", 10, null); + + // Assert + Assert.Equal(1, sink.Writes.Count()); + Assert.True(sink.Writes.TryTake(out var write)); + Assert.Equal(LogLevel.Information, write.LogLevel); + Assert.Equal("Hello John Doe. You are 10 years old.", write.State.ToString()); + Assert.Equal(1, write.EventId); + Assert.Null(write.Exception); + + var values = Assert.IsAssignableFrom>>(write.State); + AssertPropertyAtIndex(values, 0, "Name", "John Doe"); + AssertPropertyAtIndex(values, 1, "Age", 10); + AssertPropertyAtIndex(values, 2, "{OriginalFormat}", "Hello {Name}. You are {Age} years old."); + for (var i = 0; i < enrichPropertyCount; i++) + { + AssertPropertyAtIndex(values, i + 3, $"prop{i}", $"value{i}"); + } + + var after = Assert.Single(afterMetadatas); + Assert.Equal(enrichPropertyCount + 2, after.PropertyCount); + Assert.Equal(enrichPropertyCount + 2, after.PropertyInfos.Length); + + void AssertPropertyAtIndex(IReadOnlyList> values, int index, string key, object value) + { + var kvp = values[index]; + Assert.Equal(key, kvp.Key); + Assert.Equal(value, kvp.Value); + + kvp = values.ElementAt(index); + Assert.Equal(key, kvp.Key); + Assert.Equal(value, kvp.Value); + } + } + + internal class LogMetadataInfo + { + public int PropertyCount { get; set; } + public LogPropertyInfo[] PropertyInfos { get; set; } + } + + internal sealed class TestLogMetadataLogEntryProcessor : ILogEntryProcessor + { + private readonly ILogEntryProcessor _nextProcessor; + private readonly Action _handleLogEntryCallback; + + public TestLogMetadataLogEntryProcessor(ILogEntryProcessor nextProcessor, Action handleLogEntryCallback) + { + _nextProcessor = nextProcessor; + _handleLogEntryCallback = handleLogEntryCallback; + } + + public LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + var propertyInfos = new List(); + for (var i = 0; i < metadata.PropertyCount; i++) + { + propertyInfos.Add(metadata.GetPropertyInfo(i)); + } + _handleLogEntryCallback(new LogMetadataInfo + { + PropertyCount = metadata.PropertyCount, + PropertyInfos = propertyInfos.ToArray() + }); + + var nextHandler = _nextProcessor.GetLogEntryHandler(metadata, out enabled, out dynamicEnabledCheckRequired); + return new TestLogEntryHandler(nextHandler, null); + } + + public ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull + { + var nextHandler = _nextProcessor.GetScopeHandler(metadata, out enabled); + return new TestScopeHandler(nextHandler, null); + } + + public bool IsEnabled(LogLevel logLevel) => _nextProcessor.IsEnabled(logLevel); + } + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/LoggerFactoryTest.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/LoggerFactoryTest.cs index 7c2f39751b903c..64f652aea0c60b 100644 --- a/src/libraries/Microsoft.Extensions.Logging/tests/Common/LoggerFactoryTest.cs +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/LoggerFactoryTest.cs @@ -423,14 +423,15 @@ public void CallsSetScopeProvider_OnSupportedProviders() } logger.LogInformation("Message2"); - Assert.Equal(loggerProvider.LogText, + Assert.Equal( new[] { "Message", "Scope", "Scope2", "Message2", - }); + }, + loggerProvider.LogText); Assert.NotNull(loggerProvider.ScopeProvider); Assert.Equal(0, loggerProvider.BeginScopeCalledTimes); } @@ -475,23 +476,25 @@ public void BeginScope_ReturnsCompositeToken_ForMultipleLoggers() } logger.LogInformation("Message2"); - Assert.Equal(loggerProvider.LogText, + Assert.Equal( new[] { "Message", "Scope", "Scope2", "Message2", - }); + }, + loggerProvider.LogText); - Assert.Equal(loggerProvider2.LogText, + Assert.Equal( new[] { "Message", "Scope", "Scope2", "Message2", - }); + }, + loggerProvider.LogText); } // Moq heavily utilizes RefEmit, which does not work on most aot workloads diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/ProcessorTests.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/ProcessorTests.cs new file mode 100644 index 00000000000000..0143e0b640b01a --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/ProcessorTests.cs @@ -0,0 +1,87 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Linq; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Logging.Testing; +using Xunit; + +namespace Microsoft.Extensions.Logging.Test +{ + public class ProcessorTests + { + [Fact] + public void LogInformation_InvokesProcessor() + { + // Arrange + var sink = new TestSink(); + var provider = new TestLoggerProvider(sink, isEnabled: true); + + List logMessages = new List(); + + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(builder => + { + builder.SetMinimumLevel(LogLevel.Trace); + builder.AddProvider(provider); + builder.AddProcessor((serviceProvider, processor) => new TestLogEntryProcessor(processor, m => logMessages.Add(m))); + }); + var loggerFactory = serviceCollection.BuildServiceProvider().GetRequiredService(); + var logger = loggerFactory.CreateLogger("Test"); + + // Act + logger.LogInformation("Hello {Name}", "John Doe"); + + // Assert + Assert.Collection(logMessages, m => Assert.Equal("Hello John Doe", m)); + + Assert.Equal(1, sink.Writes.Count()); + Assert.True(sink.Writes.TryTake(out var write)); + Assert.Equal(LogLevel.Information, write.LogLevel); + Assert.Equal("Hello John Doe", write.State.ToString()); + Assert.Equal(0, write.EventId); + Assert.Null(write.Exception); + } + + [Fact] + public void DefinedLog_InvokesProcessor() + { + // Arrange + var sink = new TestSink(); + var provider = new TestLoggerProvider(sink, isEnabled: true); + + List logMessages = new List(); + + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(builder => + { + builder.SetMinimumLevel(LogLevel.Trace); + builder.AddProvider(provider); + builder.AddProcessor((serviceProvider, processor) => new TestLogEntryProcessor(processor, m => logMessages.Add(m))); + }); + var loggerFactory = serviceCollection.BuildServiceProvider().GetRequiredService(); + var logger = loggerFactory.CreateLogger("Test"); + + var definedLog = LoggerMessage.Define( + LogLevel.Information, + new EventId(1, "Test"), + "Hello {Name}. You are {Age} years old."); + + // Act + definedLog(logger, "John Doe", 10, null); + + // Assert + Assert.Collection(logMessages, m => Assert.Equal("Hello John Doe. You are 10 years old.", m)); + + Assert.Equal(1, sink.Writes.Count()); + Assert.True(sink.Writes.TryTake(out var write)); + Assert.Equal(LogLevel.Information, write.LogLevel); + Assert.Equal("Hello John Doe. You are 10 years old.", write.State.ToString()); + Assert.Equal(1, write.EventId); + Assert.Null(write.Exception); + } + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/Redaction/RedactionProcessor.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/Redaction/RedactionProcessor.cs new file mode 100644 index 00000000000000..4ec37d914cc2b6 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/Redaction/RedactionProcessor.cs @@ -0,0 +1,560 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +// Prototype redaction processor uses APIs not available on .NET Framework. +// The prototype redaction could probably be updated to support .NET Framework if required. + +#if NET8_0_OR_GREATER + +using System; +using System.Buffers; +using System.Collections; +using System.Collections.Generic; +using System.Linq; +using System.Threading; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Logging.Tests.Redaction +{ + public static class RedactionExtensions + { + public static ILoggingBuilder AddRedactionProcessor(this ILoggingBuilder builder) + { + builder.AddProcessor((serviceProvider, processor) => new RedactionProcessor(processor, serviceProvider.GetService())); + return builder; + } + } + + internal interface IRedactorProvider + { + IRedactor GetRedactor(DataClass dataClass); + } + + internal interface IRedactor + { + string Redact(ReadOnlySpan source); + int Redact(ReadOnlySpan source, Span destination); + int GetRedactedLength(ReadOnlySpan source); + } + + internal enum DataClass + { + Unknown, + EUPI + } + + [AttributeUsage(AttributeTargets.Class | AttributeTargets.Struct | AttributeTargets.Property | AttributeTargets.Field | AttributeTargets.Interface | AttributeTargets.Parameter | AttributeTargets.ReturnValue, AllowMultiple = true)] + internal abstract class DataClassificationAttribute : Attribute + { + public string Notes { get; set; } = string.Empty; + public DataClass DataClass { get; } + + protected DataClassificationAttribute(DataClass dataClass) + { + DataClass = dataClass; + } + } + + internal class RedactionProcessor : ILogEntryProcessor + { + private readonly ILogEntryProcessor _nextProcessor; + private readonly IRedactorProvider? _redactorProvider; + + public RedactionProcessor(ILogEntryProcessor nextProcessor, IRedactorProvider? provider) + { + _nextProcessor = nextProcessor; + _redactorProvider = provider; + } + + public LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicCheckRequired) + { + if (metadata != null && _redactorProvider != null) + { + PropertyRedaction[] redactions = GetPolicyRedactions(metadata); + if (redactions.Length > 0) + { + RedactedLogMetadata redactedMetadata = new RedactedLogMetadata(metadata, redactions); + return new RedactionHandler(redactedMetadata, + _nextProcessor.GetLogEntryHandler>(redactedMetadata, out enabled, out dynamicCheckRequired)); + } + } + return _nextProcessor.GetLogEntryHandler(metadata, out enabled, out dynamicCheckRequired); + } + + PropertyRedaction[] GetPolicyRedactions(ILogMetadata metadata) + { + List redactions = new List(); + for (int i = 0; i < metadata.PropertyCount; i++) + { + LogPropertyInfo propMetadata = metadata.GetPropertyInfo(i); + if (propMetadata.Metadata == null) + { + continue; + } + DataClassificationAttribute? dataClassAttr = propMetadata.Metadata.OfType().FirstOrDefault(); + if (dataClassAttr != null) + { + redactions.Add(new PropertyRedaction(i, _redactorProvider!.GetRedactor(dataClassAttr.DataClass))); + } + } + return redactions.ToArray(); + } + + public ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull + { + return _nextProcessor.GetScopeHandler(metadata, out enabled); + } + + public bool IsEnabled(LogLevel level) => _nextProcessor.IsEnabled(level); + + class RedactionHandler : LogEntryHandler + { + LogEntryHandler> _nextHandler; + RedactedLogMetadata _metadata; + + public RedactionHandler(RedactedLogMetadata metadata, LogEntryHandler> nextHandler) + { + _metadata = metadata; + _nextHandler = nextHandler; + } + public override void HandleLogEntry(ref LogEntry logEntry) + { + RedactedValues redactedValuesState = new RedactedValues(_metadata, logEntry.State); + LogEntry> copy = new LogEntry>(logEntry.LogLevel, category: null!, logEntry.EventId, redactedValuesState, logEntry.Exception, RedactedValues.Callback); + _nextHandler.HandleLogEntry(ref copy); + } + + public override bool IsEnabled(LogLevel level) + { + return _nextHandler.IsEnabled(level); + } + } + } + + internal struct PropertyRedaction + { + public PropertyRedaction(int index, IRedactor redactor) + { + Index = index; + Redactor = redactor; + } + public int Index; + public IRedactor Redactor; + } + + + internal class RedactedPropertyFormatter : PropertyCustomFormatter + { + const int MaxStackAllocChars = 256; + IRedactor _redactor; + + public RedactedPropertyFormatter(IRedactor redactor) + { + _redactor = redactor; + } + + public override void AppendFormatted(int index, string value, IBufferWriter buffer) + { + int len = _redactor.GetRedactedLength(value); + if (len != 0) + { + Span redactedBuffer = buffer.GetSpan(len); + _redactor.Redact(value, redactedBuffer); + buffer.Advance(len); + } + } + + public override void AppendFormatted(int index, T value, IBufferWriter buffer) + { + if (value == null) + { + return; + } + if (value is ISpanFormattable) + { + Span unredactedBuffer = stackalloc char[MaxStackAllocChars]; + if (((ISpanFormattable)value).TryFormat(unredactedBuffer, out int charsWritten2, null, null)) + { + unredactedBuffer = unredactedBuffer.Slice(0, charsWritten2); + int len2 = _redactor.GetRedactedLength(unredactedBuffer); + if (len2 != 0) + { + Span redactedBuffer2 = buffer.GetSpan(len2); + _redactor.Redact(unredactedBuffer, redactedBuffer2); + buffer.Advance(len2); + } + return; + } + } + string? unredactedValue = value.ToString(); + int len = _redactor.GetRedactedLength(unredactedValue); + if (len != 0) + { + Span redactedBuffer = buffer.GetSpan(len); + _redactor.Redact(unredactedValue, redactedBuffer); + buffer.Advance(len); + } + } + } + + internal class ChainedRedactedPropertyFormatter : PropertyCustomFormatter + { + const int MaxStackAllocChars = 256; + IRedactor _redactor; + PropertyCustomFormatter _nextFormatter; + + public ChainedRedactedPropertyFormatter(IRedactor redactor, PropertyCustomFormatter nextFormatter) + { + _redactor = redactor; + _nextFormatter = nextFormatter; + } + + public override void AppendFormatted(int index, string value, IBufferWriter buffer) + { + int len = _redactor.GetRedactedLength(value); + if (len <= MaxStackAllocChars) + { + Span redactedBuffer = stackalloc char[len]; + _redactor.Redact(value, redactedBuffer); + _nextFormatter.AppendFormatted(index, redactedBuffer, buffer); + } + else + { + string redactedValue = _redactor.Redact(value); + _nextFormatter.AppendFormatted(index, redactedValue, buffer); + } + } + + public override void AppendFormatted(int index, T value, IBufferWriter buffer) + { + if (value == null) + { + return; + } + else if (value is ISpanFormattable) + { + Span unredactedBuffer = stackalloc char[MaxStackAllocChars]; + if (((ISpanFormattable)value).TryFormat(unredactedBuffer, out int charsWritten2, null, null)) + { + unredactedBuffer = unredactedBuffer.Slice(0, charsWritten2); + int len2 = _redactor.GetRedactedLength(unredactedBuffer); + if (len2 <= MaxStackAllocChars) + { + Span redactedBuffer2 = stackalloc char[len2]; + _redactor.Redact(unredactedBuffer, redactedBuffer2); + _nextFormatter.AppendFormatted(index, redactedBuffer2, buffer); + } + else + { + string redactedValue = _redactor.Redact(unredactedBuffer); + _nextFormatter.AppendFormatted(index, redactedValue, buffer); + } + return; + } + } + string? unredactedValue = value.ToString(); + int len = _redactor.GetRedactedLength(unredactedValue); + if (len <= MaxStackAllocChars) + { + Span redactedBuffer = stackalloc char[len]; + _redactor.Redact(unredactedValue, redactedBuffer); + _nextFormatter.AppendFormatted(index, redactedBuffer, buffer); + } + else + { + string redactedValue = _redactor.Redact(unredactedValue); + _nextFormatter.AppendFormatted(index, redactedValue, buffer); + } + } + } + + internal class RedactedLogMetadata : ILogMetadata> + { + private readonly ILogMetadata _originalMetadata; + private readonly PropertyRedaction[] _redactions; + private Action>? _defaultFormatter; + + public RedactedLogMetadata(ILogMetadata metadata, PropertyRedaction[] redactions) + { + _originalMetadata = metadata; + _redactions = redactions; + } + + public IRedactor? GetPropertyRedactor(int index) + { + for (var i = 0; i < _redactions.Length; i++) + { + if (_redactions[i].Index == index) + { + return _redactions[i].Redactor; + } + } + return null; + } + + public ILogMetadata OriginalMetadata => _originalMetadata; + + public LogLevel LogLevel => _originalMetadata.LogLevel; + + public EventId EventId => _originalMetadata.EventId; + + public string OriginalFormat => _originalMetadata.OriginalFormat; + + public int PropertyCount => _originalMetadata.PropertyCount; + + public void AppendFormattedMessage(in RedactedValues state, IBufferWriter buffer) + { + if (_defaultFormatter == null) + { + RedactedPropertyFormatter[] propertyRedactors = new RedactedPropertyFormatter[PropertyCount]; + foreach (PropertyRedaction redaction in _redactions) + { + propertyRedactors[redaction.Index] = new RedactedPropertyFormatter(redaction.Redactor); + } + // this could be overwritten by another thread in a race but it doesn't matter + // as any copy of this delegate will have the same functionality + _defaultFormatter = _originalMetadata.GetMessageFormatter(propertyRedactors); + } + _defaultFormatter(state.OriginalState, buffer); + } + + public Action, IBufferWriter> GetMessageFormatter(PropertyCustomFormatter[] customFormatters) + { + PropertyCustomFormatter[] wrappedFormatters = new PropertyCustomFormatter[customFormatters.Length]; + Array.Copy(customFormatters, wrappedFormatters, customFormatters.Length); + foreach (PropertyRedaction redaction in _redactions) + { + PropertyCustomFormatter nextFormatter = wrappedFormatters[redaction.Index]; + wrappedFormatters[redaction.Index] = nextFormatter == null ? + new RedactedPropertyFormatter(redaction.Redactor) : + new ChainedRedactedPropertyFormatter(redaction.Redactor, nextFormatter); + } + Action> innerFormatter = _originalMetadata.GetMessageFormatter(wrappedFormatters); + return (state, buffer) => innerFormatter(state.OriginalState, buffer); + } + + public LogPropertyInfo GetPropertyInfo(int index) => _originalMetadata.GetPropertyInfo(index); + + class Slot { public ArrayBufferWriter? Buffer; } + static ThreadLocal t_slot = new ThreadLocal(); + + public string FormatMessage(in RedactedValues state) + { + Slot? tstate = t_slot.Value; + if (tstate == null) + { + tstate = new Slot(); + t_slot.Value = tstate; + } + ArrayBufferWriter arrayBuffer = tstate.Buffer ?? new ArrayBufferWriter(); + tstate.Buffer = null; + AppendFormattedMessage(state, arrayBuffer); + string ret = new string(arrayBuffer.WrittenSpan); + arrayBuffer.Clear(); + tstate.Buffer = arrayBuffer; + return ret; + } + + public Func, Exception?, string> GetStringMessageFormatter() => RedactedValues.Callback; + + class RedactedPropertyFormatterFactory : IPropertyFormatterFactory + { + const int MaxStackAllocChars = 256; + RedactedLogMetadata _metadata; + IPropertyFormatterFactory _wrappedFormatterFactory; + + public RedactedPropertyFormatterFactory(RedactedLogMetadata metadata, IPropertyFormatterFactory wrappedFormatterFactory) + { + _metadata = metadata; + _wrappedFormatterFactory = wrappedFormatterFactory; + } + + public FormatPropertyAction GetPropertyFormatter(int propertyIndex, LogPropertyInfo metadata) + { + PropertyRedaction? redaction = _metadata.GetRedactionForIndex(propertyIndex); + if (!redaction.HasValue) + { + return _wrappedFormatterFactory.GetPropertyFormatter(propertyIndex, _metadata.GetPropertyInfo(propertyIndex)); + } + else + { + return GetRedactedPropertyFormatter(propertyIndex, metadata, redaction.Value.Redactor); + } + } + + public FormatSpanPropertyAction GetSpanPropertyFormatter(int propertyIndex, LogPropertyInfo metadata) + { + PropertyRedaction? redaction = _metadata.GetRedactionForIndex(propertyIndex); + if (!redaction.HasValue) + { + return _wrappedFormatterFactory.GetSpanPropertyFormatter(propertyIndex, _metadata.GetPropertyInfo(propertyIndex)); + } + else + { + return GetRedactedSpanPropertyFormatter(propertyIndex, metadata, redaction.Value.Redactor); + } + } + + private FormatSpanPropertyAction GetRedactedSpanPropertyFormatter(int propertyIndex, LogPropertyInfo metadata, IRedactor redactor) + { + FormatSpanPropertyAction wrappedFormatter = _wrappedFormatterFactory.GetSpanPropertyFormatter(propertyIndex, _metadata.GetPropertyInfo(propertyIndex)); + return FormatRedactedProperty; + + void FormatRedactedProperty(scoped ReadOnlySpan value, ref BufferWriter writer) + { + int len = redactor.GetRedactedLength(value); + if (len <= MaxStackAllocChars) + { + Span redactedBuffer = stackalloc char[len]; + redactor.Redact(value, redactedBuffer); + wrappedFormatter(redactedBuffer, ref writer); + } + else + { + string redactedValue = redactor.Redact(value); + wrappedFormatter(redactedValue, ref writer); + } + } + } + + private FormatPropertyAction GetRedactedPropertyFormatter(int propertyIndex, LogPropertyInfo metadata, IRedactor redactor) + { + FormatSpanPropertyAction wrappedFormatter = _wrappedFormatterFactory.GetSpanPropertyFormatter(propertyIndex, _metadata.GetPropertyInfo(propertyIndex)); + return FormatRedactedProperty; + + void FormatRedactedProperty(PropType value, ref BufferWriter writer) + { + if (value == null) + { + return; + } + else if (value is ISpanFormattable) + { + Span unredactedBuffer = stackalloc char[MaxStackAllocChars]; + if (((ISpanFormattable)value).TryFormat(unredactedBuffer, out int charsWritten2, null, null)) + { + unredactedBuffer = unredactedBuffer.Slice(0, charsWritten2); + int len2 = redactor!.GetRedactedLength(unredactedBuffer); + if (len2 <= MaxStackAllocChars) + { + Span redactedBuffer2 = stackalloc char[len2]; + redactor!.Redact(unredactedBuffer, redactedBuffer2); + wrappedFormatter(redactedBuffer2, ref writer); + } + else + { + string redactedValue = redactor.Redact(unredactedBuffer); + wrappedFormatter(redactedValue, ref writer); + } + return; + } + } + string? unredactedValue = value.ToString(); + int len = redactor.GetRedactedLength(unredactedValue); + if (len <= MaxStackAllocChars) + { + Span redactedBuffer = stackalloc char[len]; + redactor.Redact(unredactedValue, redactedBuffer); + wrappedFormatter(redactedBuffer, ref writer); + } + else + { + string redactedValue = redactor.Redact(unredactedValue); + wrappedFormatter(redactedValue, ref writer); + } + } + } + } + + public FormatPropertyListAction> GetPropertyListFormatter(IPropertyFormatterFactory propertyFormatterFactory) + { + FormatPropertyListAction wrappedFormatPropertyList = _originalMetadata.GetPropertyListFormatter(new RedactedPropertyFormatterFactory(this, propertyFormatterFactory)); + return FormatPropertyList; + + void FormatPropertyList(in RedactedValues state, ref BufferWriter writer) + { + wrappedFormatPropertyList(in state.OriginalState, ref writer); + } + } + + private PropertyRedaction? GetRedactionForIndex(int propIndex) + { + foreach (PropertyRedaction redaction in _redactions) + { + if (redaction.Index == propIndex) + { + return redaction; + } + } + return null; + } + } + + internal readonly struct RedactedValues : IReadOnlyList> + { + public RedactedValues(RedactedLogMetadata metadata, in T originalState) + { + Metadata = metadata; + OriginalState = originalState; + } + + public readonly RedactedLogMetadata Metadata; + public readonly T OriginalState; + + public override string ToString() => Metadata.FormatMessage(this); + + public IEnumerator> GetEnumerator() + { + var nested = OriginalState as IReadOnlyList>; + if (nested == null) + { + yield break; + } + for (var i = 0; i < nested.Count; i++) + { + yield return GetRedactedValue(i, nested[i]); + } + } + + IEnumerator IEnumerable.GetEnumerator() => GetEnumerator(); + + public int Count + { + get + { + var nested = OriginalState as IReadOnlyList>; + return nested?.Count ?? 0; + } + } + + public KeyValuePair this[int index] + { + get + { + var nested = OriginalState as IReadOnlyList>; + if (nested == null) + { + throw new IndexOutOfRangeException(nameof(index)); + } + var originalValue = nested[index]; + return GetRedactedValue(index, originalValue); + } + } + + private readonly KeyValuePair GetRedactedValue(int index, KeyValuePair originalValue) + { + var redactor = Metadata.GetPropertyRedactor(index); + if (redactor == null) + { + return originalValue; + } + string? unredactedValue = originalValue.Value?.ToString(); + return new KeyValuePair(originalValue.Key, redactor.Redact(unredactedValue)); + } + + public static readonly Func, Exception?, string> Callback = (state, e) => state.ToString(); + } +} + +#endif diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/Redaction/RedactionTests.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/Redaction/RedactionTests.cs new file mode 100644 index 00000000000000..6700cdf4cb1049 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/Redaction/RedactionTests.cs @@ -0,0 +1,140 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +#if NET8_0_OR_GREATER + +using System; +using System.Collections.Generic; +using System.Linq; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging.Test; +using Microsoft.Extensions.Logging.Testing; +using Xunit; + +namespace Microsoft.Extensions.Logging.Tests.Redaction +{ + public class RedactionTests + { + [Fact] + public void Redact_Message() + { + var sink = new TestSink(); + var provider = new TestLoggerProvider(sink, isEnabled: true); + ILoggerFactory factory = LoggerFactory.Create(b => + { + b.AddProvider(provider); + b.Services.AddSingleton(); + b.AddRedactionProcessor(); + }); + + ILogger foo = factory.CreateLogger("Foo"); + LogMessages.LogName(foo, "Frank", 76); + LogMessages.LogNameRedacted(foo, "Frank", 76); + + Assert.Equal(2, sink.Writes.Count); + Assert.Equal("User Frank has now 76 status", sink.Writes.ElementAt(0).Message); + Assert.Equal("User [Redacted - EUPI] has now 76 status", sink.Writes.ElementAt(1).Message); + } + + [Fact] + public void Redact_StateValues() + { + var sink = new TestSink(); + var provider = new TestLoggerProvider(sink, isEnabled: true); + ILoggerFactory factory = LoggerFactory.Create(b => + { + b.AddProvider(provider); + b.Services.AddSingleton(); + b.AddRedactionProcessor(); + }); + + ILogger foo = factory.CreateLogger("Foo"); + LogMessages.LogNameRedacted(foo, "Frank", 76); + + Assert.Equal(1, sink.Writes.Count); + var write = sink.Writes.ElementAt(0); + Assert.Equal("User [Redacted - EUPI] has now 76 status", write.Message); + + var values = Assert.IsAssignableFrom>>(write.State); + Assert.Collection(values, + kvp => + { + Assert.Equal("username", kvp.Key); + Assert.Equal("[Redacted - EUPI]", kvp.Value); + }, + kvp => + { + Assert.Equal("status", kvp.Key); + Assert.Equal(76, kvp.Value); + }, + kvp => + { + Assert.Equal("{OriginalFormat}", kvp.Key); + Assert.Equal("User {username} has now {status} status", kvp.Value); + }); + } + + private sealed class TestRedactorProvider : IRedactorProvider + { + public IRedactor GetRedactor(DataClass dataClass) => new TestRedactor(dataClass); + } + + private sealed class TestRedactor : IRedactor + { + private readonly string _redactedText; + + public TestRedactor(DataClass dataClass) + { + _redactedText = $"[Redacted - {dataClass}]"; + } + + public int GetRedactedLength(ReadOnlySpan source) => _redactedText.Length; + public string Redact(ReadOnlySpan source) => _redactedText; + public int Redact(ReadOnlySpan source, Span destination) + { + _redactedText.AsSpan().CopyTo(destination); + return _redactedText.Length; + } + } + } + + internal class EUPIAttribute : DataClassificationAttribute + { + public EUPIAttribute() : base(DataClass.EUPI) + { + } + } + + public static partial class LogMessages + { + //[LoggerMessage(1, LogLevel.Information, "User {username} has now {status} status")] + public static void LogName(this ILogger logger, string username, int status) + { + // manually writing the code the source generator is proposed to create + __LogNameCallback(logger, username, status, null); + } + + private static readonly Action __LogNameCallback = + LoggerMessage.Define( + LogLevel.Information, + new EventId(1, nameof(LogName)), + "User {username} has now {status} status"); + + + //[LoggerMessage(2, LogLevel.Information, "User {username} has now {status} status")] + public static void LogNameRedacted(this ILogger logger, [EUPI] string username, int status) + { + // manually writing the code the source generator is proposed to create + __LogNameRedactedCallback(logger, username, status, null); + } + + private static readonly Action __LogNameRedactedCallback = + LoggerMessage.Define( + LogLevel.Information, + new EventId(1, nameof(LogNameRedacted)), + "User {username} has now {status} status", + new LogDefineOptions() { ParameterMetadata = new Attribute[]?[] { new Attribute[] { new EUPIAttribute() }, null } }); + } +} + +#endif diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestLogEntryHandler.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestLogEntryHandler.cs new file mode 100644 index 00000000000000..050bd7c1269dbf --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestLogEntryHandler.cs @@ -0,0 +1,33 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Logging.Test +{ + internal sealed class TestLogEntryHandler : LogEntryHandler + { + private readonly LogEntryHandler _nextHandler; + private readonly Action? _handleLogEntryCallback; + + public TestLogEntryHandler(LogEntryHandler nextHandler, Action? handleLogEntryCallback) + { + _nextHandler = nextHandler; + _handleLogEntryCallback = handleLogEntryCallback; + } + + public override void HandleLogEntry(ref LogEntry logEntry) + { + var message = logEntry.Formatter(logEntry.State, logEntry.Exception); + _handleLogEntryCallback?.Invoke(message); + + _nextHandler.HandleLogEntry(ref logEntry); + } + + public override bool IsEnabled(LogLevel level) + { + return _nextHandler.IsEnabled(level); + } + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestLogEntryProcessor.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestLogEntryProcessor.cs new file mode 100644 index 00000000000000..a104b650123129 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestLogEntryProcessor.cs @@ -0,0 +1,33 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Extensions.Logging.Test +{ + internal sealed class TestLogEntryProcessor : ILogEntryProcessor + { + private readonly ILogEntryProcessor _nextProcessor; + private readonly Action _handleLogEntryCallback; + + public TestLogEntryProcessor(ILogEntryProcessor nextProcessor, Action handleLogEntryCallback) + { + _nextProcessor = nextProcessor; + _handleLogEntryCallback = handleLogEntryCallback; + } + + public LogEntryHandler GetLogEntryHandler(ILogMetadata? metadata, out bool enabled, out bool dynamicEnabledCheckRequired) + { + var nextHandler = _nextProcessor.GetLogEntryHandler(metadata, out enabled, out dynamicEnabledCheckRequired); + return new TestLogEntryHandler(nextHandler, _handleLogEntryCallback); + } + + public ScopeHandler GetScopeHandler(ILogMetadata? metadata, out bool enabled) where TState : notnull + { + var nextHandler = _nextProcessor.GetScopeHandler(metadata, out enabled); + return new TestScopeHandler(nextHandler, _handleLogEntryCallback); + } + + public bool IsEnabled(LogLevel logLevel) => _nextProcessor.IsEnabled(logLevel); + } +} diff --git a/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestScopeHandler.cs b/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestScopeHandler.cs new file mode 100644 index 00000000000000..8e4cc5fcd79574 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Logging/tests/Common/TestScopeHandler.cs @@ -0,0 +1,31 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Extensions.Logging.Test +{ + internal sealed class TestScopeHandler : ScopeHandler + { + private readonly ScopeHandler _nextHandler; + private readonly Action _handleLogEntryCallback; + + public TestScopeHandler(ScopeHandler nextHandler, Action handleLogEntryCallback) + { + _nextHandler = nextHandler; + _handleLogEntryCallback = handleLogEntryCallback; + } + + public override IDisposable? HandleBeginScope(ref TState state) + { + _handleLogEntryCallback(state.ToString()); + + return _nextHandler.HandleBeginScope(ref state); + } + + public override bool IsEnabled(LogLevel level) + { + return _nextHandler.IsEnabled(level); + } + } +}