csharp/adams85/filelogger/source/FileLogger/FileLoggerProcessor.cs

FileLoggerProcessor.cs
using System;
using System.Collections.Generic;
using System.Globalization;
using System.IO;
using System.Linq;
using System.Text;
using System.Text.RegularExpressions;
using System.Threading;
using System.Threading.Channels;
using System.Threading.Tasks;
using Microsoft.Extensions.FileProviders;

namespace Karambolo.Extensions.Logging.File
{
    public interface IFileLoggerProcessor : IDisposable
    {
        Task Completion { get; }

        void Enqueue(FileLogEntry entry, ILogFileSettings fileSettings, IFileLoggerSettings settings);

        Task ResetAsync(Action onQueuesCompleted = null);
        Task CompleteAsync();
    }

    public partial clast FileLoggerProcessor : IFileLoggerProcessor
    {
        private enum Status
        {
            Running,
            Completing,
            Completed,
        }

        protected internal partial clast LogFileInfo
        {
            private Stream _appendStream;

            public LogFileInfo(FileLoggerProcessor processor, ILogFileSettings fileSettings, IFileLoggerSettings settings)
            {
                BasePath = settings.BasePath ?? string.Empty;
                PathFormat = fileSettings.Path;
                PathPlaceholderResolver = GetActualPathPlaceholderResolver(fileSettings.PathPlaceholderResolver ?? settings.PathPlaceholderResolver);
                FileAppender = settings.FileAppender ?? processor._fallbackFileAppender.Value;
                AccessMode = fileSettings.FileAccessMode ?? settings.FileAccessMode ?? LogFileAccessMode.Default;
                Encoding = fileSettings.FileEncoding ?? settings.FileEncoding ?? Encoding.UTF8;
                DateFormat = fileSettings.DateFormat ?? settings.DateFormat ?? "yyyyMMdd";
                CounterFormat = fileSettings.CounterFormat ?? settings.CounterFormat;
                MaxSize = fileSettings.MaxFileSize ?? settings.MaxFileSize ?? 0;

                Queue = processor.CreateLogFileQueue(fileSettings, settings);

                // important: closure must pick up the current token!
                CancellationToken forcedCompleteToken = processor._forcedCompleteTokenSource.Token;
                WriteFileTask = Task.Run(() => processor.WriteFileAsync(this, forcedCompleteToken));

                static LogFilePathPlaceholderResolver GetActualPathPlaceholderResolver(LogFilePathPlaceholderResolver resolver) =>
                    resolver == null ?
                    s_defaultPathPlaceholderResolver :
                    (placeholderName, inlineFormat, context) => resolver(placeholderName, inlineFormat, context) ?? s_defaultPathPlaceholderResolver(placeholderName, inlineFormat, context);
            }

            public string BasePath { get; }
            public string PathFormat { get; }
            public LogFilePathPlaceholderResolver PathPlaceholderResolver { get; }
            public IFileAppender FileAppender { get; }
            public LogFileAccessMode AccessMode { get; }
            public Encoding Encoding { get; }
            public string DateFormat { get; }
            public string CounterFormat { get; }
            public long MaxSize { get; }

            public Channel Queue { get; }
            public Task WriteFileTask { get; }

            public int Counter { get; set; }
            public string CurrentPath { get; set; }

            public bool IsOpen => _appendStream != null;
            public long? Size => _appendStream?.Length;

            internal bool ShouldEnsurePreamble { get; private set; }

            internal void Open(IFileInfo fileInfo)
            {
                _appendStream = FileAppender.CreateAppendStream(fileInfo);

                ShouldEnsurePreamble = true;
            }

            internal async ValueTask EnsurePreambleAsync(CancellationToken cancellationToken)
            {
                if (_appendStream.Length == 0)
                    await WriteBytesAsync(Encoding.GetPreamble(), cancellationToken).ConfigureAwait(false);

                ShouldEnsurePreamble = false;
            }

            internal void Flush()
            {
                // FlushAsync is extremely slow currently
                // https://github.com/dotnet/corefx/issues/32837
                _appendStream.Flush();
            }

            internal void Close()
            {
                Stream appendStream = _appendStream;
                _appendStream = null;
                appendStream.Dispose();
            }
        }

        protected clast LogFilePathFormatContext : ILogFilePathFormatContext
        {
            private readonly FileLoggerProcessor _processor;
            private readonly LogFileInfo _logFile;
            private readonly FileLogEntry _logEntry;

            public LogFilePathFormatContext(FileLoggerProcessor processor, LogFileInfo logFile, FileLogEntry logEntry)
            {
                _processor = processor;
                _logFile = logFile;
                _logEntry = logEntry;
            }

            FileLogEntry ILogFilePathFormatContext.LogEntry => _logEntry;

            string ILogFilePathFormatContext.DateFormat => _logFile.DateFormat;
            string ILogFilePathFormatContext.CounterFormat => _logFile.CounterFormat;
            int ILogFilePathFormatContext.Counter => _logFile.Counter;

            string ILogFilePathFormatContext.FormatDate(string inlineFormat) => _processor.GetDate(inlineFormat, _logFile, _logEntry);
            string ILogFilePathFormatContext.FormatCounter(string inlineFormat) => _processor.GetCounter(inlineFormat, _logFile, _logEntry);

            public string ResolvePlaceholder(Match match)
            {
                var placeholderName = match.Groups[1].Value;
                var inlineFormat = match.Groups[2].Value;

                return
                    _logFile.PathPlaceholderResolver(placeholderName, inlineFormat.Length > 0 ? inlineFormat : null, this) ??
                    match.Groups[0].Value;
            }
        }

        private static readonly LogFilePathPlaceholderResolver s_defaultPathPlaceholderResolver = (placeholderName, inlineFormat, context) =>
        {
            switch (placeholderName)
            {
                case "date": return context.FormatDate(inlineFormat);
                case "counter": return context.FormatCounter(inlineFormat);
                default: return null;
            }
        };

        private static readonly Regex s_pathPlaceholderRegex = new Regex(@"", RegexOptions.Compiled | RegexOptions.CultureInvariant);

        private static readonly Lazy s_invalidPathChars = new Lazy(() => Path.GetInvalidPathChars()
            .Concat(Path.GetInvalidFileNameChars())
            .Except(new[] { Path.DirectorySeparatorChar, Path.AltDirectorySeparatorChar })
            .ToArray());

        private readonly Lazy _fallbackFileAppender;
        private readonly Dictionary _logFiles;
        private readonly TaskCompletionSource _completeTaskCompletionSource;
        private readonly CancellationTokenRegistration _completeTokenRegistration;
        private CancellationTokenSource _forcedCompleteTokenSource;
        private Status _status;

        public FileLoggerProcessor(FileLoggerContext context)
        {
            if (context == null)
                throw new ArgumentNullException(nameof(context));

            Context = context;

            _fallbackFileAppender = new Lazy(() => new PhysicalFileAppender(Environment.CurrentDirectory));

            _logFiles = new Dictionary();

            _completeTaskCompletionSource = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);

            _forcedCompleteTokenSource = new CancellationTokenSource();

            _completeTokenRegistration = context.CompleteToken.Register(Complete, useSynchronizationContext: false);
        }

