Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add HTTP Request/Response Headers/Content Start/Stop events #41590

Merged
merged 1 commit into from
Aug 31, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 33 additions & 3 deletions src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs
Original file line number Diff line number Diff line change
Expand Up @@ -91,23 +91,53 @@ private void RequestLeftQueue(double timeOnQueueMilliseconds, byte versionMajor,
}

[Event(7, Level = EventLevel.Informational)]
public void ResponseHeadersBegin()
public void RequestHeadersStart()
{
WriteEvent(eventId: 7);
}

[Event(8, Level = EventLevel.Informational)]
public void ResponseContentStart()
public void RequestHeadersStop()
{
WriteEvent(eventId: 8);
}

[Event(9, Level = EventLevel.Informational)]
public void ResponseContentStop()
public void RequestContentStart()
{
WriteEvent(eventId: 9);
}

[Event(10, Level = EventLevel.Informational)]
public void RequestContentStop(long contentLength)
{
WriteEvent(eventId: 10, contentLength);
}

[Event(11, Level = EventLevel.Informational)]
public void ResponseHeadersStart()
{
WriteEvent(eventId: 11);
}

[Event(12, Level = EventLevel.Informational)]
public void ResponseHeadersStop()
{
WriteEvent(eventId: 12);
}

[Event(13, Level = EventLevel.Informational)]
public void ResponseContentStart()
{
WriteEvent(eventId: 13);
}

[Event(14, Level = EventLevel.Informational)]
public void ResponseContentStop()
{
WriteEvent(eventId: 14);
}

[NonEvent]
public void Http11ConnectionEstablished()
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,8 @@ public ChunkedEncodingWriteStream(HttpConnection connection) : base(connection)

