< Summary

Information
Class: AmbientServices.AmbientFileLogger
Assembly: AmbientServices
File(s): /home/runner/work/AmbientServices/AmbientServices/AmbientServices/AlternateImplementations/AmbientFileLogger.cs
Tag: 332_35464845198
Line coverage
96%
Covered lines: 79
Uncovered lines: 3
Coverable lines: 82
Total lines: 495
Line coverage: 96.3%
Branch coverage
83%
Covered branches: 45
Total branches: 54
Branch coverage: 83.3%
Method coverage

Feature is only available for sponsors

Upgrade to PRO version

Metrics

MethodBranch coverage Crap Score Cyclomatic complexity Line coverage
.ctor()100%11100%
.ctor(...)100%1414100%
GetExecutableName()37.5%8888.89%
GetExecutableNameAppDomainFallback()100%11100%
CombineRelativeFilePrefixWithProgramData(...)100%11100%
LinuxLocalShareDataFolderPath(...)100%11100%
EnsureDirectoryExists(...)100%22100%
EnsureLinuxLocalShareFolderExists(...)100%11100%
CompleteProgramDataFolderPath(...)100%44100%
GetProgramDataFolderLocation()100%11100%
GetProgramDataFolderLocationInternal()100%11100%
Log(...)100%11100%
Log(...)62.5%8890.91%
Flush(...)100%22100%
GetPeriodNumber(...)100%11100%
PeriodString(...)100%11100%
GetLogFileName(...)100%11100%
TryDeleteAllFiles(...)91.67%121290%
Dispose(...)100%44100%
Dispose()100%11100%

File(s)

/home/runner/work/AmbientServices/AmbientServices/AmbientServices/AlternateImplementations/AmbientFileLogger.cs

