Skip to content

Commit

Permalink
- Add benchmark project to tests that outputs a histogram of ack/cons…
Browse files Browse the repository at this point in the history
…ume latencies. Code borrowed from mtbench for MassTransit (#845)
  • Loading branch information
gkinsman committed Feb 3, 2021
1 parent 3670d2f commit 9d791a1
Show file tree
Hide file tree
Showing 10 changed files with 453 additions and 0 deletions.
7 changes: 7 additions & 0 deletions JustSaying.sln
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,8 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "JustSaying.Sample.Restauran
EndProject
Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "JustSaying.Extensions.DependencyInjection.StructureMap.Tests", "tests\JustSaying.Extensions.DependencyInjection.StructureMap.Tests\JustSaying.Extensions.DependencyInjection.StructureMap.Tests.csproj", "{6AF4E086-6784-489C-9AB1-36F637A30094}"
EndProject
Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "JustSaying.Benchmark", "tests\JustSaying.Benchmark\JustSaying.Benchmark.csproj", "{83B43FC1-1F1C-4838-B67B-CE70D16870AF}"
EndProject
Global
GlobalSection(SolutionConfigurationPlatforms) = preSolution
Debug|Any CPU = Debug|Any CPU
Expand Down Expand Up @@ -128,6 +130,10 @@ Global
{6AF4E086-6784-489C-9AB1-36F637A30094}.Debug|Any CPU.Build.0 = Debug|Any CPU
{6AF4E086-6784-489C-9AB1-36F637A30094}.Release|Any CPU.ActiveCfg = Release|Any CPU
{6AF4E086-6784-489C-9AB1-36F637A30094}.Release|Any CPU.Build.0 = Release|Any CPU
{83B43FC1-1F1C-4838-B67B-CE70D16870AF}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
{83B43FC1-1F1C-4838-B67B-CE70D16870AF}.Debug|Any CPU.Build.0 = Debug|Any CPU
{83B43FC1-1F1C-4838-B67B-CE70D16870AF}.Release|Any CPU.ActiveCfg = Release|Any CPU
{83B43FC1-1F1C-4838-B67B-CE70D16870AF}.Release|Any CPU.Build.0 = Release|Any CPU
EndGlobalSection
GlobalSection(SolutionProperties) = preSolution
HideSolutionNode = FALSE
Expand All @@ -149,6 +155,7 @@ Global
{B42B2446-00F6-407E-8C62-E3831B61C8B6} = {77C93C37-DE5B-448F-9A23-6C9D0C8465CA}
{A4D0E032-3AF1-437F-AF6B-4B602B8D4C49} = {77C93C37-DE5B-448F-9A23-6C9D0C8465CA}
{6AF4E086-6784-489C-9AB1-36F637A30094} = {E22A50F2-9952-4483-8AD1-09BE354FB3E4}
{83B43FC1-1F1C-4838-B67B-CE70D16870AF} = {E22A50F2-9952-4483-8AD1-09BE354FB3E4}
EndGlobalSection
GlobalSection(ExtensibilityGlobals) = postSolution
SolutionGuid = {18FBDF85-C124-4444-9F03-D0D4F2B3A612}
Expand Down
66 changes: 66 additions & 0 deletions tests/JustSaying.Benchmark/Analytics.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,66 @@
using System;
using System.Collections.Generic;
using System.Linq;

namespace JustSaying.Benchmark
{
// Borrowed with ❤ from https://github.com/MassTransit/MassTransit-Benchmark/blob/a04a0235e13cd25e898a4238bad24ab5476d52d0/src/MassTransit-Benchmark/Analytics.cs
public static class Analytics
{
public static double? Median<TColl, TValue>(
this IEnumerable<TColl> source,
Func<TColl, TValue> selector)
where TValue : struct
{
return source.Select(selector).Median();
}

public static double? Percentile<TColl, TValue>(
this IEnumerable<TColl> source,
Func<TColl, TValue> selector, int percentile = 95)
where TValue : struct
{
return source.Select(selector).Percentile(percentile);
}

public static double? Median<T>(
this IEnumerable<T> source)
where T : struct
{
int count = source.Count();
if (count == 0)
return null;

source = source.OrderBy(n => n);

int midpoint = count / 2;
if (count % 2 == 0)
{
return (Convert.ToDouble(source.ElementAt(midpoint - 1)) + Convert.ToDouble(source.ElementAt(midpoint)))
/ 2.0;
}

return Convert.ToDouble(source.ElementAt(midpoint));
}

public static double? Percentile<T>(
this IEnumerable<T> source, int percentile)
where T : struct
{
int count = source.Count();
if (count == 0)
return null;

source = source.OrderBy(n => n);

int point = count * percentile / 100;
if (count % 2 == 0)
{
return (Convert.ToDouble(source.ElementAt(point - 1)) + Convert.ToDouble(source.ElementAt(point)))
/ 2.0;
}

return Convert.ToDouble(source.ElementAt(point));
}
}
}
17 changes: 17 additions & 0 deletions tests/JustSaying.Benchmark/BenchmarkMessage.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,17 @@
using System;
using JustSaying.Models;

namespace JustSaying.Benchmark
{
public class BenchmarkMessage : Message
{
public BenchmarkMessage(TimeSpan sentAtOffset, int sequenceId)
{
SentAtOffset = sentAtOffset;
SequenceId = sequenceId;
}

public TimeSpan SentAtOffset { get; }
public int SequenceId { get; }
}
}
21 changes: 21 additions & 0 deletions tests/JustSaying.Benchmark/BenchmarkMessageHander.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
using System.Threading.Tasks;
using JustSaying.Messaging.MessageHandling;

namespace JustSaying.Benchmark
{
public class BenchmarkMessageHander : IHandlerAsync<BenchmarkMessage>
{
private readonly IReportConsumerMetric _reporter;

public BenchmarkMessageHander(IReportConsumerMetric reporter)
{
_reporter = reporter;
}

public Task<bool> Handle(BenchmarkMessage message)
{
_reporter.Consumed<BenchmarkMessage>(message.Id);
return Task.FromResult(true);
}
}
}
13 changes: 13 additions & 0 deletions tests/JustSaying.Benchmark/IReportConsumerMetric.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
using System;
using System.Threading.Tasks;

namespace JustSaying.Benchmark
{
public interface IReportConsumerMetric
{
Task Consumed<T>(Guid messageId)
where T : class;

Task Sent(Guid messageId, Task sendTask);
}
}
26 changes: 26 additions & 0 deletions tests/JustSaying.Benchmark/JustSaying.Benchmark.csproj
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
<Project Sdk="Microsoft.NET.Sdk">

<PropertyGroup>
<OutputType>Exe</OutputType>
<TargetFramework>net5.0</TargetFramework>
</PropertyGroup>

<ItemGroup>
<PackageReference Include="CommandLineParser" Version="2.8.0" />
<PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="5.0.1" />
<PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="5.0.0" />
<PackageReference Include="morelinq" Version="3.3.2" />
<PackageReference Include="Serilog" Version="2.9.0" />
<PackageReference Include="Serilog.Extensions.Logging" Version="3.0.1" />
<PackageReference Include="Serilog.Sinks.Console" Version="3.1.1" />
<PackageReference Include="Serilog.Sinks.Seq" Version="4.0.0" />
<PackageReference Include="SerilogTimings" Version="2.3.0" />
</ItemGroup>

<ItemGroup>
<ProjectReference Include="..\..\src\JustSaying.Extensions.DependencyInjection.Microsoft\JustSaying.Extensions.DependencyInjection.Microsoft.csproj" />
<ProjectReference Include="..\..\src\JustSaying.Models\JustSaying.Models.csproj" />
<ProjectReference Include="..\..\src\JustSaying\JustSaying.csproj" />
</ItemGroup>

</Project>
151 changes: 151 additions & 0 deletions tests/JustSaying.Benchmark/JustSayingBenchmark.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,151 @@
using System;
using System.Diagnostics;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using Amazon;
using CommandLine;
using JustSaying.Messaging;
using Microsoft.Extensions.DependencyInjection;
using MoreLinq;
using Serilog;
using SerilogTimings;

namespace JustSaying.Benchmark
{
[Verb("benchmark", HelpText = "Runs a benchmark against an SQS queue to test queue throughput")]
public class JustSayingBenchmark
{
[Option(HelpText = "The number of messages to send and receive in this test",
Required = false, Default = 1000)]
public int MessageCount { get; set; }

public static async Task RunTest(JustSayingBenchmark options)
{
Console.WriteLine("Running benchmark with message count of {0}", options.MessageCount);

var capture = new MessageMetricCapture(options.MessageCount);

var services = new ServiceCollection()
.AddSingleton<IReportConsumerMetric>(capture)
.AddLogging(lg => lg.AddSerilog());

RegisterJustSaying(services);

var provider = services.BuildServiceProvider();
var publisher = provider.GetService<IMessagePublisher>();

using (Operation.Time("Executing startup work"))
{
await publisher.StartAsync(CancellationToken.None);
var bus = provider.GetService<IMessagingBus>();
await bus.StartAsync(CancellationToken.None);
}

Console.WriteLine("Completed startup, beginning benchmark");

var watch = new Stopwatch();

var taskBatches = Enumerable.Range(0, options.MessageCount).Batch(20)
.Select(async batch =>
{
var messageTasks =
batch.Select(id => new BenchmarkMessage(watch.Elapsed, id))
.Select(async x => await capture.Sent(x.Id, publisher.PublishAsync(x)));
await Task.WhenAll(messageTasks);
}).ToList();

var batchId = 1;
var batchCount = taskBatches.Count;
foreach (var taskBatch in taskBatches)
{
using (Operation.Time("Sending batch id {BatchId} of {BatchCount}",
batchId,
batchCount))
{
await taskBatch;
}
}

Log.Information("Waiting for sends to complete...");
await capture.SendCompleted;

Log.Information("Waiting for consumes to complete...");
await capture.ConsumeCompleted;

Log.Information("Sends and Consumes completed!");

var messageMetrics = capture.GetMessageMetrics();

Console.WriteLine("Avg Ack Time: {0:F0}ms",
messageMetrics.Average(x => x.AckLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("Min Ack Time: {0:F0}ms",
messageMetrics.Min(x => x.AckLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("Max Ack Time: {0:F0}ms",
messageMetrics.Max(x => x.AckLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("Med Ack Time: {0:F0}ms",
messageMetrics.Median(x => x.AckLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("95t Ack Time: {0:F0}ms",
messageMetrics.Percentile(x => x.AckLatency) * 1000 / Stopwatch.Frequency);

Console.WriteLine("Avg Consume Time: {0:F0}ms",
messageMetrics.Average(x => x.ConsumeLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("Min Consume Time: {0:F0}ms",
messageMetrics.Min(x => x.ConsumeLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("Max Consume Time: {0:F0}ms",
messageMetrics.Max(x => x.ConsumeLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("Med Consume Time: {0:F0}ms",
messageMetrics.Median(x => x.ConsumeLatency) * 1000 / Stopwatch.Frequency);
Console.WriteLine("95t Consume Time: {0:F0}ms",
messageMetrics.Percentile(x => x.ConsumeLatency) * 1000 / Stopwatch.Frequency);

DrawResponseTimeGraph(messageMetrics, m => m.ConsumeLatency);
}

static void RegisterJustSaying(IServiceCollection services)
{
services.AddJustSaying(config =>
{
config.Messaging(x => { x.WithRegion(RegionEndpoint.EUWest1); });
config.Publications(x => { x.WithTopic<BenchmarkMessage>(); });
config.Subscriptions(x => { x.ForTopic<BenchmarkMessage>("justsaying-benchmark"); });
});

services.AddJustSayingHandler<BenchmarkMessage, BenchmarkMessageHander>();
}

static void DrawResponseTimeGraph(MessageMetric[] metrics, Func<MessageMetric, long> selector)
{
long maxTime = metrics.Max(selector);
long minTime = metrics.Min(selector);

const int segments = 10;

long span = maxTime - minTime;
long increment = span / segments;

var histogram = (from x in metrics.Select(selector)
let key = ((x - minTime) * segments / span)
where key >= 0 && key < segments
let groupKey = key
group x by groupKey
into segment
orderby segment.Key
select new { Value = segment.Key, Count = segment.Count() }).ToList();

int maxCount = histogram.Max(x => x.Count);

foreach (var item in histogram)
{
int barLength = item.Count * 60 / maxCount;
Console.WriteLine("{0,5}ms {2,-60} ({1,7})",
(minTime + increment * item.Value) * 1000 / Stopwatch.Frequency,
item.Count,
new string('*', barLength));
}
}
}
}
18 changes: 18 additions & 0 deletions tests/JustSaying.Benchmark/MessageMetric.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
using System;

namespace JustSaying.Benchmark
{
public class MessageMetric
{
public MessageMetric(Guid messageId, long ackLatency, long consumeLatency)
{
MessageId = messageId;
AckLatency = ackLatency;
ConsumeLatency = consumeLatency;
}

public Guid MessageId { get; }
public long AckLatency { get; set; }
public long ConsumeLatency { get; set; }
}
}
Loading

0 comments on commit 9d791a1

Please sign in to comment.