Eventos de rede no .NET

Os eventos dão-lhe acesso a:

Carimbos de data/hora precisos durante toda a vida útil de uma operação. Por exemplo, quanto tempo levou para se conectar ao servidor e quanto tempo levou uma solicitação HTTP para receber cabeçalhos de resposta.
Depurar/rastrear informações que podem não ser obtidas por outros meios. Por exemplo, que tipo de decisões o pool de conexões tomou e qual foi o motivo.

A instrumentação é baseada no EventSource, permitindo que você colete essas informações de dentro e de fora do processo.

Fornecedores de eventos

As informações de rede são divididas entre os seguintes provedores de eventos:

System.Net.Http (HttpClient e SocketsHttpHandler)
System.Net.NameResolution (Dns)
System.Net.Security (SslStream)
System.Net.Sockets
Microsoft.AspNetCore.Hosting
Microsoft-AspNetCore-Server-Kestrel

A telemetria tem alguma sobrecarga de desempenho quando ativada, portanto, certifique-se de se inscrever apenas em provedores de eventos nos quais você está realmente interessado.

Consumir eventos diretamente no processo

Prefira a coleta em processo quando possível para facilitar a correlação e a análise de eventos.

EventListener

EventListener é uma API que permite ouvir eventos EventSource a partir do mesmo processo que os produziu.

using System.Diagnostics.Tracing;

using var listener = new MyListener();

using var client = new HttpClient();
await client.GetStringAsync("https://httpbin.org/get");

public sealed class MyListener : EventListener
{
    protected override void OnEventSourceCreated(EventSource eventSource)
    {
        if (eventSource.Name == "System.Net.Http")
        {
            EnableEvents(eventSource, EventLevel.Informational);
        }
    }

    protected override void OnEventWritten(EventWrittenEventArgs eventData)
    {
        Console.WriteLine($"{DateTime.UtcNow:ss:fff} {eventData.EventName}: " +
            string.Join(' ', eventData.PayloadNames!.Zip(eventData.Payload!).Select(pair => $"{pair.First}={pair.Second}")));
    }
}

O código anterior imprime uma saída semelhante à seguinte:

00:598 RequestStart: scheme=https host=httpbin.org port=443 pathAndQuery=/get versionMajor=1 versionMinor=1 versionPolicy=0
01:470 ConnectionEstablished: versionMajor=1 versionMinor=1
01:474 RequestLeftQueue: timeOnQueueMilliseconds=470,6214 versionMajor=1 versionMinor=1
01:476 RequestHeadersStart:
01:477 RequestHeadersStop:
01:592 ResponseHeadersStart:
01:593 ResponseHeadersStop:
01:633 ResponseContentStart:
01:635 ResponseContentStop:
01:635 RequestStop:
01:637 ConnectionClosed: versionMajor=1 versionMinor=1

Yarp.Telemetria.Consumo

Embora a EventListener abordagem descrita acima seja útil para uma experimentação e depuração rápidas, as APIs não são fortemente tipadas e obrigam o utilizador a depender dos detalhes de implementação da biblioteca instrumentada.

Para resolver isso, o .NET criou uma biblioteca que facilita o consumo de eventos de rede no processo: Yarp.Telemetry.Consumption. Embora o pacote seja atualmente mantido como parte do projeto YARP , ele pode ser usado em qualquer aplicativo .NET.

Para usá-lo, implemente as interfaces e métodos (eventos) em que você está interessado:

public sealed class MyTelemetryConsumer : IHttpTelemetryConsumer, INetSecurityTelemetryConsumer
{
    public void OnRequestStart(DateTime timestamp, string scheme, string host, int port, string pathAndQuery, int versionMajor, int versionMinor, HttpVersionPolicy versionPolicy)
    {
        Console.WriteLine($"Request to {host} started at {timestamp}");
    }

    public void OnHandshakeStart(DateTime timestamp, bool isServer, string targetHost)
    {
        Console.WriteLine($"Starting TLS handshake with {targetHost}");
    }
}

E registre as implementações com seu contêiner DI:

services.AddTelemetryConsumer<MyTelemetryConsumer>();

A biblioteca fornece as seguintes interfaces fortemente tipadas:

Estes callbacks são chamados como parte da operação instrumentada, portanto, a orientação geral de logging se aplica. Você deve evitar bloquear ou executar cálculos onerosos como parte do retorno de chamada. Descarregue qualquer trabalho de pós-processamento para threads diferentes para evitar adicionar latência à operação subjacente.

A consumir eventos vindos de fora do processo

dotnet-trace