#LineLine coverage
 1using AmbientServices.Utilities;
 2using System;
 3using System.Collections.Concurrent;
 4using System.IO;
 5using System.Runtime.InteropServices;
 6using System.Threading;
 7using System.Threading.Tasks;
 8
 9namespace AmbientServices;
 10
 11/// <summary>
 12/// A basic implementation of <see cref="IAmbientLogger"/> that writes log messages to a rotating set of files.
 13/// Turn the logger off for maximum performance.
 14/// </summary>
 15/// <remarks>
 16/// <pitch>Durable, rotating on-disk logs that survive a process restart — the logger to use when you need to diagnose i
 17/// <pledge><see cref="IAmbientLogger"/></pledge>
 18/// <pledge><see cref="IAmbientStructuredLogger"/></pledge>
 19/// <pledge><see cref="IDisposable"/></pledge>
 20/// <pledge>
 21/// Log files are named by a path/filename prefix plus a four-digit rotation-period suffix plus an extension.  The prefi
 22/// Logging buffers in memory and performs no file I/O on the logging call; buffered entries reach disk when a rotation 
 23/// </pledge>
 24/// <plan>
 25/// All buffering and file I/O is delegated to an internal <see cref="RotatingFileBuffer"/>, which queues lines and in-b
 26/// Rotation reuses filenames day over day: opening a period's file truncates any previous day's content for that same p
 27/// </plan>
 28/// <priority>
 29/// <see cref="IAmbientLogger"/>
 30/// 1. Durability over aggregate logging cost: this realization exists so the data is on disk afterwards, so it is allow
 31/// 2. Bounded disk use over retained history: reusing period filenames day over day and truncating the previous day's c
 32/// </priority>
 33/// </remarks>
 34public class AmbientFileLogger : IAmbientLogger, IAmbientStructuredLogger, IDisposable
 35{
 36    private readonly string _fileExtension;
 37    private readonly int _rotationPeriodMinutes;
 38    private readonly RotatingFileBuffer _fileBuffers;
 39    private int _periodNumber;                      // interlocked
 40    private bool _disposedValue;                    // too small to need interlocking
 41
 42    /// <summary>
 43    /// Constructs a default ambient file logger that writes files that start with a default prefix.
 44    /// </summary>
 245    public AmbientFileLogger() : this(null)
 46    {
 247    }
 48    /// <summary>
 49    /// Constructs an ambient file logger that writes files that start with the specified prefix.
 50    /// </summary>
 51    /// <param name="filePrefix">
 52    /// The path and filename prefix to use for the log files.
 53    /// If not specified, the executing process's ProcessName or the application domain's friendly name will be used as 
 54    /// If specified without a full path, on windows the local application data folder on windows will be used as the pa
 55    /// </param>
 56    /// <param name="fileExtension">The file extension (with leading .) to use for the files.  Defaults to ".log".</para
 57    /// <param name="rotationPeriodMinutes">The number of minutes after which a new file should be used.  Suffixes will 
 58    /// <param name="autoFlushSeconds">The number of seconds between automatic flushes of the log file.  Zero or negativ
 259    public AmbientFileLogger(string? filePrefix, string? fileExtension = null, int rotationPeriodMinutes = 60, int autoF
 60    {
 61        // file prefix not specified?
 62        // use a default path that uses the executable name
 263        filePrefix ??= GetExecutableName();
 64        // else if we have a file prefix, but it doesn't have a directory, use the program data location
 265        if (string.IsNullOrEmpty(Path.GetDirectoryName(filePrefix)))
 66        {
 267            filePrefix = CombineRelativeFilePrefixWithProgramData(filePrefix, GetProgramDataFolderLocation, GetExecutabl
 68        }
 269        fileExtension ??= ".log";
 270        if (fileExtension.Length > 0 && fileExtension[0] != '.') fileExtension = "." + fileExtension;
 271        FilePrefix = filePrefix;
 272        _fileExtension = fileExtension;
 273        _rotationPeriodMinutes = rotationPeriodMinutes;
 74        // which period number within the day are we in right now?
 275        _periodNumber = GetPeriodNumber(AmbientClock.UtcNow);
 76        // use that for the starting suffix
 277        string startingSuffix = PeriodString(_periodNumber);
 278        _fileBuffers = new RotatingFileBuffer(filePrefix, startingSuffix + _fileExtension, TimeSpan.FromSeconds(autoFlus
 279    }
 80    internal static string GetExecutableName()
 81    {
 282        if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows)
 283            || RuntimeInformation.IsOSPlatform(OSPlatform.Linux)
 284            || RuntimeInformation.IsOSPlatform(OSPlatform.OSX)
 285#if NETCOREAPP3_1_OR_GREATER || NET5_0_OR_GREATER
 286            || RuntimeInformation.IsOSPlatform(OSPlatform.FreeBSD)
 287#endif
 288            )
 89        {
 290            return System.Diagnostics.Process.GetCurrentProcess().ProcessName;
 91        }
 092        return GetExecutableNameAppDomainFallback();
 93    }
 94
 95    /// <summary>
 96    /// Returns <see cref="AppDomain.CurrentDomain"/>'s friendly name (used when the OS is not Windows, Linux, macOS, or
 97    /// </summary>
 298    internal static string GetExecutableNameAppDomainFallback() => AppDomain.CurrentDomain.FriendlyName;
 99
 100    /// <summary>
 101    /// Combines a filename-only prefix with the program data folder, or falls back to a temp-path prefix when <see cref
 102    /// </summary>
 103    internal static string CombineRelativeFilePrefixWithProgramData(string filePrefix, Func<string> getProgramDataFolder
 104    {
 105        try
 106        {
 2107            return Path.Combine(getProgramDataFolderLocation(), filePrefix);
 108        }
 2109        catch
 110        {
 2111            return $"{Path.GetTempPath()}{getExecutableName()}_AmbientLogger";
 112        }
 2113    }
 114
 115    /// <summary>
 116    /// Linux fallback when <see cref="Environment.SpecialFolder.LocalApplicationData"/> is empty (exposed for unit test
 117    /// </summary>
 118    internal static string LinuxLocalShareDataFolderPath(string userName) =>
 2119        $"/home/{userName}/.local/share";
 120
 121    /// <summary>
 122    /// Creates <paramref name="folderPath"/> when missing (exposed for unit tests; used from Linux fallback).
 123    /// </summary>
 124    internal static void EnsureDirectoryExists(string folderPath)
 125    {
 2126        if (!Directory.Exists(folderPath)) Directory.CreateDirectory(folderPath);
 2127    }
 128
 129    /// <summary>
 130    /// Ensures the Linux per-user share folder exists and returns its path (same logic as the Linux branch of <see cref
 131    /// </summary>
 132    internal static string EnsureLinuxLocalShareFolderExists(string userName)
 133    {
 2134        string folderPath = LinuxLocalShareDataFolderPath(userName);
 2135        EnsureDirectoryExists(folderPath);
 2136        return folderPath;
 137    }
 138
 139    /// <summary>
 140    /// When <paramref name="useLinuxEmptyLocalAppDataFallback"/> is true and <paramref name="localApplicationDataPath"/
 141    /// </summary>
 142    internal static string CompleteProgramDataFolderPath(string localApplicationDataPath, bool useLinuxEmptyLocalAppData
 143    {
 2144        if (!useLinuxEmptyLocalAppDataFallback || !string.IsNullOrEmpty(localApplicationDataPath))
 145        {
 2146            return localApplicationDataPath;
 147        }
 2148        return EnsureLinuxLocalShareFolderExists(Environment.UserName);
 149    }
 150
 151    private static string GetProgramDataFolderLocation()
 152    {
 2153        string path = Environment.GetFolderPath(Environment.SpecialFolder.LocalApplicationData);
 2154        path = CompleteProgramDataFolderPath(path, RuntimeInformation.IsOSPlatform(OSPlatform.Linux));
 2155        return path + Path.DirectorySeparatorChar;
 156    }
 157
 158    /// <summary>
 159    /// Exposes <see cref="GetProgramDataFolderLocation"/> for overflow log path construction (internal use).
 160    /// </summary>
 2161    internal static string GetProgramDataFolderLocationInternal() => GetProgramDataFolderLocation();
 162    /// <summary>
 163    /// Gets the file prefix.
 164    /// </summary>
 165    public string FilePrefix { get; }
 166    /// <summary>
 167    /// Buffers the specified structured data to be asynchronously logged.
 168    /// </summary>
 169    /// <param name="structuredData">The structured data object.</param>
 170    public void Log(object structuredData)
 171    {
 172#if NET5_0_OR_GREATER
 2173        ArgumentNullException.ThrowIfNull(structuredData);
 174#else
 175    if (structuredData is null) throw new ArgumentNullException(nameof(structuredData));
 176#endif
 2177        string message = AmbientLogger.ConvertStructuredDataIntoSimpleMessage(structuredData);
 2178        Log(message);
 2179    }
 180    /// <summary>
 181    /// Buffers the specified message to be asynchronously logged.
 182    /// </summary>
 183    /// <param name="message">The message to log.</param>
 184    public void Log(string message)
 185    {
 186        // which period number within the day are we in right now?
 2187        TimeSpan timeOfDay = AmbientClock.UtcNow.TimeOfDay;
 2188        int newPeriodNumber = (int)(timeOfDay.TotalMinutes / _rotationPeriodMinutes);
 189
 2190        int attempt = 0;
 191        // loop attempting to update the period number if we need to or until we win the race or timeout
 192        while (true)
 193        {
 194            // get the latest value
 2195            int oldValue = _periodNumber;
 196            // someone beat us to it?
 2197            if (newPeriodNumber == oldValue) break;
 198            // try to put in our value--did we win the race?
 2199            if (oldValue == Interlocked.CompareExchange(ref _periodNumber, newPeriodNumber, oldValue))
 200            {
 201                // we won the race to update the period number
 2202                _fileBuffers.BufferFileRotation(PeriodString(newPeriodNumber) + _fileExtension);
 2203                break;
 204            }
 205            // note that it's very difficult to test a miss here--you really have to pound it with multiple threads, so 
 0206            if (!InterlockedUtilities.TryAgainAfterOptimisticMissDelay(attempt++)) break;
 207        }
 2208        if (!_disposedValue) _fileBuffers.BufferLine(message);
 2209    }
 210    /// <summary>
 211    /// Flushes everything that has been previously logged to the appropriate file on disk.
 212    /// </summary>
 213    /// <param name="cancel">A <see cref="CancellationToken"/> to cancel the operation before it finishes.</param>
 214    public ValueTask Flush(CancellationToken cancel = default)
 215    {
 2216        return _disposedValue ? default : _fileBuffers.Flush(cancel);
 217    }
 218    private int GetPeriodNumber(DateTime dateTime)
 219    {
 220        // which period number within the day are we in right now?
 2221        TimeSpan timeOfDay = dateTime.TimeOfDay;
 2222        return (int)(timeOfDay.TotalMinutes / _rotationPeriodMinutes);
 223    }
 224    private static string PeriodString(int periodNumber)
 225    {
 2226        return periodNumber.ToString("D4", System.Globalization.CultureInfo.InvariantCulture);
 227    }
 228    /// <summary>
 229    /// Gets the log file name for the specified time.
 230    /// </summary>
 231    /// <param name="dateTime">The time whose log filename should be constructed.</param>
 232    /// <returns>The filename for log messages logged at the specified time.</returns>
 233    internal string GetLogFileName(DateTime dateTime)
 234    {
 2235        _periodNumber = GetPeriodNumber(dateTime);
 236        // use that for the starting suffix
 2237        string suffix = PeriodString(_periodNumber) + _fileExtension;
 2238        return FilePrefix + suffix;
 239    }
 240    /// <summary>
 241    /// Attempts to delete all log files using the specified file prefix.
 242    /// If they cannot be deleted, they are skipped.
 243    /// </summary>
 244    /// <param name="filePathPrefix">The file prefix (the same one that would be passed as the filePrefix parameter to t
 245    /// <param name="fileExtension">The file extension (with leading dot) used when the logger was constructed. Defaults
 246    /// <param name="cancel">A <see cref="CancellationToken"/> to cancel the operation before it finishes.</param>
 247    public static ValueTask TryDeleteAllFiles(string filePathPrefix, string? fileExtension = null, CancellationToken can
 248    {
 2249        string? directory = Path.GetDirectoryName(filePathPrefix) ?? throw new ArgumentException("The specified file pat
 2250        string filename = Path.GetFileName(filePathPrefix)!;
 2251        fileExtension ??= ".log";
 2252        if (fileExtension.Length > 0 && fileExtension[0] != '.') fileExtension = "." + fileExtension;
 253        // clean up the files (suffix is a period number before the extension, e.g. prefix0001.log)
 2254        foreach (string file in Directory.GetFiles(directory, filename + "*" + fileExtension))
 255        {
 2256            if (cancel.IsCancellationRequested) break;
 257            try
 258            {
 2259                File.Delete(file);
 2260            }
 261#pragma warning disable CA1031  // we REALLY want to catch everything here--delete can throw a lot of different exceptio
 0262            catch { }   // ignore all errors and just skip files we can't delete
 263#pragma warning restore CA1031
 264        }
 2265        return default;
 266    }
 267    /// <summary>
 268    /// Disposes of this instance.
 269    /// </summary>
 270    /// <param name="disposing">Whether or not the instance is being disposed (as opposed to finalized).</param>
 271    protected virtual void Dispose(bool disposing)
 272    {
 2273        if (!_disposedValue)
 274        {
 2275            _disposedValue = true;
 2276            if (disposing)
 277            {
 278                // TODO: dispose managed state (managed objects)
 2279                _fileBuffers.Dispose();
 280            }
 281
 282            // TODO: free unmanaged resources (unmanaged objects) and override finalizer
 283            // TODO: set large fields to null
 284        }
 2285    }
 286
 287    // // TODO: override finalizer only if 'Dispose(bool disposing)' has code to free unmanaged resources
 288    // ~AmbientFileLogger()
 289    // {
 290    //     // Do not change this code. Put cleanup code in 'Dispose(bool disposing)' method
 291    //     Dispose(disposing: false);
 292    // }
 293    /// <summary>
 294    /// Disposes of the instance.
 295    /// </summary>
 296    public void Dispose()
 297    {
 298        // Do not change or override this method. Put cleanup code in 'Dispose(bool disposing)' method
 2299        Dispose(disposing: true);
 2300        GC.SuppressFinalize(this);
 2301    }
 302}
 303
 304/// <summary>
 305/// A class to buffer log messages and write them asynchronously.
 306/// </summary>
 307/// <remarks>
 308/// <pitch>The buffering and file-writing engine behind <see cref="AmbientFileLogger"/>: enqueueing lines and rotation i
 309/// <pledge>
 310/// Buffering a line or a rotation instruction performs no I/O, may be called concurrently from any thread, and throws <
 311/// Flushing is safe to invoke concurrently (writers take turns); auto-flush, when enabled at construction, periodically
 312/// </pledge>
 313/// <plan>
 314/// A single <see cref="ConcurrentQueue{T}"/> of strings carries both log lines and in-band commands, with GUID-prefixed
 315/// Trade-off profile: the logging path costs one enqueue; the price is that unflushed lines are lost on a crash, bounde
 316/// </plan>
 317/// </remarks>
 318internal class RotatingFileBuffer : IDisposable
 319{
 320    private static readonly string _FlushString = Guid.NewGuid().ToString();
 321    private static readonly string _SwitchFilesPrefix = Guid.NewGuid().ToString() + ":";
 322
 323    private readonly ConcurrentQueue<string> _queue = new();
 324    private readonly SemaphoreSlim _writeLock = new(1);
 325    private readonly AmbientEventTimer _timer;
 326    private readonly string _baselineFilename;
 327    private readonly string _startingSuffix;
 328    private TextWriter? _currentFileWriter;          // only accessed while the write lock is held
 329    private bool _disposedValue;
 330
 331    /// <summary>
 332    /// Constructs a file buffers instance that uses the specified properties.
 333    /// </summary>
 334    /// <param name="baselineFilename">The baseline filename (full path).</param>
 335    /// <param name="startingSuffix">The starting suffix.</param>
 336    /// <param name="autoFlushFrequency">A <see cref="TimeSpan"/> indicating how often to autoflush the log files.</para
 337    public RotatingFileBuffer(string baselineFilename, string startingSuffix, TimeSpan autoFlushFrequency)
 338    {
 339        _baselineFilename = baselineFilename;
 340        _startingSuffix = startingSuffix;
 341        if (autoFlushFrequency > TimeSpan.Zero)
 342        {
 343            _timer = new AmbientEventTimer(autoFlushFrequency) {
 344                AutoReset = true
 345            };
 346            _timer.Elapsed += Timer_Elapsed;
 347            _timer.Enabled = true;
 348        }
 349        else // just create a default timer with nothing attached (so we still have something to dispose)
 350        {
 351            _timer = new AmbientEventTimer();
 352        }
 353    }
 354
 355    private async void Timer_Elapsed(object? sender, System.Timers.ElapsedEventArgs e)
 356    {
 357        try
 358        {
 359            await FlushInternal();
 360        }
 361        // Coverage note: this code is pretty-much impossible to test because the time has to go off AFTER this instance
 362        catch (ObjectDisposedException)
 363        {
 364            // ignore this error (it can happen during the race to dispose)
 365        }
 366    }
 367
 368    /// <summary>
 369    /// Buffer the specified line (this function should NOT block on I/O of any kind).
 370    /// </summary>
 371    /// <param name="line">The string to put into the log.</param>
 372    public void BufferLine(string line)
 373    {
 374#if NET7_0_OR_GREATER
 375        ObjectDisposedException.ThrowIf(_disposedValue, this);
 376#else
 377        if (_disposedValue) throw new ObjectDisposedException(_baselineFilename);
 378#endif
 379        AmbientLogBufferLimits.EnqueueOrOverflow(_queue, line);
 380    }
 381    /// <summary>
 382    /// Buffers an instruction to rotate files.
 383    /// </summary>
 384    /// <param name="newSuffix">The new filename suffix.</param>
 385    public void BufferFileRotation(string newSuffix)
 386    {
 387#if NET7_0_OR_GREATER
 388        ObjectDisposedException.ThrowIf(_disposedValue, this);
 389#else
 390        if (_disposedValue) throw new ObjectDisposedException(_baselineFilename);
 391#endif
 392        _queue.Enqueue(_SwitchFilesPrefix + newSuffix);
 393    }
 394    /// <summary>
 395    /// Flushes any buffered data to the appropriate file(s).
 396    /// </summary>
 397    /// <param name="cancel">A <see cref="CancellationToken"/> to cancel the operation before it finishes.</param>
 398    public async ValueTask Flush(CancellationToken cancel = default)
 399    {
 400        await FlushInternal(cancel);
 401    }
 402    private async ValueTask FlushInternal(CancellationToken cancel = default)
 403    {
 404#if NET7_0_OR_GREATER
 405        ObjectDisposedException.ThrowIf(_disposedValue, this);
 406#else
 407        if (_disposedValue) throw new ObjectDisposedException(_baselineFilename);
 408#endif
 409        // queue up a special message so we know when we have processed up to the current spot in the queue
 410        _queue.Enqueue(_FlushString);
 411        try
 412        {
 413            // make sure only one thread at a time processes the queue
 414            await _writeLock.WaitAsync(cancel);
 415            // loop through the queue processing log lines until we get to that message
 416            string logString;
 417            while (_queue.TryDequeue(out logString!))   // while TryQueue *can* put null into logString, it can only do 
 418            {
 419                // no file yet?
 420                if (_currentFileWriter == null)
 421                {
 422                    // open the starting file
 423                    await SwitchFiles(_startingSuffix);
 424                }
 425                // time to switch files?
 426                else if (logString.StartsWith(_SwitchFilesPrefix, StringComparison.Ordinal))
 427                {
 428                    await SwitchFiles(logString.Substring(_SwitchFilesPrefix.Length));
 429                }
 430                // reached the flush command queued above?
 431                else if (logString.Equals(_FlushString, StringComparison.Ordinal))
 432                {
 433                    // stop here even if there are more messages (they were queued AFTER we started flushing)
 434                    break;
 435                }
 436                else // this is just a regular log string
 437                {
 438                    await _currentFileWriter.WriteLineAsync(logString);
 439                }
 440                cancel.ThrowIfCancellationRequested();
 441            }
 442        }
 443        finally
 444        {
 445            _writeLock.Release();
 446        }
 447    }
 448    // NOTE: This function may only be called while the write lock is held
 449    private ValueTask SwitchFiles(string suffix)
 450    {
 451        string filename = _baselineFilename + suffix;
 452        // close the old file
 453        _currentFileWriter?.Close();
 454        // open a new one
 455        _currentFileWriter = new StreamWriter(new FileStream(filename, FileMode.Create, FileAccess.Write, FileShare.Read
 456        // this really SHOULD be async--why can't windows open files asynchronously still!
 457        return default;
 458    }
 459
 460    protected virtual void Dispose(bool disposing)
 461    {
 462        if (!_disposedValue)
 463        {
 464            _disposedValue = true;
 465
 466            if (disposing)
 467            {
 468                // TODO: dispose managed state (managed objects)
 469                _timer.Dispose();
 470                _writeLock.Dispose();
 471                _currentFileWriter?.Dispose();
 472                _currentFileWriter = null;
 473            }
 474
 475            // TODO: free unmanaged resources (unmanaged objects) and override finalizer
 476            // TODO: set large fields to null
 477        }
 478    }
 479
 480    // // TODO: override finalizer only if 'Dispose(bool disposing)' has code to free unmanaged resources
 481    // ~FileBuffers()
 482    // {
 483    //     // Do not change this code. Put cleanup code in 'Dispose(bool disposing)' method
 484    //     Dispose(disposing: false);
 485    // }
 486    /// <summary>
 487    /// Disposes of the file buffers.  No more messages should be processed.  <see cref="Flush"/> should have been calle
 488    /// </summary>
 489    public void Dispose()
 490    {
 491        // Do not change this code. Put cleanup code in 'Dispose(bool disposing)' method
 492        Dispose(disposing: true);
 493        GC.SuppressFinalize(this);
 494    }
 495}