YARP 诊断基于 YARP 的代理

当使用反向代理时,从客户端到代理,再从代理到目标都有一个额外的跃点,可能会出现问题。 本主题应提供有关在出现问题时如何调试和诊断问题的一些提示和建议。 它假定代理已在运行,因此不包括启动时的问题,例如配置错误。

伐木业

要了解 YARP 发生了什么的第一步是打开 日志记录。 这是一个配置标志,因此可以动态更改。 YARP 作为 ASP.NET Core 的中间件组件实现,因此需要为 YARP 和 ASP.NET 启用日志记录,以便全面了解所发生的事情。

默认情况下,ASP.NET 将记录到控制台,配置文件可用于控制日志记录级别。

  //Sets the Logging level for ASP.NET
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      // Uncomment to hide diagnostic messages from runtime and proxy
      // "Microsoft": "Warning",
      // "Yarp" : "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  },

需要来自 Microsoft.AspNetCore.\*Yarp.ReverseProxy.\* 提供程序的日志记录信息。 前面的示例从两个提供程序向控制台发出 Information 级事件。 将级别更改为 Debug 会显示其他条目。 ASP.NET 实现配置文件的更改检测,因此可以在项目运行时编辑appsettings.json文件(或appsettings.development.jsonDevelopment环境),并观察日志输出的更改。

注释

appsettings.development.json 环境中运行时,appsettings.json 文件中的设置将覆盖 Development 中的设置;因此,如果正在编辑 appsettings.json,请确保这些值不会被覆盖。

了解日志条目

日志记录输出直接绑定到 ASP.NET Core 处理请求的方式。 请务必认识到,作为中间件,YARP 依赖于大部分 ASP.NET 功能来处理请求,例如,下面是对启用了“调试”模式的请求的处理:

级别 日志消息 DESCRIPTION
dbug Microsoft.AspNetCore.Server.Kestrel。Connections[39]
已接受连接 ID“0HMCD0JK7K51U”。
连接独立于请求,因此这是一个新的连接
dbug Microsoft.AspNetCore.Server.Kestrel。Connections[1]
连接 ID "0HMCD0JK7K51U"已启动。
信息 Microsoft.AspNetCore.Hosting.Diagnostics[1]
请求启动 HTTP/1.1 GET http://localhost:5000/ - -
这是传入 ASP.NET 请求
dbug Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware[0]
检测到通配符,将允许对主机的所有请求。
我的配置不会将终结点绑定到特定的主机名
dbug Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
为请求路径 '/' 找到 1 个候选路径
这显示了该路由可能的匹配结果
dbug Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
路由模式为'{**catch-all}'的终结点'minimumroute'对请求路径 '/' 有效
YARPs 配置中的最短路径已完成匹配
dbug Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
请求已匹配终结点 'minimumroute'
信息 Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
正在执行终结点 'minimumroute'
信息 Yarp.ReverseProxy.Forwarder.HttpForwarder[9]
代理至 http://www.example.com/
YARP 正在将请求代理到 example.com
信息 Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
已执行终结点 'minimumroute'
dbug Microsoft.AspNetCore.Server.Kestrel。Connections[9]
连接 ID “0HMCD0JK7K51U”已完成保持连接响应。
响应已完成,但连接可以保持活动状态。
信息 Microsoft.AspNetCore.Hosting.Diagnostics[2]
请求完成 HTTP/1.1 GET http://localhost:5000/ - - - 200 1256 text/html;+charset=utf-8 12.7797ms
响应以状态代码 200 完成,响应为 1256 字节的文本/html,耗时约 13 毫秒。
dbug Microsoft.AspNetCore.Server.Kestrel。Transport.Sockets[6]
连接 ID “0HMCD0JK7K51U” 收到 FIN。
有关连接的诊断信息,以确定谁关闭了连接以及其完全程度
dbug Microsoft.AspNetCore.Server.Kestrel。Connections[10]
连接 ID“0HMCD0JK7K51U” 正在断开连接。
dbug Microsoft.AspNetCore.Server.Kestrel。Connections[2]
连接 ID “0HMCD0JK7K51U” 已停止。
dbug Microsoft.AspNetCore.Server.Kestrel。Transport.Sockets[7]
连接 ID “0HMCD0JK7K51U” 正在发送 FIN,因为:“套接字传输的发送循环已正常结束。”