dotnet-trace é uma ferramenta multiplataforma que permite a recolha de rastreamentos do .NET Core de um processo em execução sem um perfilador nativo.

dotnet tool install --global dotnet-trace

dotnet-trace collect --providers System.Net.Http,System.Net.Security,System.Threading.Tasks.TplEventSource:0x80:4 --process-id 1234

Para todos os comandos e parâmetros disponíveis, consulte os documentos dotnet-trace.

Você pode analisar o arquivo capturado .nettrace no Visual Studio ou PerfView. Para obter mais informações, consulte a documentação de análise do dotnet-trace.

PerfView

O PerfView é uma ferramenta avançada e gratuita de análise de desempenho. Ele roda no Windows, mas também pode analisar vestígios capturados no Linux.

Para configurar a lista de eventos a capturar, especifique-os em Advanced Options / Additional Providers:

*System.Net.Sockets,*System.Net.NameResolution,*System.Net.Http,*System.Net.Security

TraceEvent

TraceEvent é uma biblioteca que permite consumir eventos de diferentes processos em tempo real. dotnet-trace e PerfView ambos confiam nele.

Se você quiser processar eventos programaticamente e em tempo real, consulte os TraceEvent documentos.

Iniciar e Parar eventos

Operações maiores geralmente começam com um Start evento e terminam com um Stop evento. Por exemplo, você verá RequestStart/RequestStop eventos de System.Net.Http ouConnectStart/ConnectStop eventos de .System.Net.Sockets

Embora grandes operações como essas muitas vezes garantam que um Stop evento sempre estará presente, nem sempre é esse o caso. Por exemplo, ver o RequestHeadersStart evento de System.Net.Http não garante que RequestHeadersStop também será registrado.

Correlação de eventos

Agora que você sabe como observar esses eventos, muitas vezes precisa correlacioná-los juntos, geralmente à solicitação HTTP de origem.

Prefira a coleta em processo quando possível para facilitar a correlação e a análise de eventos.

Correlação durante o processo

Como a rede usa E/S assíncrona, você não pode assumir que o thread que concluiu uma determinada solicitação também é o thread que a iniciou. Isso significa que você não pode usar [ThreadLocal] estáticas para correlacionar eventos, mas pode usar AsyncLocal. Familiarize-se com AsyncLocal, pois este tipo é fundamental para correlacionar o trabalho em diferentes subprocessos.

AsyncLocal Permite aceder ao mesmo estado mais profundamente no fluxo assíncrono de uma operação. AsyncLocal os valores apenas fluem para baixo (mais profundamente na pilha de chamadas assíncronas) e não propagam as alterações até o chamador.

Considere o seguinte exemplo:

AsyncLocal<int> asyncLocal = new();
asyncLocal.Value = 1;

await WorkAsync();
Console.WriteLine($"Value after WorkAsync: {asyncLocal.Value}");

async Task WorkAsync()
{
    Console.WriteLine($"Value in WorkAsync: {asyncLocal.Value}");
    asyncLocal.Value = 2;
    Console.WriteLine($"Value in WorkAsync: {asyncLocal.Value}");
}

Este código gera o seguinte resultado:

Value in WorkAsync: 1
Value in WorkAsync: 2
Value after WorkAsync: 1

O valor 1 fluiu do chamador para WorkAsync, mas a modificação em WorkAsync (2) não fluiu de volta para o chamador.

Como os eventos de telemetria (e seus retornos de chamada correspondentes) ocorrem como parte da operação subjacente, eles acontecem dentro do mesmo escopo assíncrono do chamador que iniciou a solicitação. Isso significa que tu podes observar asyncLocal.Value de dentro do callback, mas se definires o valor no callback, nada será capaz de o observar mais acima na pilha.

As etapas a seguir mostram o padrão geral.

Crie uma classe mutável que possa ser atualizada de dentro de retornos de chamada de eventos.
```
public sealed class RequestInfo
{
    public DateTime StartTime, HeadersSent;
}
```

Defina o AsyncLocal.Valueantes da operação principal para que o estado seja transferido para a operação.

private static readonly AsyncLocal<RequestInfo> _requestInfo = new();

