Send logs to collector from native messaging host

Author: HashidaTKS

BrowserGuard.Tests/NetLogEntryTests.cs

@@ -0,0 +1,56 @@
+using BrowserGuard;
+using Xunit;
+
+namespace BrowserGuard.Tests
+{
+    public class NetLogEntryTests
+    {
+        [Fact]
+        public void AcceptsAnEntry()
+        {
+            var rejection = NetLogEntry.Compact(
+                """{"operation":"browsing","url":"https://example.com/"}""", out var line);
+
+            Assert.Null(rejection);
+            Assert.Equal("""{"operation":"browsing","url":"https://example.com/"}""", line);
+        }
+
+        // A sender that pretty printed its entry must not break the one line per
+        // entry rule the file depends on.
+        [Fact]
+        public void PutsAPrettyPrintedEntryOnASingleLine()
+        {
+            NetLogEntry.Compact(
+                "{\n  \"operation\": \"browsing\",\n  \"url\": \"https://example.com/\"\n}",
+                out var line);
+
+            Assert.DoesNotContain("\n", line);
+            Assert.Equal("""{"operation":"browsing","url":"https://example.com/"}""", line);
+        }
+
+        [Fact]
+        public void LeavesJapaneseLegible()
+        {
+            NetLogEntry.Compact("""{"operation":"browsing","name":"ページ名"}""", out var line);
+
+            Assert.Contains("ページ名", line);
+        }
+
+        [Fact]
+        public void RefusesSomethingThatIsNotJson()
+        {
+            var rejection = NetLogEntry.Compact("not json at all", out var line);
+
+            Assert.Contains("not valid JSON", rejection);
+            Assert.Equal("", line);
+        }
+
+        // A bare string or an array is valid JSON but not a log entry.
+        [Fact]
+        public void RefusesJsonThatIsNotAnObject()
+        {
+            Assert.Contains("not a JSON object", NetLogEntry.Compact("\"browsing\"", out _));
+            Assert.Contains("not a JSON object", NetLogEntry.Compact("[1,2,3]", out _));
+        }
+    }
+}

BrowserGuard.Tests/NetLogSenderTests.cs

