diff --git a/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs b/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs index 0904adf..ba32c9a 100644 --- a/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs +++ b/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs @@ -9,7 +9,9 @@ using System.Buffers; using System.Collections.Concurrent; using System.Collections.Generic; using System.IO; +using System.IO.Compression; using System.Linq; +using System.Security.Cryptography; using System.Text; using System.Threading; using System.Threading.Tasks; @@ -22,10 +24,11 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable private readonly int _maxFileSize; private readonly int _maxRetainedFiles; private readonly int _maxRolloverFiles; - private readonly List _compressionTasks = new(); private readonly byte[] _encryptionKey; private readonly byte[] _encryptionIV; + private readonly bool _isEncryptionEnabled; + public bool IsEncryptionEnabled => _encryptionKey != null && _encryptionIV != null; private bool _disposed; @@ -33,6 +36,10 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable public static TimeSpan FaultCooldown = TimeSpan.FromSeconds(60); + private readonly ConcurrentQueue _compressionQueue = new(); + private readonly SemaphoreSlim _compressionSemaphore = new(1, 1); + private readonly Task _compressionWorker; + private readonly LoggerScopedContext _context = new(); private readonly ConcurrentDictionary _files = new(); private readonly ConcurrentDictionary> _messageQueues = new(); @@ -51,8 +58,9 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable public event EventHandler OnRollOver; private readonly Timer _flushTimer; - private readonly TimeSpan _flushInterval = TimeSpan.FromMilliseconds(500); + private readonly TimeSpan _flushInterval = TimeSpan.FromSeconds(1); private readonly string _fallbackPath; + private readonly Aes _aes; private sealed class FileState : IDisposable { @@ -75,7 +83,6 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable { if (Buffer != null) { - Array.Clear(Buffer, 0, BufferPosition); ArrayPool.Shared.Return(Buffer, clearArray: true); Buffer = null; } @@ -83,10 +90,7 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable Stream?.Dispose(); WriteLock?.Dispose(); } - catch - { - // Do nothing - } + catch { } } } @@ -94,8 +98,9 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable { var o = options.Value ?? throw new ArgumentNullException(nameof(options)); + _path = EnsureWritableDirectory(o.LogDirectory); + _fallbackPath = EnsureWritableDirectory(Path.Combine(Path.GetTempPath(), "EonaCatFallbackLogs")); - _path = o.LogDirectory; _fileNamePrefix = o.FileNamePrefix; _maxFileSize = o.FileSizeLimit; _maxRetainedFiles = o.RetainedFileCountLimit; @@ -103,19 +108,27 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable IncludeCorrelationId = o.IncludeCorrelationId; EnableCategoryRouting = o.EnableCategoryRouting; MinimumLogLevel = o.MinimumLogLevel; + _encryptionKey = o.EncryptionKey; _encryptionIV = o.EncryptionIV; + _isEncryptionEnabled = _encryptionKey != null && _encryptionIV != null; - _path = EnsureWritableDirectory(o.LogDirectory); - _fallbackPath = EnsureWritableDirectory(Path.Combine(Path.GetTempPath(), "EonaCatFallbackLogs")); + if (_isEncryptionEnabled) + { + _aes = Aes.Create(); + _aes.Key = _encryptionKey; + _aes.IV = _encryptionIV; + } var defaultState = CreateFileState(DateTime.UtcNow.Date, o.Category); _files[string.Empty] = defaultState; _flushTimer = new Timer(FlushTimerCallback, null, _flushInterval, _flushInterval); + + _compressionWorker = Task.Run(CompressionWorkerAsync); } - private static string EnsureWritableDirectory(string path) + private string EnsureWritableDirectory(string path) { string fallback = Path.Combine(Path.GetTempPath(), "EonaCatFallbackLogs"); @@ -124,33 +137,18 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable try { Directory.CreateDirectory(dir); - - // Test write permission string testFile = Path.Combine(dir, $"write_test_{Guid.NewGuid()}.tmp"); File.WriteAllText(testFile, "test"); File.Delete(testFile); - return dir; } - catch - { - // Do nothing - } - } - - try - { - Directory.CreateDirectory(fallback); - } - catch - { - // Do nothing + catch { } } + Directory.CreateDirectory(fallback); return fallback; } - private void FlushTimerCallback(object state) { if (_disposed) @@ -163,15 +161,7 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable return; } - try - { - PeriodicFlushAsync().ConfigureAwait(false); - } - catch { } - finally - { - Interlocked.Exchange(ref _isFlushing, 0); - } + _ = PeriodicFlushAsync().ContinueWith(_ => Interlocked.Exchange(ref _isFlushing, 0)); } internal override Task WriteMessagesAsync(IReadOnlyList messages, CancellationToken token) @@ -182,7 +172,6 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable if (EnableCategoryRouting) { - // Group messages by sanitized category var grouped = filtered.GroupBy(m => SanitizeCategory(m.Category)); foreach (var group in grouped) { @@ -204,11 +193,7 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable } catch (Exception ex) { - OnError?.Invoke(this, new ErrorMessage - { - Exception = ex, - Message = $"Failed to enqueue messages: {ex.Message}" - }); + OnError?.Invoke(this, new ErrorMessage { Exception = ex, Message = $"Failed to enqueue messages: {ex.Message}" }); } return Task.CompletedTask; @@ -234,7 +219,7 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable if (!TryRecover(state)) { - // drop to prevent memory leak + // drop messages if recovery fails while (queue.TryDequeue(out _)) { } continue; } @@ -244,23 +229,16 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable continue; } - state.WriteLock.Wait(); + await state.WriteLock.WaitAsync(); + try { - var batch = new List(256); + await FlushMessagesBatchAsync(state, queue).ConfigureAwait(false); - while (queue.TryDequeue(out var msg)) + // If buffer has remaining data, flush it + if (state.BufferPosition > 0) { - batch.Add(msg); - if (batch.Count >= 256) - { - break; - } - } - - if (batch.Count > 0) - { - await WriteBatchAsync(state, batch, key).ConfigureAwait(false); + await FlushBufferAsync(state).ConfigureAwait(false); } } finally @@ -269,132 +247,186 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable } } - CompressOldLogFiles(); - CompressOldFilesByAge(7); + QueueOldFilesForCompression(); } - private void CompressOldLogFiles() - { + private async Task FlushMessagesBatchAsync(FileState state, ConcurrentQueue queue) + { + const int maxBatch = 128; + int batchCount = 0; + + await state.WriteLock.WaitAsync(); + try + { + while (queue.TryDequeue(out var msg) && batchCount < maxBatch) + { + var msgDate = msg.Timestamp.UtcDateTime.Date; + if (state.Date != msgDate) + { + await FlushBufferAsync(state).ConfigureAwait(false); + RotateByDate(state, msgDate, string.Empty); + } + + var text = BuildMessage(msg); + int byteCount = Utf8.GetByteCount(text); + + // Flush buffer if message won't fit + if (state.BufferPosition + byteCount > BufferSize) + { + await FlushBufferAsync(state).ConfigureAwait(false); + } + + // Encode directly into buffer + Utf8.GetBytes(text, 0, text.Length, state.Buffer, state.BufferPosition); + state.BufferPosition += byteCount; + state.Size += byteCount; + + batchCount++; + } + + // Encrypt buffer in place if needed + if (_isEncryptionEnabled && state.BufferPosition > 0) + { + var encrypted = Encrypt(state.Buffer.AsSpan(0, state.BufferPosition).ToArray()); + await state.Stream.WriteAsync(encrypted, 0, encrypted.Length).ConfigureAwait(false); + await state.Stream.FlushAsync().ConfigureAwait(false); + Array.Clear(encrypted, 0, encrypted.Length); + state.BufferPosition = 0; + } + else if (state.BufferPosition > 0) + { + await state.Stream.WriteAsync(state.Buffer, 0, state.BufferPosition).ConfigureAwait(false); + await state.Stream.FlushAsync().ConfigureAwait(false); + state.BufferPosition = 0; + } + } + finally + { + state.WriteLock.Release(); + } + } + + private async Task FlushBufferAsync(FileState state, CancellationToken token = default) + { + if (state.IsFaulted || state.BufferPosition == 0 || state.Stream == null) + { + return; + } + + try + { + await state.Stream.WriteAsync(state.Buffer, 0, state.BufferPosition, token).ConfigureAwait(false); + await state.Stream.FlushAsync(token).ConfigureAwait(false); + } + catch (Exception ex) + { + HandleWriteFailure(state, ex); + } + finally + { + // Clear buffer to prevent sensitive data leak + Array.Clear(state.Buffer, 0, state.BufferPosition); + state.BufferPosition = 0; + } + } + + private void QueueOldFilesForCompression() + { if (_maxRetainedFiles <= 0) { return; } - var files = new DirectoryInfo(_path).GetFiles($"{_fileNamePrefix}*").OrderByDescending(f => f.LastWriteTimeUtc).Skip(_maxRetainedFiles); - foreach (var currentFile in files) - { - try - { - Task.Run(() => CompressOldLogFile(currentFile.FullName)); - } - catch - { - // Do nothing - } - } - } - - private void CompressOldFilesByAge(int daysThreshold) - { - var cutoff = DateTime.UtcNow.AddDays(-daysThreshold); - var files = new DirectoryInfo(_path) .GetFiles($"{_fileNamePrefix}*") - .Where(f => f.LastWriteTimeUtc < cutoff && !f.Name.EndsWith(".gz")); + .OrderByDescending(f => f.LastWriteTimeUtc) + .Skip(_maxRetainedFiles); - foreach (var file in files) + foreach (var f in files) { - var task = Task.Run(() => CompressOldLogFile(file.FullName)); - _compressionTasks.Add(task); + _compressionQueue.Enqueue(f.FullName); } } - private async Task WriteBatchAsync(FileState state, List messages, string categoryKey) + private async Task CompressionWorkerAsync() { - foreach (var msg in messages) + while (!_disposed) { - var date = msg.Timestamp.UtcDateTime.Date; - - if (state.Date != date) + if (_compressionQueue.TryDequeue(out var filePath)) { - await FlushBufferAsync(state).ConfigureAwait(false); - RotateByDate(state, date, categoryKey); - } - - await WriteMessageToBufferAsync(state, msg).ConfigureAwait(false); - - if (state.BufferPosition >= BufferSize - 1024 || state.Size >= _maxFileSize) - { - await FlushBufferAsync(state).ConfigureAwait(false); - - if (state.Size >= _maxFileSize) + await _compressionSemaphore.WaitAsync(); + try { - RollOverAndCompressOldest(state, categoryKey); + await CompressOldLogFileAsync(filePath); + } + finally + { + _compressionSemaphore.Release(); } } + else + { + // Sleep longer if no work to reduce CPU + await Task.Delay(2000); + } } - - await FlushBufferAsync(state).ConfigureAwait(false); } - private async Task WriteMessageToBufferAsync(FileState state, LogMessage msg) + private async Task CompressOldLogFileAsync(string filePath, int retryCount = 3) { - try + if (!File.Exists(filePath) || filePath.EndsWith(".gz", StringComparison.OrdinalIgnoreCase)) + return; + + var dir = Path.GetDirectoryName(filePath); + var name = Path.GetFileNameWithoutExtension(filePath); + var ext = Path.GetExtension(filePath); + + int suffix = 1; + string compressedFile; + do + { + compressedFile = Path.Combine(dir, $"{name}_{suffix}{ext}.gz"); + suffix++; + } while (File.Exists(compressedFile)); + + for (int attempt = 0; attempt < retryCount; attempt++) { - string text; try { - text = BuildMessage(msg); + using var original = new FileStream(filePath, FileMode.Open, FileAccess.Read, FileShare.Read); + using var compressed = new FileStream(compressedFile, FileMode.CreateNew, FileAccess.Write); + using var gzip = new GZipStream(compressed, CompressionLevel.Fastest); // faster + + await original.CopyToAsync(gzip).ConfigureAwait(false); + await gzip.FlushAsync().ConfigureAwait(false); + + File.Delete(filePath); + return; + } + catch (IOException) + { + await Task.Delay(200); } catch (Exception ex) { OnError?.Invoke(this, new ErrorMessage { Exception = ex, - Message = $"Failed to build log message: {msg.Message}" + Message = $"Failed to compress log file: {filePath}" }); return; } - - var data = Utf8.GetBytes(text); - - if (IsEncryptionEnabled) - { - data = Encrypt(data); - } - - // Flush buffer if not enough space - if (state.BufferPosition + data.Length > BufferSize) - { - await FlushBufferAsync(state).ConfigureAwait(false); - } - - // Copy to buffer safely - if (data.Length <= BufferSize) - { - Array.Copy(data, 0, state.Buffer, state.BufferPosition, data.Length); - state.BufferPosition += data.Length; - state.Size += data.Length; - } - - // Clear temporary data - Array.Clear(data, 0, data.Length); - } - catch (Exception ex) - { - HandleWriteFailure(state, ex); } } private byte[] Encrypt(byte[] plainBytes) { - if (plainBytes == null || plainBytes.Length == 0) return plainBytes; + if (plainBytes == null || plainBytes.Length == 0) + { + return plainBytes; + } - using var aes = System.Security.Cryptography.Aes.Create(); - aes.Key = _encryptionKey; - aes.IV = _encryptionIV; - - using var encryptor = aes.CreateEncryptor(); + using var encryptor = _aes.CreateEncryptor(); var encrypted = encryptor.TransformFinalBlock(plainBytes, 0, plainBytes.Length); // Clear plaintext bytes @@ -406,13 +438,11 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable public byte[] Decrypt(byte[] encryptedData) { if (!IsEncryptionEnabled || encryptedData == null || encryptedData.Length == 0) + { return encryptedData; + } - using var aes = System.Security.Cryptography.Aes.Create(); - aes.Key = _encryptionKey; - aes.IV = _encryptionIV; - - using var decryptor = aes.CreateDecryptor(); + using var decryptor = _aes.CreateDecryptor(); using var ms = new MemoryStream(encryptedData); using var cryptoStream = new System.Security.Cryptography.CryptoStream(ms, decryptor, System.Security.Cryptography.CryptoStreamMode.Read); using var resultStream = new MemoryStream(); @@ -464,49 +494,21 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable return sb.ToString(); } - - private async Task FlushBufferAsync(FileState state, CancellationToken token = default) - { - if (state.IsFaulted || state.BufferPosition == 0 || state.Stream == null) - return; - - try - { - await state.Stream.WriteAsync(state.Buffer, 0, state.BufferPosition, token).ConfigureAwait(false); - await state.Stream.FlushAsync(token).ConfigureAwait(false); - } - catch (Exception ex) - { - HandleWriteFailure(state, ex); - } - finally - { - // Clear buffer to prevent leaking sensitive info - Array.Clear(state.Buffer, 0, state.BufferPosition); - state.BufferPosition = 0; - } - } - - - private void HandleWriteFailure(FileState state, Exception ex) { state.IsFaulted = true; state.LastFailureUtc = DateTime.UtcNow; - // Dispose current stream state.Stream?.Dispose(); state.Stream = null; - // Determine a fallback path string originalDir = Path.GetDirectoryName(state.FilePath); - string fallbackDir = EnsureWritableDirectory(originalDir); + string fallbackDir = Directory.Exists(_fallbackPath) ? _fallbackPath : EnsureWritableDirectory(originalDir); string fileName = Path.GetFileName(state.FilePath); string fallbackFile = Path.Combine(fallbackDir, fileName); try { - // Try to reopen the stream in the fallback directory state.FilePath = fallbackFile; state.Stream = new FileStream( fallbackFile, @@ -534,8 +536,6 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable } } - - private bool TryRecover(FileState state) { if (!state.IsFaulted) @@ -560,8 +560,29 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable } catch { - state.LastFailureUtc = DateTime.UtcNow; - return false; + // Attempt fallback path if recovery fails + + try + { + string fallbackFile = Path.Combine(_fallbackPath, Path.GetFileName(state.FilePath)); + state.Stream = new FileStream(fallbackFile, FileMode.Append, + FileAccess.Write, FileShare.ReadWrite | FileShare.Delete); + state.FilePath = fallbackFile; + state.Size = GetFileSize(fallbackFile); + state.IsFaulted = false; + + OnError?.Invoke(this, new ErrorMessage + { + Message = $"Switched to fallback path: {fallbackFile}" + }); + + return true; + } + catch + { + state.LastFailureUtc = DateTime.UtcNow; + return false; + } } } @@ -622,12 +643,13 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable var dir = Path.GetDirectoryName(state.FilePath); var name = Path.GetFileNameWithoutExtension(state.FilePath); - var ext = Path.GetExtension(state.FilePath); + var ext = Path.GetExtension(state.FilePath); // ".log" + // Shift existing rolled files up 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}"); + var src = Path.Combine(dir, $"{name}_{i}{ext}"); + var dst = Path.Combine(dir, $"{name}_{i + 1}{ext}"); if (File.Exists(dst)) { File.Delete(dst); @@ -639,7 +661,8 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable } } - var rolledFile = Path.Combine(dir, $"{name}.1{ext}"); + // Move current file to _1 + var rolledFile = Path.Combine(dir, $"{name}_1{ext}"); if (File.Exists(state.FilePath)) { File.Move(state.FilePath, rolledFile); @@ -647,69 +670,21 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable OnRollOver?.Invoke(this, rolledFile); + // Create new active log file state.Size = 0; state.Stream = new FileStream(state.FilePath, FileMode.Create, FileAccess.Write, FileShare.ReadWrite | FileShare.Delete); - // Compress the oldest rolled file safely - var oldestFile = Path.Combine(dir, $"{name}.{_maxRolloverFiles}{ext}"); + // Compress the oldest file safely + var oldestFile = Path.Combine(dir, $"{name}_{_maxRolloverFiles}{ext}"); if (File.Exists(oldestFile)) { - Task.Run(() => CompressOldLogFile(oldestFile)); + _compressionQueue.Enqueue(oldestFile); } } - private static long GetFileSize(string path) => File.Exists(path) ? new FileInfo(path).Length : 0; - private void CompressOldLogFile(string filePath, int retryCount = 3) - { - if (filePath.EndsWith(".gz", StringComparison.OrdinalIgnoreCase)) - return; - - Task.Run(async () => - { - for (int attemptRetry = 1; attemptRetry <= retryCount; attemptRetry++) - { - try - { - string compressedFile; - int suffix = 0; - do - { - string suffixText = suffix == 0 ? "" : $"_{suffix}"; - compressedFile = filePath + suffixText + ".gz"; - suffix++; - } while (File.Exists(compressedFile)); - - using var originalFileStream = new FileStream(filePath, FileMode.Open, FileAccess.Read, FileShare.Read); - using var compressedFileStream = new FileStream(compressedFile, FileMode.CreateNew, FileAccess.Write); - using (var compressionStream = new System.IO.Compression.GZipStream(compressedFileStream, System.IO.Compression.CompressionLevel.Optimal)) - { - await originalFileStream.CopyToAsync(compressionStream).ConfigureAwait(false); - await compressionStream.FlushAsync().ConfigureAwait(false); - } - - File.Delete(filePath); - break; - } - catch (IOException) - { - await Task.Delay(100).ConfigureAwait(false); - } - catch (Exception ex) - { - OnError?.Invoke(this, new ErrorMessage - { - Exception = ex, - Message = $"Failed to compress log file: {filePath}" - }); - break; - } - } - }); - } - private string GetFullName(DateTime date, string category) { var datePart = date.ToString("yyyyMMdd"); @@ -767,16 +742,12 @@ public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable _files.Clear(); _messageQueues.Clear(); - try + // Wait for compression worker to finish remaining tasks + while (_compressionQueue.Count > 0) { - if (_compressionTasks.Count > 0) - { - await Task.WhenAny(Task.WhenAll(_compressionTasks), Task.Delay(TimeSpan.FromSeconds(5))); - } - } - catch - { - // Do nothing + await Task.Delay(100); } + + _aes?.Dispose(); } }