From d5bc73902a9fbe8c3edbea0d1e91e4a0d3b2622a Mon Sep 17 00:00:00 2001 From: Luke Butters Date: Mon, 6 Nov 2023 15:01:57 +1100 Subject: [PATCH] Record all log lines, and don't let logging alter the test run (#526) * Record all log lines, and don't let logging alter the tests timings. --- source/Halibut.Tests/Halibut.Tests.csproj | 1 + source/Halibut.Tests/TraceLogFileLogger.cs | 66 ++++++++++++++++++++-- 2 files changed, 61 insertions(+), 6 deletions(-) diff --git a/source/Halibut.Tests/Halibut.Tests.csproj b/source/Halibut.Tests/Halibut.Tests.csproj index 60573996..73a295e4 100644 --- a/source/Halibut.Tests/Halibut.Tests.csproj +++ b/source/Halibut.Tests/Halibut.Tests.csproj @@ -36,6 +36,7 @@ + diff --git a/source/Halibut.Tests/TraceLogFileLogger.cs b/source/Halibut.Tests/TraceLogFileLogger.cs index 90d8d836..cbb0ebf6 100644 --- a/source/Halibut.Tests/TraceLogFileLogger.cs +++ b/source/Halibut.Tests/TraceLogFileLogger.cs @@ -1,25 +1,79 @@ using System; +using System.Collections.Generic; using System.IO; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.VisualStudio.Threading; namespace Halibut.Tests { public class TraceLogFileLogger : IDisposable { - string tempFilePath = Path.GetTempFileName(); + readonly AsyncQueue queue = new(); + readonly string tempFilePath = Path.GetTempFileName(); string testHash; + readonly CancellationTokenSource cancellationTokenSource = new CancellationTokenSource(); + readonly Task writeDataToDiskTask; + + public TraceLogFileLogger() + { + writeDataToDiskTask = WriteDataToFile(); + } + public void SetTestHash(string testHash) { this.testHash = testHash; } - + public void WriteLine(string logMessage) { - File.AppendAllLines(tempFilePath, new[] { logMessage }); + if (cancellationTokenSource.IsCancellationRequested) return; + queue.Enqueue(logMessage); + } + + async Task WriteDataToFile() + { + while (!cancellationTokenSource.IsCancellationRequested) + { + var list = new List(); + + try + { + // Don't hammer the disk, let some log message queue up before writing them. + await Task.Delay(TimeSpan.FromMilliseconds(5), cancellationTokenSource.Token); + + // await here for something to enter the queue. + list.Add(await queue.DequeueAsync(cancellationTokenSource.Token)); + } + catch (OperationCanceledException) + { + } + + // If we got something from the queue, get as much as we can from queue without blocking. + // So what we can write it down as one chunk. + while (queue.TryDequeue(out var log)) list.Add(log); + + using (var fileAppender = new StreamWriter(tempFilePath, true, Encoding.UTF8, 8192)) + { + foreach (var logLine in list) await fileAppender.WriteLineAsync(logLine); + + await fileAppender.FlushAsync(); + } + } + } + + void FinishWritingLogs() + { + cancellationTokenSource.Cancel(); + writeDataToDiskTask.GetAwaiter().GetResult(); + cancellationTokenSource.Dispose(); } public bool CopyLogFileToArtifacts() { + FinishWritingLogs(); // The current directory is expected to have the following structure // (w/ variance depending on Debug/Release and dotnet framework used (net6.0, net48 etc): // @@ -29,7 +83,7 @@ public bool CopyLogFileToArtifacts() // from which point we can navigate to the artifacts directory. var currentDirectory = Directory.GetCurrentDirectory(); var rootDirectory = new DirectoryInfo(currentDirectory).Parent.Parent.Parent.Parent.Parent; - + var traceLogsDirectory = rootDirectory.CreateSubdirectory("artifacts").CreateSubdirectory("trace-logs"); var fileName = $"{testHash}.tracelog"; @@ -43,7 +97,7 @@ public bool CopyLogFileToArtifacts() return false; } } - + public void Dispose() { try @@ -57,4 +111,4 @@ public void Dispose() } } } -} +} \ No newline at end of file