Fix logs --since and /proxy/logs?since= to filter by date and time

DevProxy.Tests/LogSinceFilterTests.cs

@@ -0,0 +1,143 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+// See the LICENSE file in the project root for more information.
+
+using DevProxy.Logging;
+
+using Xunit;
+
+namespace DevProxy.Tests;
+
+public class LogSinceFilterTests
+{
+    private static readonly DateTime _start = new(2026, 10, 19, 22, 0, 0, DateTimeKind.Local);
+
+    private static string TimeLine(DateTime localTime) =>
+        $" time  \u2502 {new DateTimeOffset(localTime).ToUniversalTime():O}";
+
+    private static string[] RequestBlock(string url, DateTime localTime) =>
+    [
+        "",
+        $" req   \u256d GET {url}",
+        TimeLine(localTime),
+        " skip  \u2502 RetryAfterPlugin: Request not throttled",
+        " pass  \u2570 Passed through",
+    ];
+
+    [Fact]
+    public void Filter_RequestsOnPreviousDays_ExcludedBySinceDuration()
+    {
+        string[] lines =
+        [
+            " info    Dev Proxy listening on 127.0.0.1:8000",
+            .. RequestBlock("https://example.com/day1", _start.AddMinutes(30)),
+            .. RequestBlock("https://example.com/day2", _start.AddDays(1).AddHours(1)),
+            .. RequestBlock("https://example.com/day3", _start.AddDays(2).AddHours(1)),
+        ];
+
+        var result = LogSinceFilter.Filter(lines, _start, _start.AddDays(2)).ToList();
+
+        Assert.DoesNotContain(result, l => l.Contains("listening", StringComparison.Ordinal));
+        Assert.DoesNotContain(result, l => l.Contains("day1", StringComparison.Ordinal));
+        Assert.DoesNotContain(result, l => l.Contains("day2", StringComparison.Ordinal));
+        Assert.Equal(RequestBlock("https://example.com/day3", _start.AddDays(2).AddHours(1)), result);
+    }
+
+    [Fact]
+    public void Filter_SinceInFuture_ReturnsNoLines()
+    {
+        string[] lines =
+        [
+            " info    Dev Proxy listening on 127.0.0.1:8000",
+            .. RequestBlock("https://example.com", _start.AddMinutes(5)),
+        ];
+
+        Assert.Empty(LogSinceFilter.Filter(lines, _start, _start.AddYears(1)));
+    }
+
+    [Fact]
+    public void Filter_SinceBeforeLogStart_ReturnsAllLines()
+    {
+        string[] lines =
+        [
+            " info    Dev Proxy listening on 127.0.0.1:8000",
+            .. RequestBlock("https://example.com", _start.AddMinutes(5)),
+        ];
+
+        Assert.Equal(lines, LogSinceFilter.Filter(lines, _start, _start.AddDays(-1)));
+    }
+
+    [Fact]
+    public void GetLineTimes_LinesWithoutTimestamp_UseLogStartOrPrecedingTimestamp()
+    {
+        string[] lines =
+        [
+            " info    Dev Proxy listening on 127.0.0.1:8000",
+            .. RequestBlock("https://example.com", _start.AddHours(1)),
+            " info    Configuration changed. Restarting...",
+        ];
+
+        var times = LogSinceFilter.GetLineTimes(lines, _start);
+
+        Assert.Equal(_start, times[0]);
+        Assert.All(times[1..], t => Assert.Equal(_start.AddHours(1), t));
+    }
+
+    [Fact]
+    public void GetLineTimes_DebugTimeOfDayAcrossMidnight_RollsOverToNextDay()
+    {
+        string[] lines =
+        [
+            " dbug    [23:59:59.0000000] ProxyEngine: before midnight",
+            " dbug    [00:00:01.0000000] ProxyEngine: after midnight",
+            " dbug    [00:00:00.9990000] ProxyEngine: written slightly out of order",
+            " dbug    [23:00:00.0000000] ProxyEngine: next evening",
+        ];
+
+        var times = LogSinceFilter.GetLineTimes(lines, _start);
+
+        Assert.Equal(_start.Date.AddHours(23).AddMinutes(59).AddSeconds(59), times[0]);
+        Assert.Equal(_start.Date.AddDays(1).AddSeconds(1), times[1]);
+        Assert.Equal(_start.Date.AddDays(1).AddMilliseconds(999), times[2]);
+        Assert.Equal(_start.Date.AddDays(1).AddHours(23), times[3]);
+    }
+
+    [Fact]
+    public void GetLineTimes_RequestTimestampJustBeforeMidnight_KeepsPreviousDay()
+    {
+        var afterMidnight = _start.Date.AddDays(1).AddMilliseconds(1);
+        string[] lines =
+        [
+            .. RequestBlock("https://example.com", afterMidnight),
+            " trce    [23:59:59.9990000] ProxyEngine: written slightly out of order",
+        ];
+
+        var times = LogSinceFilter.GetLineTimes(lines, _start);
+
+        Assert.Equal(_start.Date.AddDays(1).AddMilliseconds(-1), times[^1]);
+    }
+
+    [Fact]
+    public void GetLineTimes_JsonLines_UseTimestampProperty()
+    {
+        var timestamp = _start.AddDays(3);
+        string[] lines =
+        [
+            $$"""{"type":"log","level":"info","message":"hello","timestamp":"{{new DateTimeOffset(timestamp).ToUniversalTime():O}}"}""",
+            "{not json",
+        ];
+
+        var times = LogSinceFilter.GetLineTimes(lines, _start);
+
+        Assert.Equal(timestamp, times[0]);
+        Assert.Equal(timestamp, times[1]);
+    }
+
+    [Fact]
+    public void FilterLines_NoSince_ReturnsAllLines()
+    {
+        string[] lines = ["a", "b"];
+
+        Assert.Equal(lines, Commands.LogsCommand.FilterLines(lines, null, _start));
+    }
+}

