| | | 1 | | using System; |
| | | 2 | | using System.Collections.Concurrent; |
| | | 3 | | using System.Diagnostics; |
| | | 4 | | using System.Diagnostics.CodeAnalysis; |
| | | 5 | | #if NET5_0_OR_GREATER |
| | | 6 | | using System.Runtime.Versioning; |
| | | 7 | | #endif |
| | | 8 | | using System.Text; |
| | | 9 | | using System.Threading; |
| | | 10 | | using System.Threading.Tasks; |
| | | 11 | | |
| | | 12 | | namespace AmbientServices; |
| | | 13 | | |
| | | 14 | | /// <summary> |
| | | 15 | | /// A very basic ambient logger that just sends log data to a high-performance asynchronous wrapper on the system debug/ |
| | | 16 | | /// This logger is higher performance than the default one that writes to files, but it also effectively tosses data unl |
| | | 17 | | /// so using the file logger by default is better for diagnosing issues that occur before the user is able to switch log |
| | | 18 | | /// Switch to this logger for better performance, but less persistent log data. |
| | | 19 | | /// Turn the logger off for maximum performance. |
| | | 20 | | /// </summary> |
| | | 21 | | /// <remarks> |
| | | 22 | | /// <pitch>The zero-configuration default logger: higher-performance debug/trace output that is effectively discarded un |
| | | 23 | | /// <pledge><see cref="IAmbientLogger"/></pledge> |
| | | 24 | | /// <pledge><see cref="IAmbientStructuredLogger"/></pledge> |
| | | 25 | | /// <plan> |
| | | 26 | | /// A stateless singleton (<see cref="Instance"/>, private constructor) that forwards every line to the process-wide <se |
| | | 27 | | /// Trade-off profile: fastest of the built-in loggers on the logging path, but durability is entirely delegated to what |
| | | 28 | | /// </plan> |
| | | 29 | | /// <priority> |
| | | 30 | | /// <see cref="IAmbientLogger"/> |
| | | 31 | | /// 1. Logging-path speed over durability: whether anything survives is the attached listeners' business, and with none |
| | | 32 | | /// </priority> |
| | | 33 | | /// </remarks> |
| | | 34 | | [DefaultAmbientService] |
| | | 35 | | public class AmbientTraceLogger : IAmbientLogger, IAmbientStructuredLogger |
| | | 36 | | { |
| | | 37 | | /// <summary> |
| | | 38 | | /// Gets the default instance of the ambient debug/trace logger. |
| | | 39 | | /// </summary> |
| | | 40 | | public static AmbientTraceLogger Instance { get; } = new(); |
| | | 41 | | |
| | | 42 | | /// <summary> |
| | | 43 | | /// Constructs an ambient trace logger, and implementation of <see cref="IAmbientLogger"/> that outputs log data to |
| | | 44 | | /// </summary> |
| | | 45 | | private AmbientTraceLogger() |
| | | 46 | | { |
| | | 47 | | } |
| | | 48 | | /// <summary> |
| | | 49 | | /// Buffers the specified structured data to be asynchronously logged. |
| | | 50 | | /// </summary> |
| | | 51 | | /// <param name="structuredData">The structured data object.</param> |
| | | 52 | | #if NET5_0_OR_GREATER |
| | | 53 | | [UnsupportedOSPlatform("browser")] |
| | | 54 | | #endif |
| | | 55 | | public void Log(object structuredData) |
| | | 56 | | { |
| | | 57 | | #if NET5_0_OR_GREATER |
| | | 58 | | ArgumentNullException.ThrowIfNull(structuredData); |
| | | 59 | | #else |
| | | 60 | | if (structuredData is null) throw new ArgumentNullException(nameof(structuredData)); |
| | | 61 | | #endif |
| | | 62 | | string message = AmbientLogger.ConvertStructuredDataIntoSimpleMessage(structuredData); |
| | | 63 | | Log(message); |
| | | 64 | | } |
| | | 65 | | /// <summary> |
| | | 66 | | /// Adds the specified message to the log. |
| | | 67 | | /// </summary> |
| | | 68 | | /// <param name="message">The message to log.</param> |
| | | 69 | | #if NET5_0_OR_GREATER |
| | | 70 | | [UnsupportedOSPlatform("browser")] |
| | | 71 | | #endif |
| | | 72 | | public void Log(string message) |
| | | 73 | | { |
| | | 74 | | TraceBuffer.BufferLine(message); |
| | | 75 | | } |
| | | 76 | | /// <summary> |
| | | 77 | | /// Asynchronously flushes log entries to the system debug/trace output. |
| | | 78 | | /// </summary> |
| | | 79 | | #if NET5_0_OR_GREATER |
| | | 80 | | [UnsupportedOSPlatform("browser")] |
| | | 81 | | #endif |
| | | 82 | | public ValueTask Flush(CancellationToken cancel = default) |
| | | 83 | | { |
| | | 84 | | return TraceBuffer.Flush(cancel); |
| | | 85 | | } |
| | | 86 | | } |
| | | 87 | | /// <summary> |
| | | 88 | | /// A class to buffer debug trace messages and display them asynchronously. |
| | | 89 | | /// </summary> |
| | | 90 | | /// <remarks> |
| | | 91 | | /// <pitch>The process-wide asynchronous buffer between logging callers and <see cref="System.Diagnostics.Trace"/>: buff |
| | | 92 | | /// <pledge> |
| | | 93 | | /// Buffering never blocks on trace I/O and may be called concurrently from any thread; buffered lines are written to th |
| | | 94 | | /// When the in-memory buffer is at capacity, additional lines spill to the ambient <see cref="IAmbientLogOverflowWriter |
| | | 95 | | /// </pledge> |
| | | 96 | | /// <plan> |
| | | 97 | | /// A static <see cref="ConcurrentQueue{T}"/> drained by one dedicated below-normal-priority background thread that batc |
| | | 98 | | /// Trade-off profile: minimal per-line cost and no lock contention on the logging path, at the price of a dedicated thr |
| | | 99 | | /// </plan> |
| | | 100 | | /// </remarks> |
| | | 101 | | #if NET5_0_OR_GREATER |
| | | 102 | | [UnsupportedOSPlatform("browser")] |
| | | 103 | | #endif |
| | | 104 | | public static class TraceBuffer |
| | | 105 | | { |
| | 2 | 106 | | private static readonly string _FlushString = Guid.NewGuid().ToString(); |
| | 2 | 107 | | private static readonly ConcurrentQueue<string> _Queue = new(); |
| | 2 | 108 | | private static readonly SemaphoreSlim _Semaphore = new(0, short.MaxValue); |
| | 2 | 109 | | private static readonly Thread _FlusherThread = FlusherThread(); |
| | 2 | 110 | | private static readonly SemaphoreSlim _FlusherSemaphore = new(0, short.MaxValue); |
| | | 111 | | |
| | | 112 | | private static Thread FlusherThread() |
| | | 113 | | { |
| | | 114 | | // fire up a background thread to flush the trace data |
| | 2 | 115 | | Thread thread = new(new ThreadStart(TraceBufferBackgroundFlusher)) { |
| | 2 | 116 | | IsBackground = true, |
| | 2 | 117 | | Name = "TraceBuffer.FlusherThread", |
| | 2 | 118 | | Priority = ThreadPriority.BelowNormal, |
| | 2 | 119 | | }; |
| | 2 | 120 | | thread.Start(); |
| | 2 | 121 | | return thread; |
| | | 122 | | } |
| | | 123 | | /// <summary> |
| | | 124 | | /// Buffers the specified line to the concurrent buffer. |
| | | 125 | | /// </summary> |
| | | 126 | | /// <param name="s">The string to buffer.</param> |
| | | 127 | | public static void BufferLine(string s) |
| | | 128 | | { |
| | 2 | 129 | | Buffer(s + Environment.NewLine); |
| | 2 | 130 | | } |
| | | 131 | | private static void Buffer(string s) |
| | | 132 | | { |
| | | 133 | | // enqueue the string given to us (or spill to the standard local overflow log when the buffer is full) |
| | 2 | 134 | | AmbientLogBufferLimits.EnqueueOrOverflow(_Queue, s); |
| | | 135 | | // release the semaphore so the data gets processed |
| | 2 | 136 | | Release(false).Wait(); |
| | 2 | 137 | | } |
| | | 138 | | [DebuggerStepThrough] |
| | | 139 | | private static bool Release() |
| | | 140 | | { |
| | | 141 | | try |
| | | 142 | | { |
| | 2 | 143 | | _Semaphore.Release(); |
| | 2 | 144 | | return true; |
| | | 145 | | } |
| | 0 | 146 | | catch (SemaphoreFullException) |
| | | 147 | | { |
| | | 148 | | // failure! |
| | 0 | 149 | | return false; |
| | | 150 | | } |
| | 2 | 151 | | } |
| | | 152 | | private static async Task Release(bool flush, CancellationToken cancel = default) |
| | | 153 | | { |
| | | 154 | | try |
| | | 155 | | { |
| | | 156 | | // if the release fails, flush the queue |
| | 2 | 157 | | if (!Release()) flush = true; |
| | 2 | 158 | | cancel.ThrowIfCancellationRequested(); |
| | | 159 | | // are we flushing? |
| | 2 | 160 | | if (flush) |
| | | 161 | | { |
| | | 162 | | // boost the priority of the flusher thread for a bit |
| | 2 | 163 | | _FlusherThread.Priority = ThreadPriority.AboveNormal; |
| | 2 | 164 | | cancel.ThrowIfCancellationRequested(); |
| | | 165 | | // wait for the flush to happen |
| | 2 | 166 | | await _FlusherSemaphore.WaitAsync(cancel); |
| | | 167 | | } |
| | 2 | 168 | | } |
| | | 169 | | finally |
| | | 170 | | { |
| | | 171 | | // restore the thread priority |
| | 2 | 172 | | if (flush) _FlusherThread.Priority = ThreadPriority.BelowNormal; |
| | | 173 | | } |
| | 2 | 174 | | } |
| | | 175 | | /// <summary> |
| | | 176 | | /// Asynchronously flushes any queued trace lines. |
| | | 177 | | /// </summary> |
| | | 178 | | /// <param name="cancel">A <see cref="CancellationToken"/> that the caller can use to interrupt the operation before |
| | | 179 | | public static async ValueTask Flush(CancellationToken cancel = default) |
| | | 180 | | { |
| | | 181 | | // queue a flush command |
| | 2 | 182 | | _Queue.Enqueue(_FlushString); |
| | | 183 | | // release the semaphore so the data gets processed |
| | 2 | 184 | | await Release(true, cancel); |
| | 2 | 185 | | } |
| | | 186 | | /// <summary> |
| | | 187 | | /// Peeks at all unflushed messages synchronously (for diagnostic purposes only). |
| | | 188 | | /// </summary> |
| | | 189 | | [ExcludeFromCoverage] |
| | | 190 | | [ExcludeFromCodeCoverage, Obsolete("This property should not be used directly--it's only for debugging!")] |
| | | 191 | | public static string PeekUnflushed |
| | | 192 | | { |
| | | 193 | | get |
| | | 194 | | { |
| | | 195 | | StringBuilder ret = new(); |
| | | 196 | | foreach (string s in _Queue) |
| | | 197 | | { |
| | | 198 | | // add this to the result |
| | | 199 | | ret.Append(s); |
| | | 200 | | } |
| | | 201 | | // return the data |
| | | 202 | | return ret.ToString(); |
| | | 203 | | } |
| | | 204 | | } |
| | | 205 | | private static void TraceBufferBackgroundFlusher() |
| | | 206 | | { |
| | | 207 | | // loop forever! |
| | | 208 | | while (true) |
| | | 209 | | { |
| | | 210 | | try |
| | | 211 | | { |
| | 2 | 212 | | StringBuilder traceData = new(); |
| | | 213 | | // get up to 10 lines of trace data |
| | 2 | 214 | | for (int line = 0; line < 10; ++line) |
| | | 215 | | { |
| | | 216 | | // get the oldest item on the queue |
| | | 217 | | // is there a string to trace? |
| | 2 | 218 | | if (_Queue.TryDequeue(out string? s)) |
| | | 219 | | { |
| | 2 | 220 | | if (s == _FlushString) |
| | | 221 | | { |
| | | 222 | | // release the flusher that told us to flush |
| | 2 | 223 | | _FlusherSemaphore.Release(); |
| | | 224 | | } |
| | | 225 | | else |
| | | 226 | | { |
| | | 227 | | // add this to the trace data |
| | 2 | 228 | | traceData.Append(s); |
| | | 229 | | } |
| | | 230 | | // is there more data? (don't wait if there isn't) |
| | 2 | 231 | | if (_Semaphore.Wait(0)) |
| | | 232 | | { |
| | | 233 | | // try to get some more data (up to ten lines) |
| | | 234 | | continue; |
| | | 235 | | } |
| | | 236 | | // else no data left in queue--no point in waiting before we flush to the output |
| | | 237 | | } |
| | | 238 | | // else nothing left in the queue |
| | | 239 | | else break; |
| | | 240 | | } |
| | | 241 | | // is there a string to trace? |
| | 2 | 242 | | if (traceData.Length > 0) |
| | | 243 | | { |
| | | 244 | | // trace out this string |
| | 2 | 245 | | Trace.Write(traceData.ToString()); |
| | | 246 | | } |
| | | 247 | | else |
| | | 248 | | { |
| | | 249 | | // wait for more work (ie. stop using CPU until there is more work to do) |
| | 2 | 250 | | _Semaphore.Wait(TimeSpan.FromMinutes(5)); // we shouldn't ever hang here, but just in case, exit * |
| | | 251 | | } |
| | 2 | 252 | | } |
| | | 253 | | catch (Exception ex) |
| | | 254 | | { |
| | | 255 | | // trace out this string |
| | 0 | 256 | | Trace.Write(ex.ToString()); |
| | 0 | 257 | | } |
| | | 258 | | } |
| | | 259 | | } |
| | | 260 | | } |