Files
EonaCat.Logger/EonaCat.Logger/EonaCatCoreLogger/FileLoggerProvider.cs
2026-02-12 22:10:13 +01:00

789 lines
23 KiB
C#

using EonaCat.Logger;
using EonaCat.Logger.EonaCatCoreLogger;
using EonaCat.Logger.EonaCatCoreLogger.Internal;
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.IO.Compression;
using System.Linq;
using System.Security.Cryptography;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
[ProviderAlias("EonaCatFileLogger")]
public sealed class FileLoggerProvider : BatchingLoggerProvider, IDisposable
{
private readonly string _path;
private readonly string _fileNamePrefix;
private readonly int _maxFileSize;
private readonly int _maxRetainedFiles;
private readonly int _maxRolloverFiles;
private readonly byte[] _encryptionKey;
private readonly byte[] _encryptionIV;
private readonly bool _isEncryptionEnabled;
public bool IsEncryptionEnabled => _encryptionKey != null && _encryptionIV != null;
private bool _disposed;
private int _isFlushing;
public static TimeSpan FaultCooldown = TimeSpan.FromSeconds(60);
private readonly ConcurrentQueue<string> _compressionQueue = new();
private readonly SemaphoreSlim _compressionSemaphore = new(1, 1);
private readonly Task _compressionWorker;
private readonly LoggerScopedContext _context = new();
private readonly ConcurrentDictionary<string, FileState> _files = new();
private readonly ConcurrentDictionary<string, ConcurrentQueue<LogMessage>> _messageQueues = new();
private const int BufferSize = 4 * 1024 * 1024; // 4 MB
private static readonly Encoding Utf8 = new UTF8Encoding(false);
private readonly SemaphoreSlim _queueSignal = new(0);
public bool IncludeCorrelationId { get; }
public bool EnableCategoryRouting { get; }
public string LogFile => _files.TryGetValue(string.Empty, out var s) ? s.FilePath : null;
public ELogType MinimumLogLevel { get; set; }
public event EventHandler<ErrorMessage> OnError;
public event EventHandler<string> OnRollOver;
private readonly Timer _flushTimer;
private readonly TimeSpan _flushInterval = TimeSpan.FromMilliseconds(100);
private readonly string _fallbackPath;
private readonly Aes _aes;
private sealed class FileState : IDisposable
{
public string FilePath;
public long Size;
public DateTime Date;
public byte[] Buffer = ArrayPool<byte>.Shared.Rent(BufferSize);
public int BufferPosition;
public FileStream Stream;
public SemaphoreSlim WriteLock = new(1, 1);
public bool IsFaulted;
public DateTime LastFailureUtc;
public void Dispose()
{
try
{
if (Buffer != null)
{
ArrayPool<byte>.Shared.Return(Buffer, clearArray: true);
Buffer = null;
}
Stream?.Dispose();
WriteLock?.Dispose();
}
catch { }
}
}
public FileLoggerProvider(IOptions<FileLoggerOptions> options) : base(options)
{
var o = options.Value ?? throw new ArgumentNullException(nameof(options));
_path = EnsureWritableDirectory(o.LogDirectory);
_fallbackPath = EnsureWritableDirectory(Path.Combine(Path.GetTempPath(), "EonaCatFallbackLogs"));
_fileNamePrefix = o.FileNamePrefix;
_maxFileSize = o.FileSizeLimit;
_maxRetainedFiles = o.RetainedFileCountLimit;
_maxRolloverFiles = o.MaxRolloverFiles;
IncludeCorrelationId = o.IncludeCorrelationId;
EnableCategoryRouting = o.EnableCategoryRouting;
MinimumLogLevel = o.MinimumLogLevel;
_encryptionKey = o.EncryptionKey;
_encryptionIV = o.EncryptionIV;
_isEncryptionEnabled = _encryptionKey != null && _encryptionIV != null;
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 string EnsureWritableDirectory(string path)
{
string fallback = Path.Combine(Path.GetTempPath(), "EonaCatFallbackLogs");
foreach (var dir in new[] { path, fallback })
{
try
{
Directory.CreateDirectory(dir);
string testFile = Path.Combine(dir, $"write_test_{Guid.NewGuid()}.tmp");
File.WriteAllText(testFile, "test");
File.Delete(testFile);
return dir;
}
catch { }
}
Directory.CreateDirectory(fallback);
return fallback;
}
private void FlushTimerCallback(object state)
{
if (_disposed)
{
return;
}
if (Interlocked.Exchange(ref _isFlushing, 1) == 1)
{
return;
}
_ = PeriodicFlushAsync().ContinueWith(_ => Interlocked.Exchange(ref _isFlushing, 0));
}
internal override Task WriteMessagesAsync(IReadOnlyList<LogMessage> messages, CancellationToken token)
{
try
{
var filtered = messages.Where(m => m.Level >= MinimumLogLevel).ToList();
if (EnableCategoryRouting)
{
var grouped = filtered.GroupBy(m => SanitizeCategory(m.Category));
foreach (var group in grouped)
{
var queue = _messageQueues.GetOrAdd(group.Key, _ => new ConcurrentQueue<LogMessage>());
foreach (var msg in group)
{
queue.Enqueue(msg);
}
}
}
else
{
var queue = _messageQueues.GetOrAdd(string.Empty, _ => new ConcurrentQueue<LogMessage>());
foreach (var msg in filtered)
{
queue.Enqueue(msg);
}
}
}
catch (Exception ex)
{
OnError?.Invoke(this, new ErrorMessage { Exception = ex, Message = $"Failed to enqueue messages: {ex.Message}" });
}
return Task.CompletedTask;
}
private async Task PeriodicFlushAsync()
{
if (_disposed)
{
return;
}
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;
}
if (!TryRecover(state))
{
// drop messages if recovery fails
while (queue.TryDequeue(out _)) { }
continue;
}
if (queue.IsEmpty)
{
continue;
}
await state.WriteLock.WaitAsync();
try
{
await FlushMessagesBatchAsync(state, queue).ConfigureAwait(false);
// If buffer has remaining data, flush it
if (state.BufferPosition > 0)
{
await FlushBufferAsync(state).ConfigureAwait(false);
}
}
finally
{
state.WriteLock.Release();
}
}
QueueOldFilesForCompression();
}
private async Task FlushMessagesBatchAsync(FileState state, ConcurrentQueue<LogMessage> queue)
{
const int maxBatch = 5000;
int batchCount = 0;
// Start with a reasonably sized buffer from the pool
int estimatedSize = 1024 * 64; // 64KB starting buffer
byte[] combined = ArrayPool<byte>.Shared.Rent(estimatedSize);
int pos = 0;
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 messageString = BuildMessage(msg);
int requiredLength = Utf8.GetByteCount(messageString);
// Grow buffer if needed
if (pos + requiredLength > combined.Length)
{
int newSize = Math.Max(combined.Length * 2, pos + requiredLength);
byte[] newBuffer = ArrayPool<byte>.Shared.Rent(newSize);
Array.Copy(combined, 0, newBuffer, 0, pos);
ArrayPool<byte>.Shared.Return(combined);
combined = newBuffer;
}
// Write directly into combined buffer
pos += Utf8.GetBytes(messageString, 0, messageString.Length, combined, pos);
batchCount++;
}
if (pos == 0)
{
ArrayPool<byte>.Shared.Return(combined);
return; // nothing to write
}
// If encryption is enabled, encrypt into a new array
byte[] dataToWrite;
if (_isEncryptionEnabled)
{
dataToWrite = Encrypt(combined.AsSpan(0, pos).ToArray());
}
else
{
// No encryption: just use the pooled buffer slice directly
dataToWrite = combined;
}
// Flush buffer if needed
if (state.BufferPosition + pos > BufferSize)
{
await FlushBufferAsync(state).ConfigureAwait(false);
}
// Rollover if file exceeds max size
if (_maxFileSize > 0 && state.Size + pos > _maxFileSize)
{
await FlushBufferAsync(state).ConfigureAwait(false);
RollOverAndCompressOldest(state, string.Empty);
}
// Copy directly into the file buffer
Array.Copy(dataToWrite, 0, state.Buffer, state.BufferPosition, pos);
state.BufferPosition += pos;
state.Size += pos;
// Clear sensitive data
Array.Clear(dataToWrite, 0, pos);
// Return buffer if unencrypted
if (!_isEncryptionEnabled)
{
ArrayPool<byte>.Shared.Return(dataToWrite);
}
}
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 f in files)
{
EnqueueCompression(f.FullName);
}
}
private void EnqueueCompression(string file)
{
_compressionQueue.Enqueue(file);
_queueSignal.Release();
}
private async Task CompressionWorkerAsync()
{
while (!_disposed)
{
await _queueSignal.WaitAsync();
if (_compressionQueue.TryDequeue(out var filePath))
{
await _compressionSemaphore.WaitAsync();
try
{
await CompressOldLogFileAsync(filePath);
}
finally
{
_compressionSemaphore.Release();
}
}
}
}
private async Task CompressOldLogFileAsync(string filePath, int retryCount = 3)
{
if (!File.Exists(filePath) || filePath.EndsWith(".gz", StringComparison.OrdinalIgnoreCase))
{
return;
}
var dir = Path.GetDirectoryName(filePath);
var name = Path.GetFileNameWithoutExtension(filePath); // "app_20260212_1"
var ext = Path.GetExtension(filePath); // ".log"
// Determine the next _N.log.gz name
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++)
{
try
{
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.Optimal);
await original.CopyToAsync(gzip).ConfigureAwait(false);
await gzip.FlushAsync().ConfigureAwait(false);
File.Delete(filePath);
return; // success
}
catch (IOException)
{
// File busy? Wait a bit and retry
await Task.Delay(200);
}
catch (Exception ex)
{
OnError?.Invoke(this, new ErrorMessage
{
Exception = ex,
Message = $"Failed to compress log file: {filePath}"
});
return;
}
}
}
private byte[] Encrypt(byte[] plainBytes)
{
if (plainBytes == null || plainBytes.Length == 0)
{
return plainBytes;
}
using var encryptor = _aes.CreateEncryptor();
var encrypted = encryptor.TransformFinalBlock(plainBytes, 0, plainBytes.Length);
// Clear plaintext bytes
Array.Clear(plainBytes, 0, plainBytes.Length);
return encrypted;
}
public byte[] Decrypt(byte[] encryptedData)
{
if (!IsEncryptionEnabled || encryptedData == null || encryptedData.Length == 0)
{
return encryptedData;
}
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();
cryptoStream.CopyTo(resultStream);
var result = resultStream.ToArray();
// Clear sensitive memory
Array.Clear(encryptedData, 0, encryptedData.Length);
return result;
}
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 + 64);
sb.Append(msg.Message).Append(" [");
foreach (var (key, value) in ctx.Select(kv => (kv.Key, kv.Value)))
{
sb.Append(key).Append('=').Append(value).Append(' ');
}
if (msg.Tags != null)
{
foreach (var tag in msg.Tags)
{
sb.Append("tag=").Append(tag).Append(' ');
}
}
if (sb[sb.Length - 1] == ' ')
{
sb.Length--; // remove trailing space
}
sb.Append(']').AppendLine();
return sb.ToString();
}
private void HandleWriteFailure(FileState state, Exception ex)
{
state.IsFaulted = true;
state.LastFailureUtc = DateTime.UtcNow;
state.Stream?.Dispose();
state.Stream = null;
string originalDir = Path.GetDirectoryName(state.FilePath);
string fallbackDir = Directory.Exists(_fallbackPath) ? _fallbackPath : EnsureWritableDirectory(originalDir);
string fileName = Path.GetFileName(state.FilePath);
string fallbackFile = Path.Combine(fallbackDir, fileName);
try
{
state.FilePath = fallbackFile;
state.Stream = new FileStream(
fallbackFile,
FileMode.Append,
FileAccess.Write,
FileShare.ReadWrite | FileShare.Delete
);
state.Size = GetFileSize(fallbackFile);
state.IsFaulted = false;
OnError?.Invoke(this, new ErrorMessage
{
Exception = ex,
Message = $"Logging failed for original path. Switching to fallback path: {fallbackFile}"
});
}
catch (Exception fallbackEx)
{
OnError?.Invoke(this, new ErrorMessage
{
Exception = fallbackEx,
Message = $"Failed to recover logging using fallback path: {fallbackFile}"
});
}
}
private bool TryRecover(FileState state)
{
if (!state.IsFaulted)
{
return true;
}
if (DateTime.UtcNow - state.LastFailureUtc < FaultCooldown)
{
return false;
}
try
{
state.Stream = new FileStream(state.FilePath, FileMode.Append,
FileAccess.Write, FileShare.ReadWrite | FileShare.Delete);
state.Size = GetFileSize(state.FilePath);
state.IsFaulted = false;
return true;
}
catch
{
// 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;
}
}
}
private FileState CreateFileState(DateTime date, string category)
{
// Get the intended log file path
var intendedPath = GetFullName(date, category);
// Ensure directory is writable (falls back automatically if needed)
var writableDir = EnsureWritableDirectory(Path.GetDirectoryName(intendedPath));
var path = Path.Combine(writableDir, Path.GetFileName(intendedPath));
try
{
return new FileState
{
FilePath = path,
Date = date,
Size = GetFileSize(path),
Stream = new FileStream(
path,
FileMode.Append,
FileAccess.Write,
FileShare.ReadWrite | FileShare.Delete
)
};
}
catch (Exception ex)
{
OnError?.Invoke(this, new ErrorMessage
{
Exception = ex,
Message = $"Failed to create log file: {path}"
});
return new FileState
{
FilePath = path,
Date = date,
IsFaulted = true
};
}
}
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.Stream = new FileStream(state.FilePath, FileMode.Append,
FileAccess.Write, FileShare.ReadWrite | FileShare.Delete);
}
private void RollOverAndCompressOldest(FileState state, string category)
{
state.Stream?.Dispose();
var dir = Path.GetDirectoryName(state.FilePath);
var name = Path.GetFileNameWithoutExtension(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}");
if (File.Exists(dst))
{
File.Delete(dst);
}
if (File.Exists(src))
{
File.Move(src, dst);
}
}
// Move current file to _1
var rolledFile = Path.Combine(dir, $"{name}_1{ext}");
if (File.Exists(state.FilePath))
{
File.Move(state.FilePath, rolledFile);
}
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 file safely
var oldestFile = Path.Combine(dir, $"{name}_{_maxRolloverFiles}{ext}");
if (File.Exists(oldestFile))
{
EnqueueCompression(oldestFile);
}
}
private static long GetFileSize(string path)
=> File.Exists(path) ? new FileInfo(path).Length : 0;
private string GetFullName(DateTime date, string category)
{
var datePart = date.ToString("yyyyMMdd");
var machine = Environment.MachineName;
if (!EnableCategoryRouting || string.IsNullOrWhiteSpace(category))
{
return Path.Combine(_path, $"{_fileNamePrefix}_{machine}_{datePart}.log");
}
var safeCategory = SanitizeCategory(category);
return Path.Combine(_path, $"{_fileNamePrefix}_{machine}_{safeCategory}_{datePart}.log");
}
private static string SanitizeCategory(string category)
{
foreach (var c in Path.GetInvalidFileNameChars())
{
category = category.Replace(c, '_');
}
return category.Replace('.', '_');
}
protected override async Task OnShutdownFlushAsync()
{
_disposed = true;
_flushTimer?.Dispose();
using var cts = new CancellationTokenSource(TimeSpan.FromSeconds(5));
try
{
await PeriodicFlushAsync().ConfigureAwait(false);
}
catch
{
// Do nothing
}
foreach (var state in _files.Values)
{
try
{
await FlushBufferAsync(state, cts.Token).ConfigureAwait(false);
}
catch
{
// Do nothing
}
state.Dispose();
}
_files.Clear();
_messageQueues.Clear();
// Wait for compression worker to finish remaining tasks
while (_compressionQueue.Count > 0)
{
await Task.Delay(100);
}
_aes?.Dispose();
}
}