Skip to content

Commit

Permalink
Moved FastBuffer lifecycle out of Formatter.
Browse files Browse the repository at this point in the history
  • Loading branch information
CptMoore committed Jan 1, 2025
1 parent bd606e3 commit 645e35b
Show file tree
Hide file tree
Showing 5 changed files with 58 additions and 50 deletions.
20 changes: 10 additions & 10 deletions ModTek/Features/Logging/AppenderFile.cs
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ internal AppenderFile(string path, AppenderSettings settings)
private void Write(string text)
{
var bytes = System.Text.Encoding.UTF8.GetBytes(text);
Write(bytes, bytes.Length);
_writer.Append(bytes, 0, bytes.Length);
}

internal static readonly MTStopwatch FlushStopWatch = new()
Expand All @@ -43,6 +43,7 @@ private void Write(string text)
};
internal static readonly MTStopwatch FiltersStopWatch = new();
internal static readonly MTStopwatch FormatterStopWatch = new();
internal static readonly MTStopwatch WriteStopwatch = new();
internal void Append(ref MTLoggerMessageDto messageDto)
{
if (messageDto.FlushToDisk)
Expand Down Expand Up @@ -72,27 +73,26 @@ internal void Append(ref MTLoggerMessageDto messageDto)
FiltersStopWatch.Stop();
}

byte[] threadUnsafeBytes;
int length;
// using a pool would allow us to implement file async API via Win32 API
// using thread local instance field would allow to use batching
var buffer = FastBuffer.GetThreadStaticBufferAndReset();
FormatterStopWatch.Start();
try
{
length = _formatter.GetFormattedLogLine(ref messageDto, out threadUnsafeBytes);
using (buffer.PinnedUse())
{
_formatter.GetFormattedLogLine(ref messageDto, buffer);
}
}
finally
{
FormatterStopWatch.Stop();
}

Write(threadUnsafeBytes, length);
}

internal static readonly MTStopwatch WriteStopwatch = new();
private void Write(byte[] bytes, int length)
{
WriteStopwatch.Start();
try
{
var length = buffer.GetBytes(out var bytes);
_writer.Append(bytes, 0, length);
}
finally
Expand Down
7 changes: 6 additions & 1 deletion ModTek/Features/Logging/AppenderUnityConsole.cs
Original file line number Diff line number Diff line change
Expand Up @@ -39,8 +39,13 @@ internal void Append(ref MTLoggerMessageDto messageDto)
return;
}

var buffer = FastBuffer.GetThreadStaticBufferAndReset();
using (buffer.PinnedUse())
{
_formatter.GetFormattedLogLine(ref messageDto, buffer);
}
var count = buffer.GetBytes(out var threadUnsafeBytes);
// working with bytes and converting is more costly here, but cheaper elsewhere
var count = _formatter.GetFormattedLogLine(ref messageDto, out var threadUnsafeBytes);
var logLine = System.Text.Encoding.UTF8.GetString(threadUnsafeBytes, 0, count);
s_ignoreNextUnityCapture = true;
_debugUnityLogger.Log(LogLevelToLogType(messageDto.LogLevel), logLine);
Expand Down
28 changes: 25 additions & 3 deletions ModTek/Features/Logging/FastBuffer.cs
Original file line number Diff line number Diff line change
Expand Up @@ -12,16 +12,25 @@ namespace ModTek.Features.Logging;
// - byte based APIs -> avoids unnecessary conversions and allocations if possible
internal unsafe class FastBuffer
{
[ThreadStatic]
private static FastBuffer s_buffer;
internal static FastBuffer GetThreadStaticBufferAndReset()
{
s_buffer ??= new FastBuffer();
s_buffer.Reset();
return s_buffer;
}

internal FastBuffer()
{
EnlargeCapacity(16 * 1024);
EnlargeCapacity(4 * 1024);
}

private int _length;
private byte[] _buffer;
internal int GetThreadUnsafeBytes(out byte[] threadUnsafeBytes)
internal int GetBytes(out byte[] bytes)
{
threadUnsafeBytes = _buffer;
bytes = _buffer;
return _length;
}

Expand All @@ -30,6 +39,19 @@ internal void Reset()
_length = 0;
}

