aspnet / Benchmarks

Benchmarks for ASP.NET Core
Other
1.17k stars 237 forks source link

[HttpClient] Warmup measurements might be off #1988

Open ManickaP opened 3 months ago

ManickaP commented 3 months ago

If ran locally and with some of the tracing on, the client fairly often reports this exception:

Unhandled exception: System.Exception: No successful requests during warmup.
   at HttpClientBenchmarks.Program.Measure(Func`1 sendAsync) in /home/manicka/repositories/aspnet-benchmarks/src/BenchmarksApps/HttpClientBenchmarks/Clients/HttpClient/Program.cs:line 312
   at HttpClientBenchmarks.Program.RunScenario() in /home/manicka/repositories/aspnet-benchmarks/src/BenchmarksApps/HttpClientBenchmarks/Clients/HttpClient/Program.cs:line 222
   at HttpClientBenchmarks.Program.<>c.<<Main>b__14_0>d.MoveNext() in /home/manicka/repositories/aspnet-benchmarks/src/BenchmarksApps/HttpClientBenchmarks/Clients/HttpClient/Program.cs:line 58
--- End of stack trace from previous location ---
   at System.CommandLine.Invocation.AnonymousCommandHandler.InvokeAsync(InvocationContext context)
   at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<<BuildInvocationChain>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<<UseParseErrorReporting>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass15_0.<<UseHelp>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass26_0.<<UseVersionOption>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass24_0.<<UseTypoCorrections>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<UseSuggestDirective>b__23_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass21_0.<<UseParseDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<UseDebugDirective>b__8_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<RegisterWithDotnetSuggest>b__7_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass11_0.<<UseExceptionHandler>b__0>d.MoveNext()

While I clearly see in the logs, that requests were exchange with the server.

Note that the client's Main was altered to start with:

public static async Task<int> Main(string[] args)
{
    using var _ = new TestEventListener(Console.Out, "Private.InternalDiagnostics.System.Net.Quic", "Private.InternalDiagnostics.System.Net.Http");
    ...

/cc @CarnaViire

CarnaViire commented 2 months ago

Thanks for the report @ManickaP!

  1. Does the issue persist if you increase the warmup time?
  2. Does it only happen locally? On the same machine?
  3. What are the arguments you are using (either for crank, or for client+server apps)? E.g. does it happen more frequently if you use high number of clients/threads?
  4. Does it only happen with console logging being on? Does it still happen if the listener is substituted with dotnet-trace for the same event providers?
ManickaP commented 2 months ago
  1. Does the issue persist if you increase the warmup time?

Up until warmup 3, with 4 it didn't happen.

  1. Does it only happen locally? On the same machine?

Yes and yes. That's how it happened to me, I haven't tried other combos to confirm whether this is the only set up where it repoduces.

  1. What are the arguments you are using (either for crank, or for client+server apps)? E.g. does it happen more frequently if you use high number of clients/threads?
# client - happens only if ran with locally built runtime
~/repositories/runtime/artifacts/bin/testhost/net9.0-linux-Release-x64/dotnet bin/release/net9.0/HttpClient.dll --address localhost --port 5000 --useHttps true --path /get --scenario get --httpVersion 3.0 --numberOfHttpClients 1 --concurrencyPerHttpClient 1000 --useHttpMessageInvoker true --warmup 1 --duration 5
# server
dotnet run -c release --address localhost --port 5000 --useHttps true --httpVersion 3.0 --responseSize 1024 --http3StreamLimit 0
  1. Does it only happen with console logging being on? Does it still happen if the listener is substituted with dotnet-trace for the same event providers?

With console logging on. dotnet-trace - I haven't tried that.

ManickaP commented 2 months ago

Just FYI, I'm removing all the temporary stuff to test this. From now on, I won't be able to easily give you more info (at least not with the same amount of effort as if you'd do it yourself).