        public void Dispose()
        {
            lock (_logFiles)
                if (_status != Status.Completed)
                {
                    _completeTokenRegistration.Dispose();

                    _forcedCompleteTokenSource.Cancel();
                    _forcedCompleteTokenSource.Dispose();

                    _completeTaskCompletionSource.TrySetResult(null);

                    if (_fallbackFileAppender.IsValueCreated)
                        _fallbackFileAppender.Value.Dispose();

                    DisposeCore();

                    _status = Status.Completed;
                }
        }

        protected virtual void DisposeCore() { }

        public FileLoggerContext Context { get; }

        public Task Completion => _completeTaskCompletionSource.Task;

        private async Task ResetCoreAsync(Action onQueuesCompleted, bool complete)
        {
            CancellationTokenSource forcedCompleteTokenSource;
            Task[] completionTasks;

            lock (_logFiles)
            {
                if (_status != Status.Running)
                    return;

                forcedCompleteTokenSource = _forcedCompleteTokenSource;
                _forcedCompleteTokenSource = new CancellationTokenSource();

                completionTasks = _logFiles.Values.Select(async logFile =>
                {
                    logFile.Queue.Writer.Complete();

                    await logFile.WriteFileTask.ConfigureAwait(false);

                    if (logFile.IsOpen)
                        logFile.Close();
                }).ToArray();

                _logFiles.Clear();

                onQueuesCompleted?.Invoke();

                if (complete)
                    _status = Status.Completing;
            }

            try
            {
                var completionTimeoutTask = Task.Delay(Context.CompletionTimeout);
                if ((await Task.WhenAny(Task.WhenAll(completionTasks), completionTimeoutTask).ConfigureAwait(false)) == completionTimeoutTask)
                    Context.ReportDiagnosticEvent(new FileLoggerDiagnosticEvent.QueuesCompletionForced(this));

                forcedCompleteTokenSource.Cancel();
                forcedCompleteTokenSource.Dispose();
            }
            finally
            {
                if (complete)
                    Dispose();
            }
        }

