Merge pull request #269 from nblumhardt/2023.1-target-cases

2023.1 target cases

Author: KodrAus

src/SeqCli/Cli/Commands/Bench/BenchCase.cs

@@ -13,13 +13,18 @@
 // limitations under the License.
 
 #nullable enable
-using System.Collections.Generic;
 
-namespace SeqCli.Cli.Commands;
+namespace SeqCli.Cli.Commands.Bench;
+
+// ReSharper disable ClassNeverInstantiated.Global AutoPropertyCanBeMadeGetOnly.Global UnusedAutoPropertyAccessor.Global
 
 class BenchCase
 {
-    public string Id = "";
-    public string Query = "";
-    public string SignalExpression = "";
+    public string Id { get; set; } = null!;
+    public string Query { get; set; } = null!;
+    public string? SignalExpression { get; set; }
+    
+    // Not used programmatically at this time.
+    // ReSharper disable once UnusedMember.Global
+    public string? Notes { get; set; }
 }

src/SeqCli/Cli/Commands/Bench/BenchCaseTimings.cs

@@ -17,31 +17,33 @@
 using System.Collections.Generic;
 using System.Linq;
 
-namespace SeqCli.Cli.Commands;
+namespace SeqCli.Cli.Commands.Bench;
 
 /*
  * Collects benchmarking elapsed time measurements and calculates statistics. 
  */
 class BenchCaseTimings
 {
-    readonly List<double> _elaspseds = new() { };
-    public double MeanElapsed => _elaspseds.Sum() / _elaspseds.Count;
-    public double MinElapsed => _elaspseds.Min();
-    public double MaxElapsed => _elaspseds.Max();
-    public double StandardDeviationElapsed => StandardDeviation(_elaspseds); 
-    public double RelativeStandardDeviationElapsed => StandardDeviation(_elaspseds) / MeanElapsed;
+    readonly List<double> _timings = new();
+    
+    public double MeanElapsed => _timings.Sum() / _timings.Count;
+    public double MinElapsed => _timings.Min();
+    public double MaxElapsed => _timings.Max();
+    public double StandardDeviationElapsed => StandardDeviation(_timings); 
+    public double RelativeStandardDeviationElapsed => StandardDeviation(_timings) / MeanElapsed;
 
     public void PushElapsed(double elapsed)
     {
-        _elaspseds.Add(elapsed);
+        _timings.Add(elapsed);
     }
 
-    double StandardDeviation(IList<double> population)
+    static double StandardDeviation(ICollection<double> population)
     {
         if (population.Count < 2)
         {
             return 0;
         }
+        
         var mean = population.Sum() / population.Count;
         return Math.Sqrt(population.Select(e => Math.Pow(e - mean, 2)).Sum() / (population.Count - 1));
     }

src/SeqCli/Cli/Commands/Bench/BenchCases.json

@@ -1,20 +1,54 @@
 {
   "cases": [
     {
-      "id": "count-star",
-      "query": "select count(*) from stream"
+      "id": "count-all",
+      "query": "select count(*) from stream where @Timestamp >= now() - 30d",
+      "notes": "Tests page traversal performance only; avoids data copies, serialization, and evaluation."
     },
     {
-      "id": "starts-with",
-      "query": "select count(*) from stream where @Message like '%abcde'"
+      "id": "count-having-request-id",
+      "query": "select count(*) from stream where RequestId is not null and @Timestamp >= now() - 30d",
+      "notes": "Tests sparse deserialization and condition evaluation atop basic page traversal."
     },
     {
-      "id": "without-signal",
-      "query": "select count(*) from stream where @Level = 'Warning'"
+      "id": "count-exception-starts-with-s",
+      "query": "select count(*) from stream where @Exception like 'S%' and @Timestamp >= now() - 30d",
+      "notes": "Text search performance. Chooses 'S' because in .NET data there should be some hits."
     },
     {
-      "id": "property-match",
-      "query": "select count(*) from stream where Action = 'ListAsync'"
+      "id": "count-message-starts-with-e",
+      "query": "select count(*) from stream where @Message like 'E%' and @Timestamp >= now() - 30d",
+      "notes": "Text search performance; worse on @Message than other properties because fragment pre-filtering is not used."
+    },
+    {
+      "id": "count-by-level",
+      "query": "select count(*) from stream where @Timestamp >= now() - 30d group by @Level",
+      "notes": "Grouping performance, strings, small number of groups."
+    },
+    {
+      "id": "count-by-millisecond",
+      "query": "select count(*) from stream where @Timestamp >= now() - 30d group by @Timestamp % 1ms limit 100",
+      "notes": "Grouping performance, numbers, up to 10000 groups."
+    },
+    {
+      "id": "count-by-day",
+      "query": "select count(*) from stream where @Timestamp >= now() - 30d group by time(12h)",
+      "notes": "Time partitioning performance."
+    },
+    {
+      "id": "distinct-exception-20ch-limit-100",
+      "query": "select distinct(substring(@Exception, 0, 20)) from stream where @Exception is not null and @Timestamp >= now() - 30d limit 100",
+      "notes": "Distinct on computed text."
+    },
+    {
+      "id": "order-by-ts-mod-10k",
+      "query": "select @Timestamp from stream where @Timestamp >= now() - 30d order by @Timestamp % 1ms limit 10",
+      "notes": "Tests performance of limited sort."
+    },
+    {
+      "id": "order-by-message-limit-10",
+      "query": "select @Message from stream where @Timestamp >= now() - 30d order by @Message limit 10",
+      "notes": "Adds character collation to limited sort."
     }
   ]
-}
+}