上述内容提供有关请求的一般信息及其处理方式。

使用 ASP.NET 进行请求日志记录

ASP.NET 包括一个中间件组件,可用于提供有关请求和响应的更多详细信息。 可以将 UseHttpLogging 组件添加到请求管道,该管道向日志中添加附加条目,详细说明传入和传出请求标头。

app.UseHttpLogging();
// Enable endpoint routing, required for the reverse proxy
app.UseRouting();
// Register the reverse proxy routes
app.MapReverseProxy();

例如:

info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[1]
      Request:
      Protocol: HTTP/1.1
      Method: GET
      Scheme: http
      PathBase:
      Path: /
      Accept: */*
      Host: localhost:5000
      User-Agent: curl/7.55.1
info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[2]
      Response:
      StatusCode: 200
      Content-Type: text/html; charset=utf-8
      Date: Tue, 12 Oct 2021 23:29:20 GMT
      Server: ECS,(sec/97A5)
      Age: 113258
      Cache-Control: [Redacted]
      ETag: [Redacted]
      Expires: Tue, 19 Oct 2021 23:29:20 GMT
      Last-Modified: Thu, 17 Oct 2019 07:18:26 GMT
      Vary: [Redacted]
      Content-Length: 1256
      X-Cache: [Redacted]

使用遥测事件

我们建议阅读.NET 中的网络遥测,以了解如何在 .NET 中使用网络遥测的入门知识。

指标示例展示了如何侦听来自不同提供程序的事件,这些提供程序将遥测数据收集为 YARP 的一部分。 从诊断的角度来看,最重要的是:

  • ForwarderTelemetryConsumer
  • HttpClientTelemetryConsumer

若要使用其中任一项,请创建实现接口的Yarp.Telemetry.Consumption类,例如IForwarderTelemetryConsumer

public class ForwarderTelemetry : IForwarderTelemetryConsumer
{
    /// Called before forwarding a request.
    public void OnForwarderStart(DateTime timestamp, string destinationPrefix)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnForwarderStart :: Destination prefix: {destinationPrefix}");
    }

    /// Called after forwarding a request.
    public void OnForwarderStop(DateTime timestamp, int statusCode)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnForwarderStop :: Status: {statusCode}");
    }

    /// Called before <see cref="OnForwarderStop(DateTime, int)"/> if forwarding the request failed.
    public void OnForwarderFailed(DateTime timestamp, ForwarderError error)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnForwarderFailed :: Error: {error.ToString()}");
    }

    /// Called when reaching a given stage of forwarding a request.
    public void OnForwarderStage(DateTime timestamp, ForwarderStage stage)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnForwarderStage :: Stage: {stage.ToString()}");
    }

    /// Called periodically while a content transfer is active.
    public void OnContentTransferring(DateTime timestamp, bool isRequest, long contentLength,
        long iops, TimeSpan readTime, TimeSpan writeTime)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnContentTransferring :: Is request: {isRequest}, Content length: {contentLength}, " +
            $"IOps: {iops}, Read time: {readTime:s\\.fff}, Write time: {writeTime:s\\.fff}");
    }

    /// Called after transferring the request or response content.
    public void OnContentTransferred(DateTime timestamp, bool isRequest, long contentLength,
        long iops, TimeSpan readTime, TimeSpan writeTime, TimeSpan firstReadTime)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnContentTransferred :: Is request: {isRequest}, Content length: {contentLength}, " +
            $"IOps: {iops}, Read time: {readTime:s\\.fff}, Write time: {writeTime:s\\.fff}");
    }

    /// Called before forwarding a request from `ForwarderMiddleware`, therefore is not called for direct forwarding scenarios.
    public void OnForwarderInvoke(DateTime timestamp, string clusterId, string routeId,
        string destinationId)
    {
        Console.WriteLine($"Forwarder Telemetry [{timestamp:HH:mm:ss.fff}] => " +
            $"OnForwarderInvoke:: Cluster id: {clusterId}, Route Id: {routeId}, Destination: {destinationId}");
    }
}

将类作为服务的一部分注册,例如:

services.AddTelemetryConsumer<ForwarderTelemetry>();

// Add the reverse proxy to capability to the server
var proxyBuilder = services.AddReverseProxy();
// Initialize the reverse proxy from the "ReverseProxy" section of configuration
proxyBuilder.LoadFromConfig(Configuration.GetSection("ReverseProxy"));

详细信息记录在请求的每个部分,例如:

Forwarder Telemetry [06:40:48.186] => OnForwarderInvoke::
    Cluster id: minimumcluster, Route Id: minimumroute, Destination: example.com
Forwarder Telemetry [06:41:00.269] => OnForwarderStart ::
    Destination prefix: http://www.example.com/
Forwarder Telemetry [06:41:00.298] => OnForwarderStage :: Stage: SendAsyncStart
Forwarder Telemetry [06:41:00.507] => OnForwarderStage :: Stage: SendAsyncStop
Forwarder Telemetry [06:41:00.530] => OnForwarderStage :: Stage:
    ResponseContentTransferStart
Forwarder Telemetry [06:41:03.655] => OnForwarderStop :: Status: 200

遥测事件在发生时触发,因此可以从中获取 HttpContext 和 YARP 功能。

services.AddTelemetryConsumer<ForwarderTelemetry>();
services.AddHttpContextAccessor();
...
public void OnForwarderInvoke(DateTime timestamp, string clusterId, string routeId,
    string destinationId)
{
    var context = new HttpContextAccessor().HttpContext;
    var YarpFeature = context.GetReverseProxyFeature();

    var dests = from d in YarpFeature.AvailableDestinations
        select d.Model.Config.Address;

    Console.WriteLine($"Destinations: {string.Join(", ", dests)}");
}

使用自定义中间件

检查请求状态的另一种方法是将其他中间件插入请求管道。 可以在其他阶段之间插入以查看请求的状态。

// We can customize the proxy pipeline and add/remove/replace steps
app.MapReverseProxy(proxyPipeline =>
{
    // Use a custom proxy middleware, defined below
    proxyPipeline.Use(MyCustomProxyStep);
    // Don't forget to include these two middleware when you make a custom proxy pipeline (if you need them).
    proxyPipeline.UseSessionAffinity();
    proxyPipeline.UseLoadBalancing();
});
...
public Task MyCustomProxyStep(HttpContext context, Func<Task> next)
{
    // Can read data from the request via the context
    foreach (var header in context.Request.Headers)
    {
        Console.WriteLine($"{header.Key}: {header.Value}");
    }

    // The context also stores a ReverseProxyFeature which holds proxy specific data such as the cluster, route and destinations
    var proxyFeature = context.GetReverseProxyFeature();
    Console.WriteLine(System.Text.Json.JsonSerializer.Serialize(proxyFeature.Route.Config));

    // Important - required to move to the next step in the proxy pipeline
    return next();
}

还可以在“配置 ”中使用 ASP.NET 中间件 ,以便在代理管道之前检查请求。

注释

代理将来自目标服务器的响应流式传输到客户端,因此无法通过中间件轻松访问响应标头和正文。

使用调试器

调试器(如 Visual Studio)可以附加到代理进程。 但是,除非你已有中间件,否则应用代码中没有合适的位置来中断和检查请求的状态。 因此,最好将调试器与上述技术之一结合使用,以便能够在明确的位置插入断点。

网络跟踪

使用 FiddlerWireshark 等网络跟踪工具来尝试监视代理的任一端发生了什么,这很有吸引力。 但是,请谨慎使用这两种工具:

  • Fiddler 将自身注册为代理,并依赖于使用默认代理的应用来监视流量。 这适用于从浏览器到 YARP 的入站流量,但不会捕获出站请求,因为 YARP 配置为不使用出站流量的代理设置。
  • 在 Windows 上,Wireshark 使用 Npcap 捕获网络流量的数据包数据,以便捕获入站和出站流量,并可用于监视 HTTP 流量。
  • HTTPS 流量已加密,网络监视工具无法自动解密。 每个工具都有一些解决方法,这些解决方法可能允许监视流量,但它们需要有风险地使用证书并更改信任关系。 由于 YARP 正在发出出站请求,因此用于欺骗浏览器的技术不适用于 YARP 过程。

出站流量的协议选择基于群集配置中的目标 URL 进行。 如果流量监视用于诊断,并且这些被诊断的问题与传输协议无关,那么(如果可能)将出站 URL 更改为 http:// 可能是启用监视工具工作最简单的方法。