DevProxy/ApiControllers/ProxyController.cs

@@ -5,6 +5,7 @@
 using DevProxy.Abstractions.Proxy;
 using DevProxy.Commands;
 using DevProxy.Jwt;
+using DevProxy.Logging;
 using DevProxy.Proxy;
 using Microsoft.AspNetCore.Mvc;
 using System.ComponentModel.DataAnnotations;
@@ -246,7 +247,7 @@ private async Task WriteSseEventAsync(string line, bool useJson, CancellationTok
         await Response.Body.FlushAsync(cancellationToken);
     }
 
-    private static IEnumerable<string> FilterLines(IList<string> lines, string? since)
+    private static IEnumerable<string> FilterLines(List<string> lines, string? since)
     {
         if (string.IsNullOrEmpty(since))
         {
@@ -259,7 +260,8 @@ private static IEnumerable<string> FilterLines(IList<string> lines, string? sinc
             return lines;
         }
 
-        return lines.Where(line => LineMatchesSince(line, sinceTime.Value));
+        using var process = System.Diagnostics.Process.GetCurrentProcess();
+        return LogSinceFilter.Filter(lines, process.StartTime, sinceTime.Value);
     }
 
     private static DateTime? ParseSinceOption(string? since)
@@ -295,29 +297,6 @@ private static IEnumerable<string> FilterLines(IList<string> lines, string? sinc
         return null;
     }
 
-    private static bool LineMatchesSince(string line, DateTime sinceTime)
-    {
-        // Parse timestamp from line format: [HH:mm:ss.fff] ...
-        if (line.Length < 14 || line[0] != '[' || line[13] != ']')
-        {
-            return true;
-        }
-
-        var timestampStr = line[1..13];
-        if (TimeSpan.TryParseExact(timestampStr, "hh\\:mm\\:ss\\.fff", System.Globalization.CultureInfo.InvariantCulture, out var timeOfDay))
-        {
-            var lineTime = DateTime.Today.Add(timeOfDay);
-            if (lineTime > DateTime.Now)
-            {
-                lineTime = lineTime.AddDays(-1);
-            }
-
-            return lineTime >= sinceTime;
-        }
-
-        return true;
-    }
-
     private static LogEntryDto ParseLogLine(string line)
     {
         // Parse: [HH:mm:ss.fff] level: category: message

DevProxy/Commands/LogsCommand.cs

@@ -2,6 +2,7 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 // See the LICENSE file in the project root for more information.
 
+using DevProxy.Logging;
 using DevProxy.State;
 using System.CommandLine;
 using System.Globalization;
@@ -89,11 +90,11 @@ private async Task<int> RunAsync(ParseResult parseResult, CancellationToken canc
 
         if (follow)
         {
-            await FollowLogFileAsync(logFile, lines, sinceTime, cancellationToken);
+            await FollowLogFileAsync(logFile, lines, sinceTime, state.StartedAt.LocalDateTime, cancellationToken);
         }
         else
         {
-            await ShowLastLinesAsync(logFile, lines, sinceTime);
+            await ShowLastLinesAsync(logFile, lines, sinceTime, state.StartedAt.LocalDateTime);
         }
 
         return 0;
@@ -148,15 +149,15 @@ private async Task<int> RunAsync(ParseResult parseResult, CancellationToken canc
         return null;
     }
 
-    private static async Task ShowLastLinesAsync(string logFile, int lineCount, DateTime? sinceTime)
+    private static async Task ShowLastLinesAsync(string logFile, int lineCount, DateTime? sinceTime, DateTime logStartTime)
     {
         var lines = new List<string>();
         await foreach (var line in File.ReadLinesAsync(logFile))
         {
             lines.Add(line);
         }
 
-        var filteredLines = FilterLines(lines, sinceTime);
+        var filteredLines = FilterLines(lines, sinceTime, logStartTime);
         var linesToShow = filteredLines.TakeLast(lineCount);
 
         foreach (var line in linesToShow)
@@ -165,10 +166,10 @@ private static async Task ShowLastLinesAsync(string logFile, int lineCount, Date
         }
     }
 
-    private static async Task FollowLogFileAsync(string logFile, int initialLines, DateTime? sinceTime, CancellationToken cancellationToken)
+    private static async Task FollowLogFileAsync(string logFile, int initialLines, DateTime? sinceTime, DateTime logStartTime, CancellationToken cancellationToken)
     {
         // Show initial lines
-        await ShowLastLinesAsync(logFile, initialLines, sinceTime);
+        await ShowLastLinesAsync(logFile, initialLines, sinceTime, logStartTime);
 
         // Follow new lines using FileSystemWatcher and reading from last position
         var lastPosition = new FileInfo(logFile).Length;
@@ -214,7 +215,8 @@ private static async Task FollowLogFileAsync(string logFile, int initialLines, D
                     string? line;
                     while ((line = await reader.ReadLineAsync(cancellationToken)) != null)
                     {
-                        if (sinceTime == null || LineMatchesSince(line, sinceTime.Value))
+                        // New lines are written now
+                        if (sinceTime == null || DateTime.Now >= sinceTime.Value)
                         {
                             Console.WriteLine(line);
                         }
@@ -231,39 +233,13 @@ private static async Task FollowLogFileAsync(string logFile, int initialLines, D
         }
     }
 
-    private static IEnumerable<string> FilterLines(IEnumerable<string> lines, DateTime? sinceTime)
+    internal static IEnumerable<string> FilterLines(IReadOnlyList<string> lines, DateTime? sinceTime, DateTime logStartTime)
     {
         if (sinceTime == null)
         {
             return lines;
         }
 
-        return lines.Where(line => LineMatchesSince(line, sinceTime.Value));
+        return LogSinceFilter.Filter(lines, logStartTime, sinceTime.Value);
     }
-
-    private static bool LineMatchesSince(string line, DateTime sinceTime)
-    {
-        // Parse timestamp from line format: [HH:mm:ss.fff] ...
-        if (line.Length < 14 || line[0] != '[' || line[13] != ']')
-        {
-            return true; // Include lines that don't match the expected format
-        }
-
-        var timestampStr = line[1..13]; // "HH:mm:ss.fff"
-        if (TimeSpan.TryParseExact(timestampStr, "hh\\:mm\\:ss\\.fff", CultureInfo.InvariantCulture, out var timeOfDay))
-        {
-            // Assume the log is from today
-            var lineTime = DateTime.Today.Add(timeOfDay);
-
-            // If line time is in the future, assume it's from yesterday
-            if (lineTime > DateTime.Now)
-            {
-                lineTime = lineTime.AddDays(-1);
-            }
-
-            return lineTime >= sinceTime;
-        }
-
-        return true; // Include lines with unparseable timestamps
-    }
-}
+}