@@ -0,0 +1,157 @@
+using System;
+using System.Collections.Concurrent;
+using System.Collections.Generic;
+using System.IO;
+using System.Net;
+using System.Net.Http;
+using System.Text;
+using System.Threading;
+using System.Threading.Tasks;
+using BrowserGuard;
+using Xunit;
+
+namespace BrowserGuard.Tests
+{
+    public class NetLogSenderTests
+    {
+        const string Entry = """{"operation":"browsing","url":"https://example.com/"}""";
+
+        // Answers every request with a status the test chooses, and records what
+        // it was sent, so the whole HttpClient path is exercised for real.
+        sealed class Collector : HttpMessageHandler
+        {
+            internal readonly BlockingCollection<string> Bodies = new();
+            internal readonly List<string> ContentTypes = new();
+            internal HttpStatusCode Status = HttpStatusCode.OK;
+            internal int FailuresLeft;
+            internal Uri? LastUri;
+
+            protected override async Task<HttpResponseMessage> SendAsync(
+                HttpRequestMessage request, CancellationToken cancellationToken)
+            {
+                LastUri = request.RequestUri;
+                ContentTypes.Add(request.Content?.Headers.ContentType?.ToString() ?? "");
+                Bodies.Add(await request.Content!.ReadAsStringAsync(cancellationToken));
+
+                if (FailuresLeft > 0)
+                {
+                    FailuresLeft--;
+                    throw new HttpRequestException("the collector is unreachable");
+                }
+                return new HttpResponseMessage(Status);
+            }
+        }
+
+        static string Take(Collector collector) =>
+            collector.Bodies.TryTake(out var body, TimeSpan.FromSeconds(5))
+                ? body
+                : throw new TimeoutException("nothing was posted");
+
+        [Fact]
+        public void PostsTheEntryToTheEndpoint()
+        {
+            var collector = new Collector();
+            using var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+
+            Assert.True(sender.Enqueue(Entry));
+
+            Assert.Equal(Entry, Take(collector));
+            Assert.Equal(new Uri("https://collector.example.com/log"), collector.LastUri);
+            Assert.Contains("application/json", collector.ContentTypes[0]);
+        }
+
+        [Fact]
+        public void PostsEveryEntryInTurn()
+        {
+            var collector = new Collector();
+            using var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+
+            for (var i = 0; i < 5; i++)
+            {
+                sender.Enqueue($$"""{"operation":"browsing","n":{{i}}}""");
+            }
+
+            for (var i = 0; i < 5; i++)
+            {
+                Assert.Contains($"\"n\":{i}", Take(collector));
+            }
+        }
+
+        // The message loop must not wait on the network.
+        [Fact]
+        public void HandsTheEntryOverWithoutWaitingForTheCollector()
+        {
+            var collector = new Collector();
+            using var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+
+            var elapsed = System.Diagnostics.Stopwatch.StartNew();
+            for (var i = 0; i < 100; i++)
+            {
+                sender.Enqueue(Entry);
+            }
+            elapsed.Stop();
+
+            Assert.True(elapsed.ElapsedMilliseconds < 1000,
+                $"queueing 100 entries took {elapsed.ElapsedMilliseconds}ms");
+        }
+
+        [Fact]
+        public void TriesAgainAfterAFailure()
+        {
+            var collector = new Collector { FailuresLeft = 2 };
+            using var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+
+            sender.Enqueue(Entry);
+
+            Take(collector);
+            Take(collector);
+            Assert.Equal(Entry, Take(collector));
+        }
+
+        // The browser closes the port on its way out, and the host follows.
+        // Whatever is queued has to leave first.
+        [Fact]
+        public void SendsWhatIsQueuedBeforeItShutsDown()
+        {
+            var collector = new Collector();
+            var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+            for (var i = 0; i < 10; i++)
+            {
+                sender.Enqueue(Entry);
+            }
+
+            sender.Dispose();
+
+            Assert.Equal(10, collector.Bodies.Count);
+        }
+
+        [Fact]
+        public void TakesNoFurtherEntriesOnceItHasShutDown()
+        {
+            var collector = new Collector();
+            var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+            sender.Dispose();
+
+            Assert.False(sender.Enqueue(Entry));
+        }
+
+        // A collector that answers with an error must not stop the ones after it.
+        [Fact]
+        public void KeepsGoingAfterTheCollectorRefusesAnEntry()
+        {
+            var collector = new Collector { Status = HttpStatusCode.InternalServerError };
+            using var sender = new NetLogSender("https://collector.example.com/log", null, collector);
+
+            sender.Enqueue("""{"operation":"first"}""");
+
+            // Three attempts at the first entry, then it moves on.
+            Assert.Contains("first", Take(collector));
+            Assert.Contains("first", Take(collector));
+            Assert.Contains("first", Take(collector));
+
+            collector.Status = HttpStatusCode.OK;
+            sender.Enqueue("""{"operation":"second"}""");
+            Assert.Contains("second", Take(collector));
+        }
+    }
+}

BrowserGuard.Tests/NetLogWriterTests.cs

@@ -70,50 +70,6 @@ public void CreatesTheDirectory()
             Assert.True(File.Exists(Path.Combine(tempDir, "nested", "netlog.jsonl")));
         }
 
-        // A sender that pretty printed its entry must not break the one line per
-        // entry rule the file depends on.
-        [Fact]
-        public void PutsAPrettyPrintedEntryOnASingleLine()
-        {
-            var writer = Writer();
-
-            writer.Write("{\n  \"operation\": \"browsing\",\n  \"url\": \"https://example.com/\"\n}");
-
-            Assert.Single(File.ReadAllLines(LogPath));
-        }
-
-        [Fact]
-        public void LeavesJapaneseLegible()
-        {
-            var writer = Writer();
-
-            writer.Write("""{"operation":"browsing","name":"ページ名"}""");
-
-            Assert.Contains("ページ名", File.ReadAllText(LogPath));
-        }
-
-        [Fact]
-        public void RefusesSomethingThatIsNotJson()
-        {
-            var writer = Writer();
-
-            var failure = writer.Write("not json at all");
-
-            Assert.Contains("not valid JSON", failure);
-            Assert.False(File.Exists(LogPath));
-        }
-
-        // A bare string or number is valid JSON but not a log entry.
-        [Fact]
-        public void RefusesJsonThatIsNotAnObject()
-        {
-            var writer = Writer();
-
-            Assert.Contains("not a JSON object", writer.Write("\"browsing\""));
-            Assert.Contains("not a JSON object", writer.Write("[1,2,3]"));
-            Assert.False(File.Exists(LogPath));
-        }
-
         [Fact]
         public void KeepsTheEarlierEntriesWhenItRotates()
         {

BrowserGuard/MessageHandler.cs

@@ -17,11 +17,12 @@ internal class ConfigResponse : Response
         public Config? Config { get; set; }
     }
 