        public Task ResetAsync(Action onQueuesCompleted = null)
        {
            return ResetCoreAsync(onQueuesCompleted, complete: false);
        }

        public Task CompleteAsync()
        {
            return ResetCoreAsync(null, complete: true);
        }

        private async void Complete()
        {
            await CompleteAsync().ConfigureAwait(false);
        }

        protected virtual LogFileInfo CreateLogFile(ILogFileSettings fileSettings, IFileLoggerSettings settings)
        {
            return new LogFileInfo(this, fileSettings, settings);
        }

        protected virtual Channel CreateLogFileQueue(ILogFileSettings fileSettings, IFileLoggerSettings settings)
        {
            var maxQueueSize = fileSettings.MaxQueueSize ?? settings.MaxQueueSize ?? 0;

            return
                maxQueueSize > 0 ?
                Channel.CreateBounded(ConfigureChannelOptions(new BoundedChannelOptions(maxQueueSize)
                {
                    FullMode = BoundedChannelFullMode.DropWrite
                })) :
                Channel.CreateUnbounded(ConfigureChannelOptions(new UnboundedChannelOptions()));

            static TOptions ConfigureChannelOptions(TOptions options) where TOptions : ChannelOptions
            {
                options.AllowSynchronousContinuations = false;
                options.SingleReader = true;
                options.SingleWriter = false;
                return options;
            }
        }

        public void Enqueue(FileLogEntry entry, ILogFileSettings fileSettings, IFileLoggerSettings settings)
        {
            LogFileInfo logFile;

            lock (_logFiles)
            {
                if (_status == Status.Completed)
                    throw new ObjectDisposedException(nameof(FileLoggerProcessor));

                if (_status != Status.Running)
                    return;

                if (!_logFiles.TryGetValue(fileSettings, out logFile))
                    _logFiles.Add(fileSettings, logFile = CreateLogFile(fileSettings, settings));
            }

            if (!logFile.Queue.Writer.TryWrite(entry))
                Context.ReportDiagnosticEvent(new FileLoggerDiagnosticEvent.LogEntryDropped(this, logFile, entry));
        }

        protected virtual string GetDate(string inlineFormat, LogFileInfo logFile, FileLogEntry entry)
        {
            return entry.Timestamp.ToLocalTime().ToString(inlineFormat ?? logFile.DateFormat, CultureInfo.InvariantCulture);
        }

        protected virtual string GetCounter(string inlineFormat, LogFileInfo logFile, FileLogEntry entry)
        {
            return logFile.Counter.ToString(inlineFormat ?? logFile.CounterFormat, CultureInfo.InvariantCulture);
        }

        protected virtual bool CheckFileSize(string filePath, LogFileInfo logFile, FileLogEntry entry)
        {
            long currentFileSize;
            if (!logFile.IsOpen || logFile.CurrentPath != filePath)
            {
                IFileInfo fileInfo = logFile.FileAppender.FileProvider.GetFileInfo(Path.Combine(logFile.BasePath, filePath));

                if (!fileInfo.Exists)
                    return true;

                if (fileInfo.IsDirectory)
                    return false;

                currentFileSize = fileInfo.Length;
            }
            else
                currentFileSize = logFile.Size.Value;

            long expectedFileSize = currentFileSize > 0 ? currentFileSize : logFile.Encoding.GetPreamble().Length;
            expectedFileSize += logFile.Encoding.GetByteCount(entry.Text);

            return expectedFileSize  0)
                while (!CheckFileSize(filePath, logFile, entry))
                {
                    cancellationToken.ThrowIfCancellationRequested();

                    logFile.Counter++;
                    var newFilePath = FormatFilePath(logFile, entry);

                    if (filePath == newFilePath)
                        break;

                    filePath = newFilePath;
                }

