From 94199e9d702bdb3439ffc10983c104403eae207b Mon Sep 17 00:00:00 2001 From: neuecc Date: Wed, 18 Oct 2023 20:38:57 +0900 Subject: [PATCH] improve ZLoggerInterpolatedStringHandler(use MagicalBox and etc) --- .../MessagePackZLoggerFormatter.cs | 2 +- src/ZLogger/Internal/MagicalBox.cs | 130 ++++++++ .../LogStates/InterpolatedStringLogState.cs | 106 ++++--- .../LogStates/StringFormatterLogState.cs | 2 - src/ZLogger/ZLogger.csproj | 22 +- src/ZLogger/ZLoggerEntry.cs | 5 + src/ZLogger/ZLoggerExtensions.cs | 2 +- .../ZLoggerInterpolatedStringHandler.cs | 287 ++++++++++++++++-- 8 files changed, 479 insertions(+), 77 deletions(-) create mode 100644 src/ZLogger/Internal/MagicalBox.cs diff --git a/src/ZLogger.MessagePack/MessagePackZLoggerFormatter.cs b/src/ZLogger.MessagePack/MessagePackZLoggerFormatter.cs index b4b095b0..57d6b7b1 100644 --- a/src/ZLogger.MessagePack/MessagePackZLoggerFormatter.cs +++ b/src/ZLogger.MessagePack/MessagePackZLoggerFormatter.cs @@ -311,7 +311,7 @@ public void FormatLogEntry(IBufferWriter writer, TEntry entry) whe var value = entry.GetParameterValue(i); MessagePackSerializer.Serialize(valueType, ref messagePackWriter, value, MessagePackSerializerOptions); } - else + else // TODO: GUID? { var boxedValue = entry.GetParameterValue(i); MessagePackSerializer.Serialize(valueType, ref messagePackWriter, boxedValue, MessagePackSerializerOptions); diff --git a/src/ZLogger/Internal/MagicalBox.cs b/src/ZLogger/Internal/MagicalBox.cs new file mode 100644 index 00000000..961dfa09 --- /dev/null +++ b/src/ZLogger/Internal/MagicalBox.cs @@ -0,0 +1,130 @@ +using System; +using System.Buffers; +using System.Runtime.CompilerServices; +using System.Runtime.InteropServices; +using System.Text.Json; +using Utf8StringInterpolation; + +namespace ZLogger.Internal; + +internal unsafe struct MagicalBox +{ + byte[] storage; + int written; + + public MagicalBox(byte[] storage) + { + this.storage = storage; + } + + public int Written => written; + + public ReadOnlySpan AsSpan() => storage.AsSpan(0, written); + + public bool TryWrite(T value, out int offset) + { + if (RuntimeHelpers.IsReferenceOrContainsReferences()) + { + offset = 0; + return false; + } + + var size = Unsafe.SizeOf(); + if (storage.Length < written + size) + { + offset = 0; + return false; + } + + Unsafe.WriteUnaligned(ref storage[written], value); + offset = written; + written += Unsafe.SizeOf(); + return true; + } + + public bool TryRead(int offset, out T value) + { + if (RuntimeHelpers.IsReferenceOrContainsReferences() + || offset < 0 + || (storage.Length < offset + Unsafe.SizeOf())) + { + value = default!; + return false; + } + + value = Unsafe.ReadUnaligned(ref storage[offset]); + return true; + } + + public T Read(int offset) + { + if (!TryRead(offset, out var value)) + { + ThrowArgumentOutOfRangeException(); + } + return value; + } + + public object? Read(Type type, int offset) + { + // TODO: return boxed. + throw new NotImplementedException(); + } + + public bool TryReadTo(Type type, int offset, int alignment, string? format, ref Utf8StringWriter> handler) + { + if (offset < 0) return false; + // if (storage.Length < offset + Unsafe.SizeOf()) + + + //if (RuntimeHelpers.IsReferenceOrContainsReferences()) + //{ + // return false; + //} + + // TODO: many types...? + if (type == typeof(int)) + { + handler.AppendFormatted(Read(offset), alignment, format); + } + + return true; + } + + public bool TryReadTo(Type type, int offset, int alignment, string? format, ref DefaultInterpolatedStringHandler handler) + { + if (offset < 0) return false; + + //if (RuntimeHelpers.IsReferenceOrContainsReferences()) + //{ + // return false; + //} + + if (type == typeof(int)) + { + handler.AppendFormatted(Read(offset), alignment, format); + } + return true; + } + + public bool TryReadTo(Type type, int offset, string propertyName, Utf8JsonWriter jsonWriter) + { + if (offset < 0) return false; + + + + + if (type == typeof(int)) + { + //jsonWriter.WriteNumberValue( + + //handler.AppendFormatted(Read(offset), alignment, format); + } + return true; + } + + static void ThrowArgumentOutOfRangeException() + { + throw new ArgumentOutOfRangeException(); + } +} diff --git a/src/ZLogger/LogStates/InterpolatedStringLogState.cs b/src/ZLogger/LogStates/InterpolatedStringLogState.cs index 220b271a..ba14cc9e 100644 --- a/src/ZLogger/LogStates/InterpolatedStringLogState.cs +++ b/src/ZLogger/LogStates/InterpolatedStringLogState.cs @@ -1,81 +1,87 @@ using System; using System.Buffers; -using System.Collections; -using System.Collections.Generic; -using System.Text; using System.Text.Json; using ZLogger.Internal; namespace ZLogger.LogStates { - public readonly struct InterpolatedStringLogState : IZLoggerFormattable, IDisposable + internal struct InterpolatedStringLogState : IZLoggerFormattable, IDisposable { - public IZLoggerEntry CreateEntry(LogInfo info) - { - // If state has cached value, require clone. - var newParameters = ArrayPool>.Shared.Rent(this.ParameterCount); - for (var i = 0; i < this.ParameterCount; i++) - { - newParameters[i] = this.parameters[i]; - } + public int ParameterCount { get; } - var newBuffer = ArrayBufferWriterPool.Rent(); - this.buffer.WrittenSpan.CopyTo(newBuffer.GetSpan(this.buffer.WrittenCount)); - newBuffer.Advance(this.buffer.WrittenCount); + public bool IsSupportUtf8ParameterKey => false; - var newState = new InterpolatedStringLogState(newParameters, this.ParameterCount, newBuffer); + // pooling values. + byte[] magicalBoxStorage; + InterpolatedStringParameter[] parameters; - // Create Entry with cloned state - return ZLoggerEntry.Create(info, newState); - } + readonly MessageSequence messageSequence; + readonly MagicalBox magicalBox; - public int ParameterCount { get; } + public InterpolatedStringLogState(MessageSequence messageSequence, MagicalBox magicalBox, ReadOnlySpan parameters) + { + // need clone. + this.magicalBoxStorage = ArrayPool.Shared.Rent(magicalBox.Written); + magicalBox.AsSpan().CopyTo(magicalBoxStorage); - public bool IsSupportUtf8ParameterKey => false; + this.parameters = ArrayPool.Shared.Rent(parameters.Length); + parameters.CopyTo(this.parameters); - readonly KeyValuePair[] parameters; // pooled - readonly ArrayBufferWriter buffer; // pooled + this.messageSequence = messageSequence; + this.magicalBox = new MagicalBox(magicalBoxStorage); + } - public InterpolatedStringLogState(KeyValuePair[] parameters, int parameterCount, ArrayBufferWriter buffer) + public IZLoggerEntry CreateEntry(LogInfo info) { - this.parameters = parameters; - this.buffer = buffer; - ParameterCount = parameterCount; + // state needs clone. + var newState = new InterpolatedStringLogState(messageSequence, this.magicalBox, this.parameters); + + // Create Entry with cloned state(state will dispose when entry was disposed) + return ZLoggerEntry.Create(info, newState); } public void Dispose() { - ArrayPool>.Shared.Return(parameters); - ArrayBufferWriterPool.Return(buffer); + if (magicalBoxStorage != null) + { + ArrayPool.Shared.Return(magicalBoxStorage); + ArrayPool.Shared.Return(parameters); + + magicalBoxStorage = null!; + parameters = null!; + } } public override string ToString() { - return Encoding.UTF8.GetString(buffer.WrittenSpan); + return messageSequence.ToString(magicalBox, parameters); } public void ToString(IBufferWriter writer) { - var written = buffer.WrittenSpan; - var dest = writer.GetSpan(written.Length); - written.CopyTo(dest); - writer.Advance(written.Length); + messageSequence.ToString(writer, magicalBox, parameters); } public void WriteJsonParameterKeyValues(Utf8JsonWriter jsonWriter, JsonSerializerOptions jsonSerializerOptions) { for (var i = 0; i < ParameterCount; i++) { - var (key, value) = parameters[i]; - jsonWriter.WritePropertyName(key); - if (value == null) + ref var p = ref parameters[i]; + if (magicalBox.TryReadTo(p.Type, p.BoxOffset, p.Name, jsonWriter)) { - jsonWriter.WriteNullValue(); + continue; + } + + jsonWriter.WritePropertyName(p.Name); + + var value = magicalBox.Read(p.Type, p.BoxOffset); + if (value != null) + { + JsonSerializer.Serialize(jsonWriter, value, p.Type, jsonSerializerOptions); } else { - var valueType = GetParameterType(i); - JsonSerializer.Serialize(jsonWriter, value, valueType, jsonSerializerOptions); // TODO: more optimize ? + JsonSerializer.Serialize(jsonWriter, p.BoxedValue, p.Type, jsonSerializerOptions); } } } @@ -87,22 +93,34 @@ public ReadOnlySpan GetParameterKey(int index) public string GetParameterKeyAsString(int index) { - return parameters[index].Key; + return parameters[index].Name; } public object? GetParameterValue(int index) { - return parameters[index].Value; + ref var p = ref parameters[index]; + var value = magicalBox.Read(p.Type, p.BoxOffset); + if (value != null) return value; + + return p.BoxedValue; } public T? GetParameterValue(int index) { - return (T?)parameters[index].Value; + ref var p = ref parameters[index]; + if (magicalBox.TryRead(p.BoxOffset, out var value)) + { + return value; + } + else + { + return (T?)p.BoxedValue; + } } public Type GetParameterType(int index) { - return parameters[index].Value?.GetType() ?? typeof(string); + return parameters[index].Type; } } } diff --git a/src/ZLogger/LogStates/StringFormatterLogState.cs b/src/ZLogger/LogStates/StringFormatterLogState.cs index c56eb659..699553cb 100644 --- a/src/ZLogger/LogStates/StringFormatterLogState.cs +++ b/src/ZLogger/LogStates/StringFormatterLogState.cs @@ -1,6 +1,4 @@ -using System; using System.Buffers; -using System.Collections.Generic; using System.Text; using System.Text.Json; diff --git a/src/ZLogger/ZLogger.csproj b/src/ZLogger/ZLogger.csproj index 4aa146bd..36ac1def 100644 --- a/src/ZLogger/ZLogger.csproj +++ b/src/ZLogger/ZLogger.csproj @@ -3,13 +3,15 @@ net6.0; enable - 9.0 + 11.0 + enable true 1701;1702;1591;1573 logging; Zero Allocation Text/Strcutured Logger for .NET Core, built on top of a Microsoft.Extensions.Logging. + true @@ -42,19 +44,19 @@ ZLoggerExtensions.tt - True - True - ZLoggerExtensions.tt + True + True + ZLoggerExtensions.tt - True - True - ZLoggerExtensions.tt + True + True + ZLoggerExtensions.tt - True - True - ZLoggerExtensions.tt + True + True + ZLoggerExtensions.tt diff --git a/src/ZLogger/ZLoggerEntry.cs b/src/ZLogger/ZLoggerEntry.cs index 380b688c..fdd9a121 100644 --- a/src/ZLogger/ZLoggerEntry.cs +++ b/src/ZLogger/ZLoggerEntry.cs @@ -81,6 +81,11 @@ public void FormatUtf8(IBufferWriter writer, IZLoggerFormatter formatter) public void Return() { + if (state is IDisposable) + { + ((IDisposable)state).Dispose(); + } + state = default!; logInfo = default!; ScopeState?.Return(); diff --git a/src/ZLogger/ZLoggerExtensions.cs b/src/ZLogger/ZLoggerExtensions.cs index b736454e..bdb735d3 100644 --- a/src/ZLogger/ZLoggerExtensions.cs +++ b/src/ZLogger/ZLoggerExtensions.cs @@ -22,7 +22,7 @@ public static void ZLog(this ILogger logger, LogLevel logLevel, Exception? excep public static void ZLog(this ILogger logger, LogLevel logLevel, EventId eventId, Exception? exception, ref ZLoggerInterpolatedStringHandler message) { - using var state = message.GetState(); + using var state = message.GetStateAndClear(); logger.Log(logLevel, eventId, state, exception, (state, ex) => state.ToString()); } diff --git a/src/ZLogger/ZLoggerInterpolatedStringHandler.cs b/src/ZLogger/ZLoggerInterpolatedStringHandler.cs index 90842056..8456bd4a 100644 --- a/src/ZLogger/ZLoggerInterpolatedStringHandler.cs +++ b/src/ZLogger/ZLoggerInterpolatedStringHandler.cs @@ -1,6 +1,10 @@ using System.Buffers; -using System.Collections.Generic; +using System.Collections.Concurrent; +using System.Diagnostics.CodeAnalysis; using System.Runtime.CompilerServices; +using System.Runtime.InteropServices; +using System.Text; +using System.Text.Json; using Utf8StringInterpolation; using ZLogger.Internal; using ZLogger.LogStates; @@ -10,36 +14,281 @@ namespace ZLogger [InterpolatedStringHandler] public ref struct ZLoggerInterpolatedStringHandler { - int i; - readonly KeyValuePair[] parameters; // TODO: avoid boxing! - readonly ArrayBufferWriter buffer; - readonly int parametersCount; - Utf8StringWriter> utf8StringWriter; + [ThreadStatic] + static byte[]? boxStoragePool; - public ZLoggerInterpolatedStringHandler(int literalLength, int formattedCount) + [ThreadStatic] + static List? parametersPool; + + [ThreadStatic] + static List? literalPool; + + // fields + int literalLength; + int parametersLength; + List literals; + MagicalBox box; + List parameters; + + /// + /// DO NOT ALLOW DIRECT USE. + /// + public ZLoggerInterpolatedStringHandler(int literalLength, int formattedCount) // TODO: Use: bool outValue { - i = 0; - parametersCount = formattedCount; - parameters = ArrayPool>.Shared.Rent(formattedCount); - buffer = ArrayBufferWriterPool.Rent(); - utf8StringWriter = new Utf8StringWriter>(literalLength, formattedCount, buffer); + var boxStorage = boxStoragePool; + if (boxStorage == null) + { + boxStorage = boxStoragePool = new byte[2048]; + } + + var parameters = parametersPool; + if (parameters == null) + { + parameters = parametersPool = new List(); + } + + var literals = literalPool; + if (literals == null) + { + literals = literalPool = new List(); + } + + this.literalLength = literalLength; + this.parametersLength = formattedCount; + this.box = new MagicalBox(boxStorage); + this.parameters = parameters; + this.literals = literals; } public void AppendLiteral(string s) { - utf8StringWriter.AppendLiteral(s); + literals.Add(s); } public void AppendFormatted(T value, int alignment = 0, string? format = null, [CallerArgumentExpression("value")] string? argumentName = null) { - utf8StringWriter.AppendFormatted(value, alignment, format); - parameters[i++] = new KeyValuePair(argumentName ?? $"Arg{i}", value); + // Add for MessageSequence + literals.Add(null); + + // Use MagicalBox(set value without boxing) + if (!box.TryWrite(value, out var offset)) + { + offset = -1; + } + + var parameter = new InterpolatedStringParameter(typeof(T), argumentName ?? "", alignment, format, offset, (offset == -1) ? (object?)value : null); + parameters.Add(parameter); + } + + internal InterpolatedStringLogState GetStateAndClear() + { + // MessageSequence is immutable + var sequence = MessageSequence.GetOrCreate(literalLength, parametersLength, literals); + + // MagicalBox and Parameters are cloned in ctor. + var result = new InterpolatedStringLogState(sequence, box, CollectionsMarshal.AsSpan(parameters)); + + // clear state + literals.Clear(); + parameters.Clear(); + + return result; + } + } + + // MessageSequence is immutable, can cache per same string format. + internal sealed class MessageSequence + { + // TODO: use specialized impl dictionary?(for example, only check message length) + static readonly ConcurrentDictionary, MessageSequence> cache = new(new MessageSequenceEqualityComparer()); + + // literals null represents parameter hole + public static MessageSequence GetOrCreate(int literalLength, int parameterLength, List literals) + { + if (cache.TryGetValue(literals, out var sequence)) + { + return sequence; + } + + // create copy + var key = literals.ToList(); + sequence = new MessageSequence(literalLength, parameterLength, CollectionsMarshal.AsSpan(key)); + + // if add failed, ok to use duplicate sequence. + cache.TryAdd(key, sequence); + return sequence; + } + + readonly int literalLength; + readonly int parametersLength; + readonly MessageSequenceSegment[] segments; + + public MessageSequence(int literalLength, int parametersLength, ReadOnlySpan literals) + { + this.literalLength = literalLength; + this.parametersLength = parametersLength; + this.segments = new MessageSequenceSegment[literals.Length]; + for (int i = 0; i < literals.Length; i++) + { + var str = literals[i]; + if (str == null) + { + this.segments[i] = new MessageSequenceSegment(null, null!, default); + } + else + { + var bytes = Encoding.UTF8.GetBytes(str); + var encoded = JsonEncodedText.Encode(bytes); + this.segments[i] = new MessageSequenceSegment(str, bytes, encoded); + } + } + } + + public void ToString(IBufferWriter writer, MagicalBox box, Span parameters) + { + var stringWriter = new Utf8StringWriter>(literalLength, parametersLength); + + var parameterIndex = 0; + foreach (var item in segments) + { + if (item.IsLiteral) + { + stringWriter.AppendUtf8(item.Utf8Bytes); + } + else + { + ref var p = ref parameters[parameterIndex++]; + if (!box.TryReadTo(p.Type, p.BoxOffset, p.Alignment, p.Format, ref stringWriter)) + { + stringWriter.AppendFormatted(p.BoxedValue, p.Alignment, p.Format); + } + } + } + stringWriter.Flush(); + } + + public string ToString(MagicalBox box, Span parameters) + { + var stringHandler = new DefaultInterpolatedStringHandler(literalLength, parametersLength); + + var parameterIndex = 0; + foreach (var item in segments) + { + if (item.IsLiteral) + { + stringHandler.AppendLiteral(item.Literal); + } + else + { + ref var p = ref parameters[parameterIndex++]; + if (!box.TryReadTo(p.Type, p.BoxOffset, p.Alignment, p.Format, ref stringHandler)) + { + stringHandler.AppendFormatted(p.BoxedValue, p.Alignment, p.Format); + } + } + } + + return stringHandler.ToStringAndClear(); + } + + public override string ToString() + { + // for debugging. + var stringHandler = new DefaultInterpolatedStringHandler(literalLength, parametersLength); + + foreach (var item in segments) + { + if (item.IsLiteral) + { + stringHandler.AppendLiteral(item.Literal); + } + else + { + stringHandler.AppendLiteral("{}"); + } + } + + return stringHandler.ToStringAndClear(); + } + + internal sealed class MessageSequenceEqualityComparer : IEqualityComparer> + { + public bool Equals(List? x, List? y) + { + if (x == null && y == null) return true; + if (x == null) return false; + if (y == null) return false; + if (x.Count != y.Count) return false; + + var xs = CollectionsMarshal.AsSpan(x); + var ys = CollectionsMarshal.AsSpan(y); + + for (int i = 0; i < xs.Length; i++) + { + if (xs[i] != ys[i]) return false; + } + + return true; + } + + public int GetHashCode([DisallowNull] List? obj) + { + if (obj == null) return 0; + + var hashCode = new HashCode(); + + var span = CollectionsMarshal.AsSpan(obj); + foreach (var item in span) + { + if (item != null) + { + hashCode.AddBytes(MemoryMarshal.AsBytes(item.AsSpan())); + } + } + + return hashCode.ToHashCode(); + } + } + } + + internal readonly struct MessageSequenceSegment + { + public bool IsLiteral => Literal != null; + + public readonly string Literal; + public readonly byte[] Utf8Bytes; + public readonly JsonEncodedText JsonEncoded; + + public MessageSequenceSegment(string? literal, byte[] utf8Bytes, JsonEncodedText jsonEncoded) + { + this.Literal = literal!; + this.Utf8Bytes = utf8Bytes; + this.JsonEncoded = jsonEncoded; } - public InterpolatedStringLogState GetState() + public override string ToString() + { + return Literal; + } + } + + internal readonly struct InterpolatedStringParameter + { + public readonly Type Type; + public readonly string Name; + public readonly int Alignment; + public readonly string? Format; + public readonly int BoxOffset; // if -1, use boxed value + public readonly object? BoxedValue; + + public InterpolatedStringParameter(Type type, string name, int alignment, string? format, int boxOffset, object? boxedValue) { - utf8StringWriter.Flush(); - return new InterpolatedStringLogState(parameters, parametersCount, buffer); + Type = type; + Name = name; + Alignment = alignment; + Format = format; + BoxOffset = boxOffset; + BoxedValue = boxedValue; } - } + } }