Skip to content

Commit

Permalink
UTF-8 WIP
Browse files Browse the repository at this point in the history
  • Loading branch information
ltrzesniewski committed Dec 10, 2023
1 parent f560b2f commit d187065
Show file tree
Hide file tree
Showing 24 changed files with 1,384 additions and 43 deletions.
48 changes: 48 additions & 0 deletions src/ZeroLog.Benchmarks/Logging/StreamAppenderBenchmarks.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,48 @@
using System;
using System.IO;
using System.Text;
using BenchmarkDotNet.Attributes;
using ZeroLog.Appenders;
using ZeroLog.Configuration;
using ZeroLog.Formatting;

namespace ZeroLog.Benchmarks.Logging;

[ShortRunJob]
public class StreamAppenderBenchmarks
{
private readonly Appender _standardFormatterAppender = new(false);
private readonly Appender _utf8FormatterAppender = new(true);
private readonly LoggedMessage _loggedMessage = new(1024, ZeroLogConfiguration.CreateTestConfiguration());
private readonly LogMessage _message;

public StreamAppenderBenchmarks()
{
_message = LogMessage.CreateTestMessage(LogLevel.Info, 1024, 32);
_message.Append("Hello, ").Append("World! ").Append(42).AppendEnum(DayOfWeek.Friday).Append(new DateTime(2023, 01, 01)).Append(1024);
}

[Benchmark(Baseline = true)]
public void StandardFormatter()
{
_loggedMessage.SetMessage(_message);
_standardFormatterAppender.WriteMessage(_loggedMessage);
}

[Benchmark]
public void Utf8Formatter()
{
_loggedMessage.SetMessage(_message);
_utf8FormatterAppender.WriteMessage(_loggedMessage);
}

private class Appender : StreamAppender
{
public Appender(bool utf8Formatter)
{
AllowUtf8Formatter = utf8Formatter;
Stream = Stream.Null;
Encoding = Encoding.UTF8;
}
}
}
36 changes: 30 additions & 6 deletions src/ZeroLog.Benchmarks/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,9 @@
using BenchmarkDotNet.Columns;
using BenchmarkDotNet.Configs;
using BenchmarkDotNet.Running;
using JetBrains.Profiler.Api;
using ZeroLog.Benchmarks.LatencyTests;
using ZeroLog.Benchmarks.Logging;
using ZeroLog.Benchmarks.ThroughputTests;
using ZeroLog.Benchmarks.Tools;

Expand Down Expand Up @@ -39,6 +41,32 @@ private static void LatencyMultiProducer(int threadCount, int warmupMessageCount
);
}

private static void RunProfiler()
{
var bench = new StreamAppenderBenchmarks();

for (var i = 0; i < 100; ++i)
bench.Utf8Formatter();

MeasureProfiler.StartCollectingData();

for (var i = 0; i < 100_000; ++i)
bench.Utf8Formatter();

MeasureProfiler.SaveData();
}

private static void RunBenchmark()
{
BenchmarkSwitcher.FromAssembly(typeof(Program).Assembly).Run();

while (Console.KeyAvailable)
Console.ReadKey(true);

Console.WriteLine("Press enter to exit");
Console.ReadLine();
}

public static void Main()
{
//Throughput();
Expand All @@ -51,12 +79,8 @@ public static void Main()
//EnumBenchmarksRunner.Run();
//ThroughputToFileBench.Run();

BenchmarkSwitcher.FromAssembly(typeof(Program).Assembly).Run();
//RunProfiler();

while (Console.KeyAvailable)
Console.ReadKey(true);

Console.WriteLine("Press enter to exit");
Console.ReadLine();
RunBenchmark();
}
}
1 change: 1 addition & 0 deletions src/ZeroLog.Benchmarks/ZeroLog.Benchmarks.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
<PackageReference Include="HdrHistogram" Version="2.5.0" />
<PackageReference Include="Fody" Version="6.8.0" PrivateAssets="all" />
<PackageReference Include="InlineIL.Fody" Version="1.7.4" PrivateAssets="all" />
<PackageReference Include="JetBrains.Profiler.Api" Version="1.4.0" />
<PackageReference Include="log4net" Version="2.0.15" />
<PackageReference Include="NLog" Version="5.2.7" />
<PackageReference Include="Serilog" Version="3.1.1" />
Expand Down
6 changes: 6 additions & 0 deletions src/ZeroLog.Impl.Base/Log.cs
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,18 @@ public sealed partial class Log
private LogLevel _logLevel = LogLevel.None;

internal string Name { get; }
internal byte[] NameUtf8 { get; }

internal string CompactName { get; }
internal byte[] CompactNameUtf8 { get; }

internal Log(string name)
{
Name = name;
NameUtf8 = Encoding.UTF8.GetBytes(Name);

CompactName = GetCompactName(name);
CompactNameUtf8 = Encoding.UTF8.GetBytes(CompactName);
}