-    internal class MessageHandler
+    internal class MessageHandler : IDisposable
     {
         private readonly Logger? logger;
 
-        private NetLogWriter? netLog;
+        private NetLogWriter? netLogFile;
+        private NetLogSender? netLogSender;
         private bool netLogResolved;
 
         // The logging configuration can be handed in so that it does not have to
@@ -33,8 +34,7 @@ internal MessageHandler(Logger? logger = null, NetLoggerConfig? netLoggerConfig
             {
                 return;
             }
-            netLog = Create(netLoggerConfig);
-            netLogResolved = true;
+            ResolveNetLog(netLoggerConfig);
         }
 
         // null means nothing is sent back to the browser. Log entries arrive for
@@ -69,13 +69,25 @@ internal MessageHandler(Logger? logger = null, NetLoggerConfig? netLoggerConfig
 
         private Response? HandleLogEntry(string entry)
         {
-            var writer = NetLog();
-            if (writer is null)
+            ResolveNetLog();
+            if (netLogFile is null && netLogSender is null)
             {
                 return null;
             }
 
-            var failure = writer.Write(entry);
+            // Checked once here, so that both destinations are handed the same
+            // single line and a bad entry is refused before either sees it.
+            var rejection = NetLogEntry.Compact(entry, out var line);
+            if (rejection is not null)
+            {
+                return new Response { Success = false, Error = rejection };
+            }
+
+            // The collector is best effort; only the file reports a failure,
+            // because that is the copy the entry was meant to survive in.
+            netLogSender?.Enqueue(line);
+
+            var failure = netLogFile?.Write(line);
             if (failure is null)
             {
                 return null;
@@ -84,29 +96,38 @@ internal MessageHandler(Logger? logger = null, NetLoggerConfig? netLoggerConfig
         }
 
         // Read once and remembered, including the decision not to log at all.
-        private NetLogWriter? NetLog()
+        private void ResolveNetLog()
         {
             if (netLogResolved)
             {
-                return netLog;
+                return;
             }
-            netLogResolved = true;
-            netLog = Create(ConfigLoader.LoadConfig().NetLogger);
-            return netLog;
+            ResolveNetLog(ConfigLoader.LoadConfig().NetLogger);
         }
 
-        // Both switches have to be on: NetLogger turns the whole feature off,
-        // LocalFile only the copy kept on this machine.
-        private NetLogWriter? Create(NetLoggerConfig config)
+        // NetLogger turns the whole feature off; the two destinations are
+        // independent of each other below that.
+        private void ResolveNetLog(NetLoggerConfig config)
         {
-            if (!config.Enabled || !config.LocalFile.Enabled)
+            netLogResolved = true;
+            if (!config.Enabled)
             {
-                logger?.Log("Command: log entry, but local logging is disabled");
-                return null;
+                logger?.Log("Command: log entry, but logging is disabled");
+                return;
+            }
+
+            if (config.LocalFile.Enabled)
+            {
+                netLogFile = new NetLogWriter(config.LocalFile, logger);
+                logger?.Log($"Command: log entry, writing to {netLogFile.FilePath}");
+            }
+            if (!string.IsNullOrWhiteSpace(config.Endpoint))
+            {
+                netLogSender = new NetLogSender(config.Endpoint, logger);
+                logger?.Log($"Command: log entry, sending to {config.Endpoint}");
             }
-            var writer = new NetLogWriter(config.LocalFile, logger);
-            logger?.Log($"Command: log entry, writing to {writer.FilePath}");
-            return writer;
         }
+
+        public void Dispose() => netLogSender?.Dispose();
     }
 }