0

Long story short - I can't explain why my console app with Kestrel server runs fast only in profiler, Debug or Release - doesn't matter.

The long story

I created small message-based framework that can create instance of specific class and execute one of its methods based on the argument type used in this method. Pretty much like MediatR framework. At the startup, the app gathers available assemblies and creates a dictionary where assembly name or a message type is the key and appropriate MethodInfo is the value. When specific message is sent, the relevant MethodInfo makes a method call via reflection.

Message handler sample that will be called via reflection

public class DemoActor
{
  public virtual Task<DemoResponse> Create(CreateMessage message)
  {
    return Task.FromResult(new DemoResponse { Data = "Hello" });
  }
}

Reflection call sample

if (Processors.TryGetValue(descriptor, out MethodInfo processor))
{
  instance = Activator.CreateInstance(processor.DeclaringType); // cache 
  response = processor.Invoke(instance, message);
}

Performance check

var stopWatch = new Stopwatch();
stopWatch.Start();

for (var i = 0; i < 100000; i++) scene.Send<DemoResponse>("Demo", message).Result;

stopWatch.Stop();
var ts = stopWatch.Elapsed;
string elapsedTime = String.Format("{0:00}:{1:00}:{2:00}.{3:00}",
  ts.Hours, ts.Minutes, ts.Seconds,
  ts.Milliseconds / 10);
Console.WriteLine("RunTime " + elapsedTime);

Preliminary testing showed that the simplest local call executed in the loop 100K times takes around 6 seconds. I immediately assumed that this is due to the reflection slowness and replaced reflection call with Delegate.CreateDelegate, then with Expression.Compile. This didn't make any difference, at all. Switching between Debug and Release mode also didn't make any difference.

Then, I tried to use built-in VS 2022 profiler, specifically, the one for async calls, and execution time magically dropped from 6 seconds to less than 1 second.

Profiler

System

Windows 10 Pro x64, Quad Core i7 2.4 GHz, SSD, RAM 32 GB, .NET 6.0, VS 2022 Preview 3

Questions

  • Why there is no difference between reflection, delegates, and expressions?
  • Why there is no difference between Debug and Release configuration?
  • What is the right way to test performance in this case?

Update

Appeared to be I was always running build with attached debugger that was causing slowness. Published version runs as fast as profiler and testing performance with StopWatch should be enough in this case. Meanwhile, I still can't explain why there is no boost after switching from reflection calls to compiled delegates.

Anonymous
  • 1,823
  • 2
  • 35
  • 74
  • 1
    Your use of .Result seems suspect. – David L Feb 08 '22 at 23:35
  • @DavidL This is a part of the sample app, not the library itself, and it's for demonstration purposes only. At the moment I'm not testing Sync vs Async. The question is why execution time changes when the code doesn't and it doesn't depend on how the call is being awaited, whether the thread is blocked or not. Profiler runs 6+ times faster even with the blocked thread – Anonymous Feb 08 '22 at 23:48
  • It's possible that your performance measurement is slower than the call itself. – Jeremy Lakeman Feb 08 '22 at 23:54
  • 1
    https://devblogs.microsoft.com/dotnet/performance-improvements-in-net-6/#reflection – shingo Feb 09 '22 at 04:43
  • @shingo Thanks. Informative. According to benchmarks and discussions, reflection is expected to be pretty close to direct calls and doesn't need optimization anymore? – Anonymous Feb 09 '22 at 07:59
  • 1
    No it's optimized and still slow. But I think it is faster than DynamicInvoke. – shingo Feb 09 '22 at 08:38

0 Answers0