diff --git a/EonaCat.Logger/EonaCat.Logger.csproj b/EonaCat.Logger/EonaCat.Logger.csproj index b1862b4..af69bce 100644 --- a/EonaCat.Logger/EonaCat.Logger.csproj +++ b/EonaCat.Logger/EonaCat.Logger.csproj @@ -13,8 +13,8 @@ EonaCat (Jeroen Saey) EonaCat;Logger;EonaCatLogger;Log;Writer;Jeroen;Saey - 1.6.8 - 1.6.8 + 1.6.9 + 1.6.9 README.md True LICENSE @@ -25,7 +25,7 @@ - 1.6.8+{chash:10}.{c:ymd} + 1.6.9+{chash:10}.{c:ymd} true true v[0-9]* diff --git a/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs b/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs index a236f25..98da27d 100644 --- a/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs +++ b/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs @@ -4,47 +4,53 @@ using EonaCat.Logger.Managers; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; using System; -using System.Buffers; using System.Collections.Concurrent; using System.Collections.Generic; using System.IO; +using System.Linq; using System.Text; using System.Threading; -using System.Threading.Channels; using System.Threading.Tasks; [ProviderAlias("EonaCatFileLogger")] -public sealed class FileLoggerProvider : ILoggerProvider +public sealed class FileLoggerProvider : BatchingLoggerProvider { private readonly string _path; private readonly string _fileNamePrefix; private readonly int _maxFileSize; private readonly int _maxRetainedFiles; - private readonly LoggerScopedContext _context = new LoggerScopedContext(); - private readonly Channel _channel; - private readonly CancellationTokenSource _cts = new(); - private readonly Task _writerTask; - private readonly ConcurrentDictionary _files = new(); + private readonly int _maxRolloverFiles; - private const int BufferSize = 4 * 1024 * 1024; // 4 MB buffer for large messages + private readonly LoggerScopedContext _context = new LoggerScopedContext(); + private readonly ConcurrentDictionary _files = new(); + private readonly ConcurrentDictionary> _messageQueues = new(); + + private const int BufferSize = 1024 * 1024; // 1 MB buffer for large JSON logs private static readonly Encoding Utf8 = new UTF8Encoding(false); public bool IncludeCorrelationId { get; } public bool EnableCategoryRouting { get; } - public string LogFile => _files.TryGetValue(string.Empty, out var state) ? state.FilePath : string.Empty; + public string LogFile => _files.TryGetValue(string.Empty, out var state) ? state.FilePath : null; + + public event EventHandler OnError; + public event EventHandler OnRollOver; + + private readonly Timer _flushTimer; + private readonly TimeSpan _flushInterval = TimeSpan.FromMilliseconds(500); private sealed class FileState { - public FileStream Stream; - public byte[] Buffer = ArrayPool.Shared.Rent(BufferSize); - public int BufferPosition; + public string FilePath; public long Size; public DateTime Date; - public string FilePath; + public byte[] Buffer = new byte[BufferSize]; + public int BufferPosition; + public FileStream Stream; + public SemaphoreSlim WriteLock = new(1, 1); // async safe } - public FileLoggerProvider(IOptions options) + public FileLoggerProvider(IOptions options) : base(options) { var o = options.Value ?? throw new ArgumentNullException(nameof(options)); @@ -52,111 +58,193 @@ public sealed class FileLoggerProvider : ILoggerProvider _fileNamePrefix = o.FileNamePrefix; _maxFileSize = o.FileSizeLimit; _maxRetainedFiles = o.RetainedFileCountLimit; + _maxRolloverFiles = o.MaxRolloverFiles; IncludeCorrelationId = o.IncludeCorrelationId; EnableCategoryRouting = o.EnableCategoryRouting; Directory.CreateDirectory(_path); - _channel = Channel.CreateUnbounded(new UnboundedChannelOptions - { - SingleReader = true, - SingleWriter = false - }); + var defaultState = CreateFileState(DateTime.UtcNow.Date, o.Category); + _files[string.Empty] = defaultState; - // Start writer task - _writerTask = Task.Run(ProcessQueueAsync); - - // Start background cleanup task - Task.Run(BackgroundCleanupAsync); + // Periodic flush + _flushTimer = new Timer(_ => PeriodicFlushAsync().ConfigureAwait(false), null, _flushInterval, _flushInterval); } - public ILogger CreateLogger(string category) => new Logger(_channel, category); - - public void Dispose() + internal override Task WriteMessagesAsync(IReadOnlyList messages, CancellationToken token) { - _cts.Cancel(); - _writerTask.Wait(); - - foreach (var state in _files.Values) + try { - FlushAndDispose(state); - } - } - - private async Task ProcessQueueAsync() - { - await foreach (var msg in _channel.Reader.ReadAllAsync(_cts.Token)) - { - var categoryKey = EnableCategoryRouting ? SanitizeCategory(msg.Category) : string.Empty; - var state = _files.GetOrAdd(categoryKey, _ => CreateFileState(categoryKey)); - - var text = BuildMessage(msg); - var bytes = Utf8.GetBytes(text); - - if (bytes.Length > BufferSize) + if (EnableCategoryRouting) { - await state.Stream.WriteAsync(bytes, 0, bytes.Length, _cts.Token); - state.Size += bytes.Length; + var grouped = messages.GroupBy(m => SanitizeCategory(m.Category)); + foreach (var group in grouped) + { + var key = group.Key; + var queue = _messageQueues.GetOrAdd(key, _ => new ConcurrentQueue()); + foreach (var msg in group) + { + queue.Enqueue(msg); + } + } } else { - if (state.BufferPosition + bytes.Length > BufferSize) + var queue = _messageQueues.GetOrAdd(string.Empty, _ => new ConcurrentQueue()); + foreach (var msg in messages) { - await FlushBufferAsync(state); + queue.Enqueue(msg); } - - Array.Copy(bytes, 0, state.Buffer, state.BufferPosition, bytes.Length); - state.BufferPosition += bytes.Length; - state.Size += bytes.Length; - } - - if (state.Size >= _maxFileSize) - { - await RollOverAsync(state, categoryKey); } } + catch (Exception ex) + { + OnError?.Invoke(this, new ErrorMessage { Exception = ex, Message = ex.Message }); + } + + return Task.CompletedTask; } - private FileState CreateFileState(string category) + private async Task PeriodicFlushAsync() { - var path = GetFullPath(category, DateTime.UtcNow); - var stream = new FileStream(path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite | FileShare.Delete, - 4096, useAsync: true); + foreach (var kv in _messageQueues) + { + var key = kv.Key; + var queue = kv.Value; + + if (!_files.TryGetValue(key, out var state)) + { + state = CreateFileState(DateTime.UtcNow.Date, key); + _files[key] = state; + } + + var messagesToWrite = new List(); + while (queue.TryDequeue(out var msg)) + { + messagesToWrite.Add(msg); + } + + if (messagesToWrite.Count > 0) + { + try + { + await state.WriteLock.WaitAsync(); + WriteBatch(state, messagesToWrite, key); + } + catch (Exception ex) + { + OnError?.Invoke(this, new ErrorMessage { Exception = ex, Message = ex.Message }); + } + finally + { + state.WriteLock.Release(); + } + } + } + + DeleteOldLogFiles(); + } + + private void WriteBatch(FileState state, IEnumerable messages, string categoryKey) + { + if (!File.Exists(state.FilePath)) + { + RecreateFile(state, categoryKey); + } + + foreach (var msg in messages) + { + var date = msg.Timestamp.UtcDateTime.Date; + + if (state.Date != date) + { + FlushBufferAsync(state).GetAwaiter().GetResult(); + RotateByDate(state, date, categoryKey); + } + + WriteMessageToBuffer(state, msg); + + if (state.BufferPosition >= BufferSize - 1024 || state.Size >= _maxFileSize) + { + FlushBufferAsync(state).GetAwaiter().GetResult(); + + if (state.Size >= _maxFileSize) + { + RollOver(state, categoryKey); + } + } + } + + FlushBufferAsync(state).GetAwaiter().GetResult(); + } + + private FileState CreateFileState(DateTime date, string category) + { + var path = GetFullName(date, category); return new FileState { - Stream = stream, - Date = DateTime.UtcNow.Date, FilePath = path, - Size = stream.Length + Date = date, + Size = GetFileSize(path), + Stream = OpenFileWithRetryAsync(path).GetAwaiter().GetResult() }; } - private async Task FlushBufferAsync(FileState state) + private static async Task OpenFileWithRetryAsync(string path) { - if (state.BufferPosition == 0) + const int retries = 3; + for (int i = 0; i < retries; i++) { - return; + try + { + return new FileStream(path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite | FileShare.Delete, 4096, FileOptions.Asynchronous | FileOptions.SequentialScan); + } + catch + { + await Task.Delay(5); + } } - await state.Stream.WriteAsync(state.Buffer, 0, state.BufferPosition, _cts.Token); - state.BufferPosition = 0; - await state.Stream.FlushAsync(_cts.Token); + throw new IOException("Unable to open log file."); } - private async Task RollOverAsync(FileState state, string category) + private void RecreateFile(FileState state, string category) { - await FlushBufferAsync(state); - state.Stream.Dispose(); + FlushBufferAsync(state).GetAwaiter().GetResult(); + state.Stream?.Dispose(); + + state.FilePath = GetFullName(DateTime.UtcNow.Date, category); + state.Size = 0; + state.BufferPosition = 0; + state.Stream = OpenFileWithRetryAsync(state.FilePath).GetAwaiter().GetResult(); + } + + private void RotateByDate(FileState state, DateTime newDate, string category) + { + state.Stream?.Dispose(); + + state.Date = newDate; + state.FilePath = GetFullName(newDate, category); + state.Size = GetFileSize(state.FilePath); + state.BufferPosition = 0; + state.Stream = OpenFileWithRetryAsync(state.FilePath).GetAwaiter().GetResult(); + } + + private void RollOver(FileState state, string category) + { + FlushBufferAsync(state).GetAwaiter().GetResult(); + state.Stream?.Dispose(); var dir = Path.GetDirectoryName(state.FilePath); var name = Path.GetFileNameWithoutExtension(state.FilePath); var ext = Path.GetExtension(state.FilePath); - for (int i = _maxRetainedFiles - 1; i >= 1; i--) + for (int i = _maxRolloverFiles - 1; i >= 1; i--) { var src = Path.Combine(dir, $"{name}.{i}{ext}"); var dst = Path.Combine(dir, $"{name}.{i + 1}{ext}"); + if (File.Exists(dst)) { File.Delete(dst); @@ -174,14 +262,95 @@ public sealed class FileLoggerProvider : ILoggerProvider File.Move(state.FilePath, first); } - state.FilePath = GetFullPath(category, DateTime.UtcNow); - state.Stream = new FileStream(state.FilePath, FileMode.Append, FileAccess.Write, - FileShare.ReadWrite | FileShare.Delete, 4096, useAsync: true); + OnRollOver?.Invoke(this, state.FilePath); + state.Size = 0; state.BufferPosition = 0; + state.Stream = OpenFileWithRetryAsync(state.FilePath).GetAwaiter().GetResult(); + } + + private void WriteMessageToBuffer(FileState state, LogMessage msg) + { + var text = BuildMessage(msg); + var byteCount = Utf8.GetByteCount(text); + + if (state.BufferPosition + byteCount > BufferSize) + { + FlushBufferAsync(state).GetAwaiter().GetResult(); + } + + var written = Utf8.GetBytes(text, 0, text.Length, state.Buffer, state.BufferPosition); + state.BufferPosition += written; + state.Size += written; + } + + private string BuildMessage(LogMessage msg) + { + var settings = msg.Settings ?? LoggerSettings; + + if (!IncludeCorrelationId) + { + return msg.Message + Environment.NewLine; + } + + var ctx = _context.GetAll(); + if (ctx.Count == 0) + { + return msg.Message + Environment.NewLine; + } + + var sb = new StringBuilder(256); + sb.Append(msg.Message).Append(" ["); + + bool first = true; + foreach (var kv in ctx) + { + if (!first) + { + sb.Append(' '); + } + + sb.Append(kv.Key).Append('=').Append(kv.Value); + first = false; + } + + sb.Append(']').AppendLine(); + return sb.ToString(); + } + + private async Task FlushBufferAsync(FileState state) + { + if (state.BufferPosition == 0 || state.Stream == null) + { + return; + } + + await state.Stream.WriteAsync(state.Buffer, 0, state.BufferPosition); + await state.Stream.FlushAsync(); + state.BufferPosition = 0; } - private string GetFullPath(string category, DateTime date) + private static long GetFileSize(string path) => File.Exists(path) ? new FileInfo(path).Length : 0; + + private void DeleteOldLogFiles() + { + if (_maxRetainedFiles <= 0) + { + return; + } + + var files = new DirectoryInfo(_path) + .GetFiles($"{_fileNamePrefix}*") + .OrderByDescending(f => f.LastWriteTimeUtc) + .Skip(_maxRetainedFiles); + + foreach (var f in files) + { + try { f.Delete(); } catch { } + } + } + + private string GetFullName(DateTime date, string category) { var datePart = date.ToString("yyyyMMdd"); var machine = Environment.MachineName; @@ -195,109 +364,34 @@ public sealed class FileLoggerProvider : ILoggerProvider return Path.Combine(_path, $"{_fileNamePrefix}_{machine}_{safeCategory}_{datePart}.log"); } - private string BuildMessage(LogMessage msg) - { - if (!IncludeCorrelationId) - { - return msg.Message + Environment.NewLine; - } - - var ctx = _context.GetAll(); - if (ctx.Count == 0) - { - return msg.Message + Environment.NewLine; - } - - var sb = new StringBuilder(msg.Message.Length + 128); - sb.Append(msg.Message).Append(" ["); - bool first = true; - foreach (var kv in ctx) - { - if (!first) - { - sb.Append(' '); - } - - sb.Append(kv.Key).Append('=').Append(kv.Value); - first = false; - } - sb.Append(']').AppendLine(); - return sb.ToString(); - } - private static string SanitizeCategory(string category) { foreach (var c in Path.GetInvalidFileNameChars()) { category = category.Replace(c, '_'); } - return category.Replace('.', '_'); } - private void FlushAndDispose(FileState state) + protected override void OnShutdownFlush() { - try - { - if (state.BufferPosition > 0) - { - state.Stream.Write(state.Buffer, 0, state.BufferPosition); - state.Stream.Flush(); - } - state.Stream.Dispose(); - ArrayPool.Shared.Return(state.Buffer); - } - catch { } - } + _flushTimer?.Dispose(); + PeriodicFlushAsync().GetAwaiter().GetResult(); - private async Task BackgroundCleanupAsync() - { - while (!_cts.Token.IsCancellationRequested) + foreach (var state in _files.Values) { try { - foreach (var file in new DirectoryInfo(_path).GetFiles($"{_fileNamePrefix}*")) - { - var files = new DirectoryInfo(_path).GetFiles($"{_fileNamePrefix}*"); - Array.Sort(files, (a, b) => b.LastWriteTimeUtc.CompareTo(a.LastWriteTimeUtc)); - - for (int i = _maxRetainedFiles; i < files.Length; i++) - { - try { files[i].Delete(); } catch { } - } - } + FlushBufferAsync(state).GetAwaiter().GetResult(); + state.Stream?.Dispose(); + } + catch + { + // Do nothing } - catch { } - - await Task.Delay(TimeSpan.FromSeconds(30), _cts.Token); // cleanup every 30s - } - } - - private sealed class Logger : ILogger - { - private readonly Channel _channel; - private readonly string _category; - - public Logger(Channel channel, string category) - { - _channel = channel; - _category = category; } - public IDisposable BeginScope(TState state) => null; - public bool IsEnabled(LogLevel logLevel) => true; - - public void Log(LogLevel logLevel, EventId eventId, TState state, - Exception exception, Func formatter) - { - var msg = formatter(state, exception); - _channel.Writer.TryWrite(new LogMessage { Message = msg, Category = _category }); - } - } - - private sealed class LogMessage - { - public string Message; - public string Category; + _files.Clear(); + _messageQueues.Clear(); } }