public override void Write(ReadOnlySpan<byte> buffer)
{
BytesWritten += buffer.Length;

HttpConnection connection = GetConnectionOrThrow();
Debug.Assert(connection._currentRequest != null);

Expand All @@ -39,6 +41,8 @@ public override void Write(ReadOnlySpan<byte> buffer)

public override ValueTask WriteAsync(ReadOnlyMemory<byte> buffer, CancellationToken ignored)
{
BytesWritten += buffer.Length;

HttpConnection connection = GetConnectionOrThrow();
Debug.Assert(connection._currentRequest != null);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@ public ContentLengthWriteStream(HttpConnection connection) : base(connection)

public override void Write(ReadOnlySpan<byte> buffer)
{
BytesWritten += buffer.Length;

// Have the connection write the data, skipping the buffer. Importantly, this will
// force a flush of anything already in the buffer, i.e. any remaining request headers
// that are still buffered.
Expand All @@ -27,6 +29,8 @@ public override void Write(ReadOnlySpan<byte> buffer)

public override ValueTask WriteAsync(ReadOnlyMemory<byte> buffer, CancellationToken ignored) // token ignored as it comes from SendAsync
{
BytesWritten += buffer.Length;

// Have the connection write the data, skipping the buffer. Importantly, this will
// force a flush of anything already in the buffer, i.e. any remaining request headers
// that are still buffered.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -1354,6 +1354,8 @@ private async ValueTask<Http2Stream> SendHeadersAsync(HttpRequestMessage request
ArrayBuffer headerBuffer = default;
try
{
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart();

// Serialize headers to a temporary buffer, and do as much work to prepare to send the headers as we can
// before taking the write lock.
headerBuffer = new ArrayBuffer(InitialConnectionBufferSize, usePool: true);
Expand Down Expand Up @@ -1434,6 +1436,9 @@ private async ValueTask<Http2Stream> SendHeadersAsync(HttpRequestMessage request

return s.mustFlush || s.endStream;
}, cancellationToken).ConfigureAwait(false);

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStop();

return http2Stream;
}
catch
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -194,6 +194,8 @@ public async Task SendRequestBodyAsync(CancellationToken cancellationToken)
{
using var writeStream = new Http2WriteStream(this);

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestContentStart();

ValueTask vt = _request.Content.InternalCopyToAsync(writeStream, context: null, _requestBodyCancellationSource.Token);
if (vt.IsCompleted)
{
Expand All @@ -208,6 +210,8 @@ public async Task SendRequestBodyAsync(CancellationToken cancellationToken)

await vt.ConfigureAwait(false);
}

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestContentStop(writeStream.BytesWritten);
}

if (NetEventSource.Log.IsEnabled()) Trace($"Finished sending request body.");
Expand Down Expand Up @@ -568,8 +572,6 @@ public void OnHeader(ReadOnlySpan<byte> name, ReadOnlySpan<byte> value)

public void OnHeadersStart()
{
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersBegin();

Debug.Assert(!Monitor.IsEntered(SyncObject));
lock (SyncObject)
{
Expand Down Expand Up @@ -839,6 +841,8 @@ public async Task ReadResponseHeadersAsync(CancellationToken cancellationToken)
bool emptyResponse;
try
{
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStart();

// Wait for response headers to be read.
bool wait;

Expand All @@ -851,6 +855,8 @@ public async Task ReadResponseHeadersAsync(CancellationToken cancellationToken)
(wait, emptyResponse) = TryEnsureHeaders();
Debug.Assert(!wait);
}

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();
}
catch
{
Expand Down Expand Up @@ -1344,6 +1350,8 @@ private sealed class Http2WriteStream : HttpBaseStream
{
private Http2Stream? _http2Stream;

public long BytesWritten { get; private set; }

public Http2WriteStream(Http2Stream http2Stream)
{
Debug.Assert(http2Stream != null);
Expand All @@ -1370,6 +1378,8 @@ protected override void Dispose(bool disposing)

public override ValueTask WriteAsync(ReadOnlyMemory<byte> buffer, CancellationToken cancellationToken)
{
BytesWritten += buffer.Length;

Http2Stream? http2Stream = _http2Stream;

if (http2Stream == null)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -364,6 +364,8 @@ public async Task<HttpResponseMessage> SendAsyncCore(HttpRequestMessage request,
CancellationTokenRegistration cancellationRegistration = RegisterCancellation(cancellationToken);
try
{
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart();

Debug.Assert(request.RequestUri != null);
// Write request line
await WriteStringAsync(normalizedMethod.Method, async).ConfigureAwait(false);
Expand Down Expand Up @@ -457,6 +459,8 @@ public async Task<HttpResponseMessage> SendAsyncCore(HttpRequestMessage request,
// CRLF for end of headers.
await WriteTwoBytesAsync((byte)'\r', (byte)'\n', async).ConfigureAwait(false);

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStop();

if (request.Content == null)
{
// We have nothing more to send, so flush out any headers we haven't yet sent.
Expand Down Expand Up @@ -535,7 +539,7 @@ public async Task<HttpResponseMessage> SendAsyncCore(HttpRequestMessage request,
var response = new HttpResponseMessage() { RequestMessage = request, Content = new HttpConnectionResponseContent() };
ParseStatusLine(await ReadNextResponseHeaderLineAsync(async).ConfigureAwait(false), response);

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersBegin();
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStart();

// Multiple 1xx responses handling.
// RFC 7231: A client MUST be able to parse one or more 1xx responses received prior to a final response,
Expand Down Expand Up @@ -584,6 +588,8 @@ public async Task<HttpResponseMessage> SendAsyncCore(HttpRequestMessage request,
ParseHeaderNameValue(this, line, response);
}

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();

if (allowExpect100ToContinue != null)
{
// If we sent an Expect: 100-continue header, and didn't receive a 100-continue. Handle the final response accordingly.
Expand Down Expand Up @@ -817,6 +823,9 @@ private async ValueTask SendRequestContentAsync(HttpRequestMessage request, Http
// Now that we're sending content, prohibit retries on this connection.
_canRetry = false;

Debug.Assert(stream.BytesWritten == 0);
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestContentStart();

// Copy all of the data to the server.
if (async)
{
Expand All @@ -833,6 +842,8 @@ private async ValueTask SendRequestContentAsync(HttpRequestMessage request, Http
// Flush any content that might still be buffered.
await FlushAsync(async).ConfigureAwait(false);

if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestContentStop(stream.BytesWritten);

if (NetEventSource.Log.IsEnabled()) Trace("Finished sending request content.");
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,8 @@ internal partial class HttpConnection : IDisposable
{
private abstract class HttpContentWriteStream : HttpContentStream
{
public long BytesWritten { get; protected set; }

public HttpContentWriteStream(HttpConnection connection) : base(connection) =>
Debug.Assert(connection != null);

Expand Down
Loading