HttpClientHandler request metrics

[antonfirsov]

Initial implementation for request metrics from #84978 doing most of the work in an internal MetricsHandler, assuming API proposals #86281 and #86961 will be approved. Connection metrics shall be implemented as SocketsHttpHandler internals in a way analogous to existing counters, I plan to do that in a separate PR.

Deviations from the spec in #84978:

• http-client-request-duration: protocol and status-code are optional, since we cannot log them when the underlying handler throws without returning an HttpResponsMessage
• http-client-current-requests: no protocol tag, since there is no reliable way to report correct value after downgrades
• http-client-failed-requests:
  • Custom tags are present, since it was trivial to add them. Let me know if I should remove them.
  • protocol is optional for the same reason as with current-requests
  • status-code is optionally present
  • No exception-name, tag because it has little value on it's own (only 2 types of top-level exceptions are thrown). Instead, I prefer to add a request-error tag based on [API Proposal]: Support error codes for HttpRequestException #76644 when implementing that proposal.

Remaining work:

• Integrate with browser and Mobile variants of HttpClientHandler
• If changes are requested to [API Proposal]: pass custom tags for metrics enrichment in HttpClientHandler #86281 and [API Proposal]: Pass Meter to HttpClientHandler and SocketsHttpHandler #86961, implement them
• Decide if we are happy with the HttpResponseMessage.RequestFailedMetricsLogger hack. If not, implement it in another way. See HttpClientHandler request metrics #87319 (comment).

/cc @JamesNK @noahfalk @dpk83 @stephentoub

Fixes #86281, fixes #86961, contributes to #84978.

[dotnet-issue-labeler]

Note regarding the new-api-needs-documentation label:

This serves as a reminder for when your PR is modifying a ref *.cs file and adding/modifying public APIs, please make sure the API implementation in the src *.cs file is documented with triple slash comments, so the PR reviewers can sign off that change.

[ghost]

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Initial implementation for request metrics from #84978 doing most of the work in an internal MetricsHandler, assuming API proposals #86281 and #86961 will be approved. Connection metrics shall be implemented as SocketsHttpHandler internals in a way analogous to existing counters, I plan to do that in a separate PR.

Deviations from the spec in #84978:

• http-client-request-duration: protocol and status-code are optional, since we cannot log them when the underlying handler throws without returning an HttpResponsMessage
• http-client-current-requests: no protocol tag, since there is no reliable way to report correct value after downgrades
• http-client-failed-requests:
  • Custom tags are present, since it was trivial to add them. Let me know if I should remove them.
  • protocol is optional for the same reason as with current-requests
  • status-code is optionally present
  • No exception-name, tag because it has little value on it's own (only 2 types of top-level exceptions are thrown). Instead, I prefer to add a request-error tag based on [API Proposal]: Support error codes for HttpRequestException #76644 when implementing that proposal.

Remaining work:

• Integrate with browser and Mobile variants of HttpClientHandler
• If changes are requested to [API Proposal]: pass custom tags for metrics enrichment in HttpClientHandler #86281 and [API Proposal]: Pass Meter to HttpClientHandler and SocketsHttpHandler #86961, implement them
• Decide if we are happy with the HttpResponseMessage._requestFailedMetricsLogger hack. If not, implement it in another way.

Author:	antonfirsov
Assignees:	-
Labels:	area-System.Net.Http, new-api-needs-documentation
Milestone:	-

[antonfirsov]

@noahfalk @MihaZupan continuing the discussion on perf here.

Edit: I made a mistake in my concurrent benchmarks, and had to update them once again, see my next comment with updated results.

Its more overhead than I was anticipating

Note that this benchmark is an extreme scenario (no actual network IO, very small request/response, no header parsing ...) engineered to make the overhead well-measurable. In real life the differences may become very small. When it comes to the memory footprint of Enrichment, I think the easiest way to reduce it is to address #88750.

[MihaZupan]

These numbers look perfectly reasonable to me

[antonfirsov]

@MihaZupan @noahfalk apologies, I made a mistake in my parallel benchmarks, they were doing stuff synchronously. Copying the updated results below.

The overhead resulting from the presence of MetricsHandler seems to be still within the margin of error, see the NoMetrics case, PR vs main.

However, it looks like there is some contention over the pool in this extreme case. IMO it's not significant, should be even less noticeable in real-life cases and worth it bc of the the savings we make on memory footprint.

main

|    Method | Concurrency |     Mean |    Error |   StdDev |   Gen0 |   Gen1 | Allocated |
|---------- |------------ |---------:|---------:|---------:|-------:|-------:|----------:|
| NoMetrics |          20 | 16.67 us | 0.650 us | 1.897 us | 4.3030 | 0.1221 |  43.38 KB |

PR - no pooling

|                   Method | Concurrency |     Mean |    Error |   StdDev |   Median |   Gen0 |   Gen1 | Allocated |
|------------------------- |------------ |---------:|---------:|---------:|---------:|-------:|-------:|----------:|
|                NoMetrics |          20 | 16.88 us | 0.624 us | 1.809 us | 16.92 us | 4.3030 | 0.1221 |  43.37 KB |
|              WithMetrics |          20 | 17.70 us | 0.925 us | 2.625 us | 16.40 us | 4.5166 | 0.1221 |  46.51 KB |
| WithMetricsAndEnrichment |          20 | 18.84 us | 0.557 us | 1.642 us | 18.43 us | 5.9509 | 0.4272 |  60.11 KB |

PR - pooling

|                   Method | Concurrency |     Mean |    Error |   StdDev |   Median |   Gen0 |   Gen1 | Allocated |
|------------------------- |------------ |---------:|---------:|---------:|---------:|-------:|-------:|----------:|
|                NoMetrics |          20 | 17.28 us | 0.595 us | 1.707 us | 17.17 us | 4.3030 | 0.1526 |  43.38 KB |
|              WithMetrics |          20 | 17.03 us | 0.379 us | 1.086 us | 16.77 us | 4.6082 | 0.1984 |  46.51 KB |
| WithMetricsAndEnrichment |          20 | 21.69 us | 1.403 us | 4.138 us | 19.98 us | 5.0659 | 0.2441 |  51.23 KB |

[noahfalk]

Thanks @antonfirsov - I'm glad to see there was no appreciable difference in the baseline vs. PR in the NoMetrics case. The revised benchmark also suggests much lower overhead switching from NoMetrics to Metrics which was nice. If networking team + @stephentoub is happy, I'm happy.

Note that this benchmark is an extreme scenario

Yep I know this is a microbenchmark that is stressing the code at ~1M RPS. I don't imagine real world scenarios look quite that extreme but it does help measure how we impacted things. I could imagine a real world scenario where request latency is in the low ms range and parallelism is very high (>1000 concurrent requests). Although that combination still wouldn't be as stressful as the microbenchmark I'm guessing it could be 100K+ RPS which is not too far off.

[antonfirsov]

/azp run runtime-extra-platforms

[azure-pipelines]

Azure Pipelines successfully started running 1 pipeline(s).

[antonfirsov]

CI failures are unrelated, merging to unblock work depending on this.