src/SeqCli/Cli/Commands/Bench/BenchCasesCollection.cs

@@ -15,14 +15,13 @@
 #nullable enable
 using System.Collections.Generic;
 
-namespace SeqCli.Cli.Commands;
+namespace SeqCli.Cli.Commands.Bench;
 
 /*
  * A target type for deserialization of bench case files.
  */
 class BenchCasesCollection
 {
-    // An identifier for the particular cases file
-    public string CasesHash = "";
-    public IList<BenchCase> Cases = new List<BenchCase>();
-}
+    // ReSharper disable once CollectionNeverUpdated.Global
+    public IList<BenchCase> Cases { get; } = new List<BenchCase>();
+}

src/SeqCli/Cli/Commands/Bench/BenchCommand.cs

@@ -65,7 +65,7 @@ namespace SeqCli.Cli.Commands.Bench;
 class BenchCommand : Command
 {
     readonly SeqConnectionFactory _connectionFactory;
-    int _runs = 3;
+    int _runs = 10;
     readonly ConnectionFeature _connection;
     readonly DateRangeFeature _range;
     string _cases = "";
@@ -76,10 +76,7 @@ class BenchCommand : Command
     public BenchCommand(SeqConnectionFactory connectionFactory)
     {
         _connectionFactory = connectionFactory;
-        Options.Add("r|runs=", "The number of runs to execute", r =>
-        {
-            int.TryParse(r, out _runs);
-        });
+        Options.Add("r|runs=", "The number of runs to execute; the default is 10", r => _runs = int.Parse(r));
 
         Options.Add(
             "c|cases=", 
@@ -108,56 +105,63 @@ protected override async Task<int> Run()
         try
         {
             var connection = _connectionFactory.Connect(_connection);
-            using var reportingLogger = BuildReportingLogger();
+            var seqVersion = (await connection.Client.GetRootAsync()).Version;
+
             var cases = ReadCases(_cases);
-            var runId = Guid.NewGuid().ToString("N").Substring(0, 4);
+            var runId = Guid.NewGuid().ToString("N")[..16];
+            
+            await using var reportingLogger = BuildReportingLogger();
 
-            if (_range.Start == null || _range.End == null)
+            using (!string.IsNullOrWhiteSpace(_description)
+                       ? LogContext.PushProperty("Description", _description)
+                       : null)
             {
-                Log.Error("Both the `start` and `end` arguments are required");
-                return 1;
+                reportingLogger.Information(
+                    "Bench run {RunId} against {ServerUrl} ({SeqVersion}); {CaseCount} cases, {Runs} runs, from {Start} to {End}",
+                    runId, connection.Client.ServerUrl, seqVersion, cases.Cases.Count, _runs, _range.Start, _range.End);
             }
 
-            foreach (var c in cases.Cases)
+            using (LogContext.PushProperty("RunId", runId))
+            using (LogContext.PushProperty("Start", _range.Start))
+            using (LogContext.PushProperty("End", _range.End))
             {
-                var timings = new BenchCaseTimings();
-                object? lastResult = null;
-                
-                foreach (var i in Enumerable.Range(1, _runs))
+                foreach (var c in cases.Cases)
                 {
-                    var response = await connection.Data.QueryAsync(
-                        c.Query,
-                        _range.Start,
-                        _range.End,
-                        SignalExpressionPart.Signal(c.SignalExpression)
-                    );
+                    var timings = new BenchCaseTimings();
+                    object? lastResult = null;
 
-                    timings.PushElapsed(response.Statistics.ElapsedMilliseconds);
-
-                    if (response.Rows != null)
+                    foreach (var i in Enumerable.Range(1, _runs))
                     {
-                        var isScalarResult = response.Rows.Length == 1 && response.Rows[0].Length == 1;
-                        if (isScalarResult && i == _runs)
+                        var response = await connection.Data.QueryAsync(
+                            c.Query,
+                            _range.Start,
+                            _range.End,
+                            c.SignalExpression != null ? SignalExpressionPart.Signal(c.SignalExpression) : null
+                        );
+
+                        timings.PushElapsed(response.Statistics.ElapsedMilliseconds);
+
+                        if (response.Rows != null)
                         {
-                            lastResult = response.Rows[0][0];
+                            var isScalarResult = response.Rows.Length == 1 && response.Rows[0].Length == 1;
+                            if (isScalarResult && i == _runs)
+                            {
+                                lastResult = response.Rows[0][0];
+                            }
                         }
                     }
-                }
-                
-                using (lastResult != null ? LogContext.PushProperty("LastResult", lastResult) : null)
-                using (LogContext.PushProperty("MinElapsed", timings.MinElapsed))
-                using (LogContext.PushProperty("MaxElapsed", timings.MaxElapsed))
-                using (LogContext.PushProperty("Runs", _runs))
-                using (!string.IsNullOrWhiteSpace(c.SignalExpression) ? LogContext.PushProperty("SignalExpression", c.SignalExpression) : null)
-                using (LogContext.PushProperty("Start", _range.Start))
-                using (LogContext.PushProperty("StandardDeviationElapsed", timings.StandardDeviationElapsed))
-                using (LogContext.PushProperty("End", _range.End))
-                using (LogContext.PushProperty("Query", c.Query))
-                using (!string.IsNullOrWhiteSpace(_description) ? LogContext.PushProperty("Description", _description) : null)
-                {
-                    reportingLogger.Information(
-                        "Bench run {Cases}/{RunId} against {Server} for query {Id}: mean {MeanElapsed:N0} ms with relative dispersion {RelativeStandardDeviationElapsed:N2}", 
-                                 cases.CasesHash, runId,  _connection.Url,     c.Id,      timings.MeanElapsed,                      timings.RelativeStandardDeviationElapsed);
+
+                    using (lastResult != null ? LogContext.PushProperty("LastResult", lastResult) : null)
+                    using (!string.IsNullOrWhiteSpace(c.SignalExpression)
+                               ? LogContext.PushProperty("SignalExpression", c.SignalExpression)
+                               : null)
+                    using (LogContext.PushProperty("StandardDeviationElapsed", timings.StandardDeviationElapsed))
+                    using (LogContext.PushProperty("Query", c.Query))
+                    {
+                        reportingLogger.Information(
+                            "Case {Id,-40} mean {MeanElapsed,5:N0} ms (min {MinElapsed,5:N0} ms, max {MaxElapsed,5:N0} ms, RSD {RelativeStandardDeviationElapsed,4:N2})",
+                            c.Id, timings.MeanElapsed, timings.MinElapsed, timings.MaxElapsed, timings.RelativeStandardDeviationElapsed);
+                    }
                 }
             }
 
@@ -197,28 +201,20 @@ static BenchCasesCollection ReadCases(string filename)
         var casesString = File.ReadAllText(string.IsNullOrWhiteSpace(filename)
             ? defaultCasesPath
             : filename);
+        
         var casesFile = JsonConvert.DeserializeObject<BenchCasesCollection>(casesString)
                         ?? new BenchCasesCollection();
 
-        casesFile.CasesHash = HashString(casesString); 
-
         if (casesFile.Cases.Select(c => c.Id).Distinct().Count() != casesFile.Cases.Count)
         {
-            throw new Exception($"Cases file {filename} contains a duplicate id");
+            throw new ArgumentException($"Cases file `{filename}` contains a duplicate id.");
         }
 
         if (!casesFile.Cases.Any())
         {
-            throw new Exception($"Cases file {filename} contains no cases");
+            throw new ArgumentException($"Cases file `{filename}` contains no cases.");
         }
 
         return casesFile;
     }
-
-    static string HashString(string input)
-    {
-        using var md5 = MD5.Create();
-        var bytes = Encoding.ASCII.GetBytes(input);
-        return Convert.ToHexString(md5.ComputeHash(bytes));
-    }
 }

test/SeqCli.EndToEnd/Bench/BenchTestCase.cs

@@ -13,7 +13,7 @@ public Task ExecuteAsync(
         ILogger logger,
         CliCommandRunner runner)
     {
-        var exit = runner.Exec("bench", "--start=2022-01-01 --end=2022-01-02");
+        var exit = runner.Exec("bench", "--runs 3");
         Assert.Equal(0, exit);
 
         return Task.CompletedTask;