Added some kestrel event counters #21649

davidfowl · 2020-05-09T06:21:53Z

Connection counters

Connection queue length - This is the amount of connections accepted and queued in the thread pool.
Connection count - The number of connections
Total connections - The total number of connections.
Connection Rate - Connections per second

TLS counters

Total TLS handshakes - The total number of TLS handshakes
Current TLS handshakes - The number of TLS handshakes being performed currently
Failed TLS handshakes - The number of failed TLS handshakes
TLS handshake Rate - TLS handshake per second

Request counters

Request Queue Length - The number of HTTP/2 and HTTP/3 connections queued in the thread pool.
Current Upgraded Requests - The number of HTTP/1 requests that are currently upgraded (basiacally the number of concurrent websocket connections)
Also added event source events to Kestrel (which I'm beginning to get very conflicted about 😄 )

Contributes to #4769

Notes: The Request Queue Length only works for HTTP/2 and HTTP/3. The Connection Queue doubles as the request queue for HTTP/1.

cc @shirhatti

- Connection queue length - This is the amount of connections accepted and queued in the thread pool. - Connection count - The number of connections - Total connections - The total number of connections ever connected. - Connection Rate - Connections per second Contributes to #4769

- Current TLS handshakes - Total TLS handshakes - Failed TLS handshakes - TLS handshake per second

src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelEventSource.cs

- Add TLS version to handshake events - Add HTTP version to request queue events - Renamed HTTP/2 request queue length to http request queue

- Event sources don't like null values - Make the level information for most events

- Add more data to request events

src/Servers/Kestrel/Core/src/Internal/Http2/Http2StreamOfT.cs

Tratcher · 2020-05-11T19:55:08Z

src/Servers/Kestrel/Core/src/Internal/Http2/Http2Connection.cs

@@ -1002,6 +1002,7 @@ private void StartStream()
                throw;
            }

+            KestrelEventSource.Log.RequestQueued(_currentHeadersStream, AspNetCore.Http.HttpProtocol.Http2);


This seems pretty artificial. This is just an async offload, not a meaningful queue. Requests can become async and get queued to the threadpool many times throughout their lifetime, why is this one special? Do we see requests consistently piling up here, more than other async calls?

Or maybe it's just a naming thing? Is what you're really trying to say here that we've received a complete request and are getting ready to start processing? (Not sure why you'd need Dequeued in that case though).

While it's just another work item, I think this could be useful to quantify just how backlogged the thread pool is. It's one thing to say there's a thousand pending work items, but another to say there are thousand pending requests.

It's literally called QueueUserWorkitem 😄 , it's absolutely a queue. We're just counting how may items are ours vs global in the pool like @halter73 says.

The same request will end up back in the same threadpool queue as soon as some middleware goes async. What's special about this specific instance? I don't see this producing any actionable data (unless if the queue is completely stalled?).

Have you produced any graphs with this yet? I'm really curious what they'd show.

It's useful to see this number be non-zero.

Under sustained load, wouldn't this always be non-zero?

Under what conditions do you expect this number to diverge from it's usual value?

Under sustained load, wouldn't this always be non-zero?

It'll be non-zero if there's blocking or a huge amount of load.

Under what conditions do you expect this number to diverge from it's usual value?

Starvation/blocking and it'll show up under a thing called connections/requests which is why I like it more than just having a single "threadpool queue" counter (though that is useful as well).

For a new request on an existing connection, I'm assuming this is the first threadpool dispatch. However. in a threadpool starved scenario, this won't be the first threadpool dispatch for a request on a new connection right?

Am I correct in understanding that only the first scenario (i.e., requests on existing connections) will cause this counter to diverge from zero?

For HTTP/1 the request queue is the connection queue for HTTP/2 and 3 we queue per request

This got me thinking maybe we should add a PollingCounter for concurrent idle/active connections (e.g. connections (not) in the keep-alive state). It wouldn't be equivalent to "current-connections" - "current-requests" because of HTTP/2 and 3. It might even be different for HTTP/1.x if we consider a connection "active" as soon as we get any part of the request line and/or headers.

halter73 · 2020-05-11T20:48:38Z

src/Servers/Kestrel/Core/src/Middleware/HttpsConnectionMiddleware.cs

