Extend SocketsHttpHandler Connection and Request telemetry by antonfirsov · Pull Request #88853 · dotnet/runtime

antonfirsov · 2023-07-13T17:42:40Z

Add the telemetry events proposed in #85729 and #63159 (comment), with a difference that we log remoteAddress instead of remoteEndPoint since port is already logged as a separate parameter.

I think the changes will not prevent us from implementing #66223, since we can move the logging out of connection constructors.

Full event diff:

- ConnectionEstablished(byte versionMajor, byte versionMinor)+ ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress)- ConnectionClosed(byte versionMajor, byte versionMinor)+ ConnectionClosed(byte versionMajor, byte versionMinor, long connectionId)- RequestHeadersStart()+ RequestHeadersStart(long connectionId)-void Redirect();+void Redirect(string redirectUri);

also: pass around IPEndPoint instead of EndPoint

ghost · 2023-07-13T17:42:54Z

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

Issue Details

Fixes #63159, fixes #85729.

Add the telemetry events proposed in #85729 and #63159 (comment), with a difference that we log remoteAddress instead of remoteEndPoint since port is already logged as a separate parameter.

I think the changes will not prevent us from implementing #66223, since we can move the logging out of connection constructors.

Full event diff:

- ConnectionEstablished(byte versionMajor, byte versionMinor)+ ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress)- ConnectionClosed(byte versionMajor, byte versionMinor)+ ConnectionClosed(byte versionMajor, byte versionMinor, long connectionId)- RequestHeadersStart()+ RequestHeadersStart(long connectionId)-void Redirect();+void Redirect(string redirectUri);

Author:	antonfirsov
Assignees:	-
Labels:	`area-System.Net.Http`
Milestone:	-

antonfirsov · 2023-07-13T17:45:48Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2023-07-13T17:45:53Z

🤡 No commit pushedDate could be found for PR 88853 in repo dotnet/runtime 🤡

antonfirsov · 2023-07-13T17:46:03Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2023-07-13T17:46:11Z

Azure Pipelines successfully started running 1 pipeline(s).

antonfirsov · 2023-07-16T15:32:09Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2023-07-16T15:32:17Z

Azure Pipelines successfully started running 1 pipeline(s).

antonfirsov

@MihaZupan PTAL.

antonfirsov · 2023-07-16T15:36:43Z

+ if (_socketAddress is not null)
+ {
+ tags.Add("socket.address", _socketAddress);
+ }


Edit: Reverted this to simplify Metrics naming discussions. If this is interesting enough to be added after platform complete, we can do it in a follow-up PR.
Given it's available, it looks like it makes make sense to log this also on connection metrics, unless we think it's sensitive info. With the name I'm following OTel recommendation proactively using dot notation with the assumption that we will also change the instrument names by midnight of the 17th.
@davidfowl @noahfalk any objections?

antonfirsov · 2023-07-16T15:38:52Z

 case HttpConnectionKind.Proxy:
 stream = await ConnectToTcpHostAsync(_proxyUri!.IdnHost, _proxyUri.Port, request, async, cancellationToken).ConfigureAwait(false);
+ // remoteEndPoint is returned for diagnostic purposes.
+ remoteEndPoint = GetRemoteEndPoint(stream);


I'm no longer checking for any telemetry || metrics being enabled here, since GetRemoteEndpoint is relatively cheap to run per-connection and likely almost as expensive as the check would be.

antonfirsov · 2023-07-16T15:39:50Z

+ }
+
+ [Event(4, Level = EventLevel.Informational, Version = 1)]
+ private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? socketAddress)


Also going with the socketAddress name here.

A more generic remoteEndPoint may be better if we do decide to allow users to customize the string that is logged here (e.g. they give us a custom stream via ConnectCallback that may not be backed by a socket at all).

MihaZupan · 2023-07-17T06:08:39Z

+ }
+
+ [Event(4, Level = EventLevel.Informational, Version = 1)]
+ private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? socketAddress)


A more generic remoteEndPoint may be better if we do decide to allow users to customize the string that is logged here (e.g. they give us a custom stream via ConnectCallback that may not be backed by a socket at all).

antonfirsov · 2023-07-17T15:43:31Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2023-07-17T15:43:39Z

Azure Pipelines successfully started running 1 pipeline(s).

antonfirsov · 2023-07-17T15:50:17Z

Since we know that (at least for now), a CONNECT request will be done over HTTP/1.1 without a TLS layer

Not since #87638. Anyways, I pushed detection of the address for the non TLS-case in 066391d, but not sure if turning this many privates to internal was worth the feature.

A more generic remoteEndPoint may be better

Switched back the name to remoteAddress. We will have a naming dilemma if we decide to implement this in metrics, since OTel recommends the name server.socket.address.