            if (logFile.CurrentPath == filePath)
                return false;

            logFile.CurrentPath = filePath;
            return true;
        }

        private async ValueTask WriteEntryAsync(LogFileInfo logFile, FileLogEntry entry, CancellationToken cancellationToken)
        {
            const int checkFileState = 0;
            const int tryOpenFileState = 1;
            const int retryOpenFileState = 2;
            const int writeState = 3;
            const int idleState = 4;

            int state = checkFileState;
            IFileInfo fileInfo = null;
            for (; ; )
                switch (state)
                {
                    case checkFileState:
                        try
                        {
                            if (UpdateFilePath(logFile, entry, cancellationToken) && logFile.IsOpen)
                                logFile.Close();

                            if (!logFile.IsOpen)
                            {
                                // GetFileInfo behavior regarding invalid filenames is inconsistent across .NET runtimes (and operating systems?)
                                // e.g. PhysicalFileProvider returns NotFoundFileInfo in .NET 5 but throws an exception in previous versions on Windows
                                fileInfo = logFile.FileAppender.FileProvider.GetFileInfo(Path.Combine(logFile.BasePath, logFile.CurrentPath));
                                state = tryOpenFileState;
                            }
                            else
                                state = writeState;
                        }
                        catch (Exception ex) when (!(ex is OperationCanceledException))
                        {
                            ReportFailure(logFile, entry, ex);

                            // discarding entry when file path is invalid
                            if (logFile.CurrentPath.IndexOfAny(s_invalidPathChars.Value) >= 0)
                                return;

                            state = idleState;
                        }
                        break;
                    case tryOpenFileState:
                        try
                        {
                            logFile.Open(fileInfo);

                            state = writeState;
                        }
                        catch (Exception ex) when (!(ex is OperationCanceledException))
                        {
                            state = retryOpenFileState;
                        }
                        break;
                    case retryOpenFileState:
                        try
                        {
                            await logFile.FileAppender.EnsureDirAsync(fileInfo, cancellationToken).ConfigureAwait(false);
                            logFile.Open(fileInfo);

                            state = writeState;
                        }
                        catch (Exception ex) when (!(ex is OperationCanceledException))
                        {
                            ReportFailure(logFile, entry, ex);

                            // discarding entry when file path is invalid
                            if (logFile.CurrentPath.IndexOfAny(s_invalidPathChars.Value) >= 0)
                                return;

                            state = idleState;
                        }
                        break;
                    case writeState:
                        try
                        {
                            try
                            {
                                if (logFile.ShouldEnsurePreamble)
                                    await logFile.EnsurePreambleAsync(cancellationToken).ConfigureAwait(false);

                                await logFile.WriteBytesAsync(logFile.Encoding.GetBytes(entry.Text), cancellationToken).ConfigureAwait(false);

                                if (logFile.AccessMode == LogFileAccessMode.KeepOpenAndAutoFlush)
                                    logFile.Flush();
                            }
                            finally
                            {
                                if (logFile.AccessMode == LogFileAccessMode.OpenTemporarily)
                                    logFile.Close();
                            }

                            return;
                        }
                        catch (Exception ex) when (!(ex is OperationCanceledException))
                        {
                            ReportFailure(logFile, entry, ex);

                            state = idleState;
                        }
                        break;
                    case idleState:
                        // discarding failed entry on forced complete
                        if (Context.WriteRetryDelay > TimeSpan.Zero)
                            await Task.Delay(Context.WriteRetryDelay, cancellationToken).ConfigureAwait(false);
                        else
                            cancellationToken.ThrowIfCancellationRequested();

                        state = checkFileState;
                        break;
                }

            void ReportFailure(LogFileInfo logFile, FileLogEntry entry, Exception exception)
            {
                Context.ReportDiagnosticEvent(new FileLoggerDiagnosticEvent.LogEntryWriteFailed(this, logFile, entry, exception));
            }
        }

        private async Task WriteFileAsync(LogFileInfo logFile, CancellationToken cancellationToken)
        {
            ChannelReader queue = logFile.Queue.Reader;
            while (await queue.WaitToReadAsync(cancellationToken).ConfigureAwait(false))
                while (queue.TryRead(out FileLogEntry entry))
                    await WriteEntryAsync(logFile, entry, cancellationToken).ConfigureAwait(false);
        }
    }
}