@@ -169,6 +169,7 @@ public async Task OnConnectionAsync(ConnectionContext context)
                    {
                        selector = (sender, name) =>
                        {
+                            feature.HostName = name;


Should write log the hostname when a single cert is used and not an SNI callback meaning _serverCertificateSelector is null? We could always pass in a ServerCertificateSelectionCallback and just have it return the _serverCertificate when no custom callback is configured.

Also, don't you love it when you thought you left a comment days ago, but you accidentally started a review you didn't finsih?

Should write log the hostname when a single cert is used and not an SNI callback meaning _serverCertificateSelector is null? We could always pass in a ServerCertificateSelectionCallback and just have it return the _serverCertificate when no custom callback is configured.

Where do I get that information? Is it on SSlStream?

Where do I get that information? Is it on SSlStream?

I don't know. I don't think so. That's why I suggested always using a ServerCertificateSelectionCallback, so the hostname could be captured inside the callback.

src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelEventSource.cs

shirhatti · 2020-05-12T18:29:18Z

@sebastienros We just added new EventCounters. I've filed an issue for having these enabled in our benchmarks aspnet/Benchmarks#1513

davidsh · 2020-06-02T18:47:52Z

Added new issue dotnet/diagnostics#1188 to make sure 'dotnet-counters' tool is updated for these new counters.

davidfowl requested review from halter73, jkotalik and Tratcher as code owners May 9, 2020 06:21

ghost added the area-servers label May 9, 2020

davidfowl added 3 commits May 8, 2020 23:22

Copy pasta

16e91a9

Added TLS counters

ff24716

- Current TLS handshakes - Total TLS handshakes - Failed TLS handshakes - TLS handshake per second

Added HTTP/2 queue length counter

dbed2e2

JamesNK reviewed May 9, 2020

View reviewed changes

src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelEventSource.cs Outdated Show resolved Hide resolved

davidfowl added 5 commits May 9, 2020 09:30

Improve the event information

9be15e4

- Add TLS version to handshake events - Add HTTP version to request queue events - Renamed HTTP/2 request queue length to http request queue

Add the host name to the TLS handshake stop

cb3f353

Clean up

5378784

- Event sources don't like null values - Make the level information for most events

Added counter for upgraded connections

01376ec

More tweaks

a52b20c

- Add more data to request events

davidfowl commented May 10, 2020

View reviewed changes

src/Servers/Kestrel/Core/src/Internal/Http2/Http2StreamOfT.cs Outdated Show resolved Hide resolved

Tratcher reviewed May 11, 2020

View reviewed changes

halter73 reviewed May 11, 2020

View reviewed changes

halter73 approved these changes May 11, 2020

View reviewed changes

shirhatti reviewed May 12, 2020

View reviewed changes

src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelEventSource.cs Outdated Show resolved Hide resolved

PR feedback

980d750

davidfowl merged commit 5a0c097 into master May 12, 2020

davidfowl deleted the davidfowl/add-kestrel-counters branch May 12, 2020 18:04

shirhatti mentioned this pull request May 12, 2020

Enable collection of new EventCounters in Kestrel aspnet/Benchmarks#1513

Closed

shirhatti mentioned this pull request May 12, 2020

Add docs on the EventCounters emitted by ASP.NET Core dotnet/AspNetCore.Docs#18272

Open

BrennanConroy mentioned this pull request May 13, 2020

Add open connections PollingCounter #21488

Closed

davidsh mentioned this pull request Jun 2, 2020

Update dotnet-counters help text for .NET 5 dotnet/diagnostics#1188

Closed

This was referenced Jun 4, 2020

Add new telemetry EventCounter/EventSource tracing to System.Net.* dotnet/runtime#37428

Closed

Add telemetry to System.Net.Http dotnet/runtime#37619

Merged

halter73 mentioned this pull request Sep 21, 2020

Document Kestrel breaking changes, new API and new config in 5.0 #26141

Closed

JamesNK mentioned this pull request Sep 15, 2021

5.0 docs: Kestrel event counters dotnet/AspNetCore.Docs#23321

Closed

amcasey added area-networking Includes servers, yarp, json patch, bedrock, websockets, http client factory, and http abstractions and removed area-runtime labels Jun 6, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Added some kestrel event counters #21649

Added some kestrel event counters #21649

davidfowl commented May 9, 2020 •

edited

Loading

Tratcher May 11, 2020

halter73 May 11, 2020

davidfowl May 11, 2020

Tratcher May 11, 2020 •

edited

Loading

Tratcher May 11, 2020

shirhatti May 11, 2020

davidfowl May 12, 2020

shirhatti May 12, 2020

davidfowl May 12, 2020

halter73 May 12, 2020

halter73 May 11, 2020

davidfowl May 11, 2020

halter73 May 11, 2020

shirhatti commented May 12, 2020

davidsh commented Jun 2, 2020

Added some kestrel event counters #21649

Added some kestrel event counters #21649

Conversation

davidfowl commented May 9, 2020 • edited Loading

Connection counters

TLS counters

Request counters

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Tratcher May 11, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

shirhatti commented May 12, 2020

davidsh commented Jun 2, 2020

davidfowl commented May 9, 2020 •

edited

Loading

Tratcher May 11, 2020 •

edited

Loading