antonfirsov · 2023-07-17T18:50:45Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2023-07-17T18:50:53Z

Azure Pipelines successfully started running 1 pipeline(s).

antonfirsov · 2023-07-17T22:52:17Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2023-07-17T22:52:24Z

Azure Pipelines successfully started running 1 pipeline(s).

antonfirsov added 7 commits July 10, 2023 23:24

introduce & log connectionId
4409013

ConnectionEstablished: log more
e8dfe2b

RequestHeadersStart: long PaddedFlag
2c5136c
also: pass around IPEndPoint instead of EndPoint

EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest
bb85d16

implement Redirect(redirectUri)
cdca548

ready to go
80353d0

validate payload names in tests
e4e88e2

antonfirsov requested a review from MihaZupan July 13, 2023 17:42

ghost added the area-System.Net.Http label Jul 13, 2023

ghost assigned antonfirsov Jul 13, 2023

MihaZupan approved these changes Jul 14, 2023
View reviewed changes

MihaZupan mentioned this pull request Jul 14, 2023
Add SocketsHttpHandler connection metrics #88893
Merged

MihaZupan added this to the 8.0.0 milestone Jul 14, 2023

antonfirsov added 4 commits July 16, 2023 15:43

Merge branch 'main' into extend-request-telemetry-01
bf5d1a7

adjust logic to current main, log socketaddress to metrics
d6ac30f

update Version on events with signature change
68a9e74

review feedback
8a3fa5f

antonfirsov commented Jul 16, 2023
View reviewed changes

antonfirsov added 2 commits July 17, 2023 04:05

do not report socket.address tag
e2d86be

revert method name change in tests
36e30df

build-analysisBot mentioned this pull request Jul 17, 2023
System.Net.Http.Functional.Tests.HttpMetricsTest_Http11_Async.FailedRequests_ConnectionClosedWhileReceivingHeaders_Recorded timed out #88868
Closed

MihaZupan approved these changes Jul 17, 2023
View reviewed changes

build-analysisBot mentioned this pull request Jul 17, 2023
timeout in FailedRequests_ConnectionClosedWhileReceivingHeaders_Recorded #88921
Closed

antonfirsov added 2 commits July 17, 2023 17:36

detect non-ssl proxy tunnel
066391d

socketAddress -> remoteAddress
91c54ed

dotnet deleted a comment from azure-pipelinesBotJul 17, 2023

build-analysisBot mentioned this pull request Jul 17, 2023
NuGet failing with Response status code does not indicate success: 503 (Service Unavailable) dotnet/arcade#11723
Open
5 tasks

antonfirsov mentioned this pull request Jul 17, 2023
EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest timeout on OSX #89035
Closed

address CI failures
0fa803e

dotnet deleted a comment from azure-pipelinesBotJul 17, 2023

oops
86006f4

dotnet deleted a comment from azure-pipelinesBotJul 17, 2023

antonfirsov merged commit 1db1ba4 into dotnet:mainJul 18, 2023

ghost locked as resolved and limited conversation to collaborators Aug 17, 2023

Uh oh!

Conversation

antonfirsov commented Jul 13, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ghost commented Jul 13, 2023

Uh oh!

antonfirsov commented Jul 13, 2023

Uh oh!

azure-pipelinesBot commented Jul 13, 2023• edited by antonfirsov Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

antonfirsov commented Jul 13, 2023

Uh oh!

azure-pipelinesBot commented Jul 13, 2023

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

antonfirsov commented Jul 16, 2023

Uh oh!

azure-pipelinesBot commented Jul 16, 2023

Uh oh!

antonfirsov left a comment

Choose a reason for hiding this comment

Uh oh!

antonfirsovJul 16, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

antonfirsovJul 16, 2023

Choose a reason for hiding this comment

Uh oh!

antonfirsovJul 16, 2023

Choose a reason for hiding this comment

Uh oh!

MihaZupanJul 17, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

MihaZupanJul 17, 2023

Choose a reason for hiding this comment

Uh oh!

antonfirsov commented Jul 17, 2023

Uh oh!

azure-pipelinesBot commented Jul 17, 2023

Uh oh!

antonfirsov commented Jul 17, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

antonfirsov commented Jul 17, 2023

Uh oh!

azure-pipelinesBot commented Jul 17, 2023

Uh oh!

antonfirsov commented Jul 17, 2023

Uh oh!

azure-pipelinesBot commented Jul 17, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

antonfirsov commented Jul 13, 2023•
edited
Loading

azure-pipelinesBot commented Jul 13, 2023•
edited by antonfirsov
Loading

antonfirsovJul 16, 2023•
edited
Loading

antonfirsov commented Jul 17, 2023•
edited
Loading