/// <summary>
Expand Down
60 changes: 49 additions & 11 deletions src/ZeroLog.Impl.Full/Appenders/StreamAppender.cs
Original file line number Diff line number Diff line change
Expand Up @@ -13,9 +13,11 @@ public abstract class StreamAppender : Appender
{
private byte[] _byteBuffer = [];

private readonly Formatter _formatter = new DefaultFormatter();
private Encoding _encoding = Encoding.UTF8;
private Utf8Formatter? _utf8Formatter;
private bool _useSpanGetBytes;
private Formatter? _formatter;
private bool _allowUtf8Formatter = true;

/// <summary>
/// The stream to write to.
Expand All @@ -30,6 +32,9 @@ protected internal Encoding Encoding
get => _encoding;
set
{
if (ReferenceEquals(value, _encoding))
return;

_encoding = value;
UpdateEncodingSpecificData();
}
Expand All @@ -40,8 +45,28 @@ protected internal Encoding Encoding
/// </summary>
public Formatter Formatter
{
get => _formatter ??= new DefaultFormatter();
init => _formatter = value;
get => _formatter;
init
{
if (ReferenceEquals(value, _formatter))
return;

_formatter = value;
UpdateEncodingSpecificData();
}
}

/// <summary>
/// For benchmarks.
/// </summary>
internal bool AllowUtf8Formatter
{
get => _allowUtf8Formatter;
set
{
_allowUtf8Formatter = value;
UpdateEncodingSpecificData();
}
}

/// <summary>
Expand All @@ -64,21 +89,25 @@ public override void Dispose()
/// <inheritdoc/>
public override void WriteMessage(LoggedMessage message)
{
if (Stream is null)
if (Stream is not { } stream)
return;

if (_useSpanGetBytes)
if (_utf8Formatter is { } utf8Formatter)
{
stream.Write(utf8Formatter.FormatMessage(message));
}
else if (_useSpanGetBytes)
{
var chars = Formatter.FormatMessage(message);
var chars = _formatter.FormatMessage(message);
var byteCount = _encoding.GetBytes(chars, _byteBuffer);
Stream.Write(_byteBuffer, 0, byteCount);
stream.Write(_byteBuffer, 0, byteCount);
}
else
{
Formatter.FormatMessage(message);
var charBuffer = Formatter.GetBuffer(out var charCount);
_formatter.FormatMessage(message);
var charBuffer = _formatter.GetBuffer(out var charCount);
var byteCount = _encoding.GetBytes(charBuffer, 0, charCount, _byteBuffer, 0);
Stream.Write(_byteBuffer, 0, byteCount);
stream.Write(_byteBuffer, 0, byteCount);
}
}

Expand All @@ -91,14 +120,23 @@ public override void Flush()

private void UpdateEncodingSpecificData()
{
var maxBytes = _encoding.GetMaxByteCount(LogManager.OutputBufferSize);
if (_encoding is UTF8Encoding && _formatter.AsUtf8Formatter() is { } utf8Formatter && _allowUtf8Formatter)
{
// Fast path
_utf8Formatter = utf8Formatter;
return;
}

_utf8Formatter = null;

// The base Encoding class allocates buffers in all non-abstract GetBytes overloads in order to call the abstract
// GetBytes(char[] chars, int charIndex, int charCount, byte[] bytes, int byteIndex) in the end.
// If an encoding overrides the Span version of GetBytes, we assume it avoids this allocation
// and it skips safety checks as those are guaranteed by the Span struct. In that case, we can call this overload directly.
_useSpanGetBytes = OverridesSpanGetBytes(_encoding.GetType());

var maxBytes = _encoding.GetMaxByteCount(LogManager.OutputBufferSize);

if (_byteBuffer.Length < maxBytes)
_byteBuffer = GC.AllocateUninitializedArray<byte>(maxBytes);
}
Expand Down
37 changes: 35 additions & 2 deletions src/ZeroLog.Impl.Full/Configuration/ZeroLogConfiguration.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
using System.Collections.Generic;
using System.ComponentModel;
using System.Linq;
using System.Text;
using ZeroLog.Appenders;
using ZeroLog.Formatting;

Expand All @@ -16,6 +17,9 @@ public sealed class ZeroLogConfiguration

private LoggerConfigurationCollection _loggers = new();

private string _nullDisplayString = "null";
private string _truncatedMessageSuffix = " [TRUNCATED]";

internal event Action? ApplyChangesRequested;

/// <summary>
Expand Down Expand Up @@ -86,15 +90,35 @@ public bool UseBackgroundThread
/// <remarks>
/// Default: "null"
/// </remarks>
public string NullDisplayString { get; set; } = "null";
public string NullDisplayString
{
get => _nullDisplayString;
set
{
_nullDisplayString = value;
NullDisplayStringUtf8 = Encoding.UTF8.GetBytes(value);
}
}

internal byte[] NullDisplayStringUtf8 { get; private set; }

/// <summary>
/// The string which is appended to a message when it is truncated.
/// </summary>
/// <remarks>
/// Default: " [TRUNCATED]"
/// </remarks>
public string TruncatedMessageSuffix { get; set; } = " [TRUNCATED]";
public string TruncatedMessageSuffix
{
get => _truncatedMessageSuffix;
set
{
_truncatedMessageSuffix = value;
TruncatedMessageSuffixUtf8 = Encoding.UTF8.GetBytes(value);
}
}

internal byte[] TruncatedMessageSuffixUtf8 { get; private set; }

/// <summary>
/// The time an appender will be put into quarantine (not used to log messages) after it throws an exception.
Expand All @@ -121,6 +145,15 @@ public bool UseBackgroundThread
/// </remarks>
public ILoggerConfigurationCollection Loggers => _loggers;

/// <summary>
/// Creates a new ZeroLog configuration.
/// </summary>
public ZeroLogConfiguration()
{
NullDisplayStringUtf8 = Encoding.UTF8.GetBytes(NullDisplayString);
TruncatedMessageSuffixUtf8 = Encoding.UTF8.GetBytes(TruncatedMessageSuffix);
}

/// <summary>
/// Applies the changes made to this object since the call to <see cref="LogManager.Initialize"/>
/// or the last call to <see cref="ApplyChanges"/>.
Expand Down
Loading

0 comments on commit d187065

Please sign in to comment.