public async Task SendRequestAsync(string url)
{
    var info = new RequestInfo();
    _requestInfo.Value = info;

    info.StartTime = DateTime.UtcNow;
    await _client.GetStringAsync(url);

Dentro dos callbacks do evento, verifique se o estado partilhado está disponível e atualize-o. AsyncLocal.Value será null se a solicitação foi enviada por um componente que não definiu o AsyncLocal.Value em primeiro lugar.
```
public void OnRequestHeadersStop(DateTime timestamp)
{
    if (_requestInfo.Value is { } info) info.HeadersSent = timestamp;
}
```

Processar a informação recolhida após terminar a operação.

await _client.GetStringAsync(url);

Log($"Time until headers were sent {url} was {info.HeadersSent - info.StartTime}");

Para obter mais maneiras de fazer isso, consulte a seção de exemplos.

Correlação fora do processo

Cada evento tem um dado anexado a ele chamado ActivityID. Esse ID codifica a hierarquia assíncrona no momento em que o evento foi produzido.

Se você examinar um arquivo de rastreamento no PerfView, verá eventos como:

System.Net.Http/Request/Start           ActivityID="/#14396/1/1/"
System.Net.Http/RequestHeaders/Start    ActivityID="/#14396/1/1/2/"
System.Net.Http/RequestHeaders/Stop     ActivityID="/#14396/1/1/2/"
System.Net.Http/ResponseHeaders/Start   ActivityID="/#14396/1/1/3/"
System.Net.Http/ResponseHeaders/Stop    ActivityID="/#14396/1/1/3/"
System.Net.Http/Request/Stop            ActivityID="/#14396/1/1/"

Você saberá que esses eventos pertencem à mesma solicitação porque compartilham o prefixo /#14396/1/1/ .

Ao realizar investigações manuais, um truque útil é procurar pelo System.Net.Http/Request/Start evento de uma solicitação do seu interesse e, em seguida, colar o ActivityID na Text Filter caixa de texto. Se você selecionar todos os provedores disponíveis, verá a lista de todos os eventos que foram produzidos como parte dessa solicitação.

O PerfView coleta automaticamente o ActivityID, mas se usar ferramentas como dotnet-trace, deve habilitar explicitamente o provedor (veja como o exemplo System.Threading.Tasks.TplEventSource:0x80:4dotnet-trace acima).

Solicitação HttpClient vs. tempo de vida da conexão

Desde o .NET 6, uma solicitação HTTP não está mais vinculada a uma conexão específica. Em vez disso, a solicitação será atendida assim que qualquer conexão estiver disponível.

Isso significa que você pode ver a seguinte ordem de eventos:

Solicitar início
Início do DNS
Solicitar paragem
Parar DNS

Isso indica que a solicitação disparou uma resolução DNS, mas foi processada por uma conexão diferente antes da chamada DNS ser concluída. O mesmo vale para conexões de soquete ou handshakes TLS - a solicitação de origem pode ser concluída antes que eles o façam.

Você deve pensar sobre esses eventos separadamente. Monitorar resoluções de DNS ou handshakes de TLS individualmente, sem ligá-los à cronologia de uma solicitação específica.

Diagnósticos internos

Alguns componentes no .NET são instrumentados com eventos adicionais de nível de depuração que fornecem mais informações sobre exatamente o que está acontecendo internamente. Esses eventos vêm com sobrecarga de alto desempenho e sua forma está em constante mudança. Como o nome sugere, eles não fazem parte da API pública e, portanto, você não deve confiar em seu comportamento ou existência. Além disso, não estão censurados e podem conter PII.

Independentemente disso, esses eventos podem oferecer muitos insights quando tudo o resto falha. A pilha System.Net emite esses eventos dos Private.InternalDiagnostics.System.Net.* espaços de nomes.

Caso altere a condição no exemplo acima para eventSource.Name.Contains("System.Net"), verá mais de 100 eventos de diferentes camadas na pilha. Para obter mais informações, consulte o exemplo completo.

Para os consumir fora do processo, use dotnet-trace, por exemplo:

dotnet-trace collect --providers Private.InternalDiagnostics.System.Net.Http:0xf --process-id 1234

Exemplos

Medir resoluções DNS para um determinado endpoint
Meça o tempo até aos cabeçalhos na utilização do HttpClient
Tempo para processar um pedido no ASP.NET Core que executa o Kestrel
Medir a latência de um proxy reverso .NET

Medir resoluções DNS para um determinado endpoint

services.AddTelemetryConsumer(new DnsMonitor("httpbin.org"));

public sealed class DnsMonitor : INameResolutionTelemetryConsumer
{
    private static readonly AsyncLocal<DateTime?> _startTimestamp = new();
    private readonly string _hostname;

    public DnsMonitor(string hostname) => _hostname = hostname;

    public void OnResolutionStart(DateTime timestamp, string hostNameOrAddress)
    {
        if (hostNameOrAddress.Equals(_hostname, StringComparison.OrdinalIgnoreCase))
        {
            _startTimestamp.Value = timestamp;
        }
    }

    public void OnResolutionStop(DateTime timestamp)
    {
        if (_startTimestamp.Value is { } start)
        {
            Console.WriteLine($"DNS resolution for {_hostname} took {(timestamp - start).TotalMilliseconds} ms");
        }
    }
}

Meça o tempo até aos cabeçalhos ao usar HttpClient

var info = RequestState.Current; // Initialize the AsyncLocal's value ahead of time

var response = await client.GetStringAsync("http://httpbin.org/get");

var requestTime = (info.RequestStop - info.RequestStart).TotalMilliseconds;
var serverLatency = (info.HeadersReceived - info.HeadersSent).TotalMilliseconds;
Console.WriteLine($"Request took {requestTime:N2} ms, server request latency was {serverLatency:N2} ms");

public sealed class RequestState
{
    private static readonly AsyncLocal<RequestState> _asyncLocal = new();
    public static RequestState Current => _asyncLocal.Value ??= new();

    public DateTime RequestStart;
    public DateTime HeadersSent;
    public DateTime HeadersReceived;
    public DateTime RequestStop;
}

public sealed class TelemetryConsumer : IHttpTelemetryConsumer
{
    public void OnRequestStart(DateTime timestamp, string scheme, string host, int port, string pathAndQuery, int versionMajor, int versionMinor, HttpVersionPolicy versionPolicy) =>
        RequestState.Current.RequestStart = timestamp;

    public void OnRequestStop(DateTime timestamp) =>
        RequestState.Current.RequestStop = timestamp;

    public void OnRequestHeadersStop(DateTime timestamp) =>
        RequestState.Current.HeadersSent = timestamp;

    public void OnResponseHeadersStop(DateTime timestamp) =>
        RequestState.Current.HeadersReceived = timestamp;
}

Tempo para processar um pedido no ASP.NET Core que executa o Kestrel

Esta é atualmente a forma mais precisa de medir a duração de um determinado pedido.

public sealed class KestrelTelemetryConsumer : IKestrelTelemetryConsumer
{
    private static readonly AsyncLocal<DateTime?> _startTimestamp = new();
    private readonly ILogger<KestrelTelemetryConsumer> _logger;

    public KestrelTelemetryConsumer(ILogger<KestrelTelemetryConsumer> logger) => _logger = logger;

    public void OnRequestStart(DateTime timestamp, string connectionId, string requestId, string httpVersion, string path, string method)
    {
        _startTimestamp.Value = timestamp;
    }

    public void OnRequestStop(DateTime timestamp, string connectionId, string requestId, string httpVersion, string path, string method)
    {
        if (_startTimestamp.Value is { } startTime)
        {
            var elapsed = timestamp - startTime;
            _logger.LogInformation("Request {requestId} to {path} took {elapsedMs} ms", requestId, path, elapsed.TotalMilliseconds);
        }
    }
}

Medir a latência de um proxy reverso .NET

Este exemplo é aplicável se você tiver um proxy reverso que recebe solicitações de entrada via Kestrel e faz solicitações de saída via HttpClient (por exemplo, YARP).

Este exemplo mede o tempo desde o recebimento dos cabeçalhos de solicitação até que eles sejam enviados para o servidor back-end.

public sealed class InternalLatencyMonitor : IKestrelTelemetryConsumer, IHttpTelemetryConsumer
{
    private record RequestInfo(DateTime StartTimestamp, string RequestId, string Path);

    private static readonly AsyncLocal<RequestInfo> _requestInfo = new();
    private readonly ILogger<InternalLatencyMonitor> _logger;

    public InternalLatencyMonitor(ILogger<InternalLatencyMonitor> logger) => _logger = logger;

    public void OnRequestStart(DateTime timestamp, string connectionId, string requestId, string httpVersion, string path, string method)
    {
        _requestInfo.Value = new RequestInfo(timestamp, requestId, path);
    }

    public void OnRequestHeadersStop(DateTime timestamp)
    {
        if (_requestInfo.Value is { } requestInfo)
        {
            var elapsed = (timestamp - requestInfo.StartTimestamp).TotalMilliseconds;
            _logger.LogInformation("Internal latency for {requestId} to {path} was {duration} ms", requestInfo.RequestId, requestInfo.Path, elapsed);
        }
    }
}

Precisa de mais telemetria?

Se tiver sugestões para outras informações úteis que possam ser expostas por meio de eventos ou métricas, crie uma questão dotnet/runtime.

Se você estiver usando a Yarp.Telemetry.Consumption biblioteca e tiver sugestões, crie um problema de microsoft/proxy reverso.

Comentários

Esta página foi útil?

Last updated on 2026-02-24