internal AutoUnpin PinnedUse()
{
Pin();
return new AutoUnpin(this);
}
internal readonly struct AutoUnpin(FastBuffer fastBuffer) : IDisposable
{
public void Dispose()
{
fastBuffer.Unpin();
}
}

private GCHandle _handle;
private byte* _bufferPtr;
internal void Pin()
Expand Down
45 changes: 17 additions & 28 deletions ModTek/Features/Logging/Formatter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -21,71 +21,60 @@ internal Formatter(AppenderSettings settings)
_startupTimeEnabled = settings.StartupTimeEnabled;
}

[ThreadStatic]
private static FastBuffer s_buffer;

internal int GetFormattedLogLine(ref MTLoggerMessageDto messageDto, out byte[] threadUnsafeBytes)
internal void GetFormattedLogLine(ref MTLoggerMessageDto messageDto, FastBuffer buffer)
{
s_buffer ??= new FastBuffer();
s_buffer.Reset();
s_buffer.Pin();

if (_absoluteTimeEnabled)
{
var dt = messageDto.GetDateTime();
if (!_absoluteTimeUseUtc)
{
dt = dt.ToLocalTime();
}
s_buffer.Append(dt);
buffer.Append(dt);
}

if (_startupTimeEnabled)
{
var ts = messageDto.StartupTime();
s_buffer.Append(ts);
buffer.Append(ts);
}

if (messageDto.ThreadId != s_unityMainThreadId)
{
s_buffer.Append(s_threadIdPrefix);
s_buffer.Append(messageDto.ThreadId);
s_buffer.Append(s_threadIdSuffix);
buffer.Append(s_threadIdPrefix);
buffer.Append(messageDto.ThreadId);
buffer.Append(s_threadIdSuffix);
}

// TODO create injector and add a nameAsBytes field that should be passed along instead of string
s_buffer.Append(messageDto.LoggerName);
buffer.Append(messageDto.LoggerName);

s_buffer.Append(LogLevelExtension.GetCachedFormattedBytes(messageDto.LogLevel));
buffer.Append(LogLevelExtension.GetCachedFormattedBytes(messageDto.LogLevel));

var prefix = s_whitespaceBytes;
if (!string.IsNullOrEmpty(messageDto.Message))
{
s_buffer.Append(prefix);
s_buffer.Append(messageDto.Message);
buffer.Append(prefix);
buffer.Append(messageDto.Message);
prefix = s_environmentNewline;
}

if (messageDto.Exception != null)
{
s_buffer.Append(prefix);
s_buffer.Append(messageDto.Exception.ToString());
buffer.Append(prefix);
buffer.Append(messageDto.Exception.ToString());
prefix = s_environmentNewline;
}

if (messageDto.Location != null)
{
s_buffer.Append(prefix);
s_buffer.Append(s_locationTraceLabel);
s_buffer.Append(s_environmentNewline);
s_buffer.Append(GetLocationString(messageDto.Location));
buffer.Append(prefix);
buffer.Append(s_locationTraceLabel);
buffer.Append(s_environmentNewline);
buffer.Append(GetLocationString(messageDto.Location));
}

s_buffer.Append(s_environmentNewline);

s_buffer.Unpin();

return s_buffer.GetThreadUnsafeBytes(out threadUnsafeBytes);
buffer.Append(s_environmentNewline);
}

private static string GetLocationString(IStackTrace st)
Expand Down
8 changes: 0 additions & 8 deletions ModTek/Features/Logging/LogStreamImpl/Win32ApiImpl.cs
Original file line number Diff line number Diff line change
Expand Up @@ -140,14 +140,6 @@ private static extern unsafe int WriteFile(
out int numBytesWritten,
NativeOverlapped* lpOverlapped);

[DllImport("kernel32.dll", SetLastError = true)]
private static extern unsafe int WriteFile(
SafeHandle handle,
byte* bytes,
int numBytesToWrite,
out int numBytesWritten,
IntPtr mustBeZero);

[DllImport("kernel32.dll", SetLastError = true)]
[return: MarshalAs(UnmanagedType.Bool)]
private static extern bool FlushFileBuffers(SafeHandle hHandle);
Expand Down

0 comments on commit 645e35b

Please sign in to comment.