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

@@ -36,6 +36,7 @@
     <PackageReference Include="Microsoft.Extensions.Configuration.EnvironmentVariables" Version="7.0.0" />
     <PackageReference Include="Assent" Version="1.8.2" />
     <PackageReference Include="FluentAssertions" Version="6.8.0" />
+    <PackageReference Include="Microsoft.VisualStudio.Threading" Version="17.7.30" />
     <PackageReference Include="NSubstitute" Version="4.4.0" />
     <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.3.2" />
     <PackageReference Include="NUnit" Version="3.13.3" />

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<string> 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<string>();
+
+                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()
             }
         }
     }
-}
+}