调试

无论我们如何完善地进行单元测试，我们都是人类，而人类总是会犯错。在某些时刻，我们肯定需要调试一个服务。在这一部分，我们将探讨如何进行调试。我们将首先启用服务器反射，这样我们就能仅通过命令行调用服务。之后，我们将使用 Wireshark 来检查网络上的数据。最后，由于错误可能并不总是直接来自我们的代码，我们还将学习如何查看 gRPC 日志。

服务器反射

服务器反射是一个非常有趣的功能，它在向外部客户端暴露 API 时尤其有用。因为它允许服务器描述自己。换句话说，服务器知道所有已注册的服务和消息定义。如果客户端请求更多的信息，服务器可以通过反射列出所有服务、消息等。这样，客户端甚至不需要拥有 proto 文件。这不仅对于向外部客户端暴露 API 很有用，也对于手动测试/调试非常有帮助。它使得开发者/测试人员只需专注于调试 API，而无需让整个环境工作（比如复制 proto 文件等）。

在 gRPC Go 中启用服务器反射非常简单。我们只需要两行代码：一个导入语句和一个调用 reflection.Register 函数来将反射服务注册到我们的服务器。代码如下所示（在 server/main.go 文件中）：

import (
    //...
    "google.golang.org/grpc/reflection"
)

func newGrpcServer(lis net.Listener, srvMetrics *grpcprom.ServerMetrics) (*grpc.Server, error) {
    //...
    s := grpc.NewServer(opts...)

    pb.RegisterTodoServiceServer(/*…*/)
    reflection.Register(s)

    return s, nil
}

然而，尽管这些代码足以暴露信息，我们仍然需要一个客户端来连接服务器并查看它所获得的信息。市面上有多个这样的工具，其中最流行的是 grpcurl（ https://github.com/fullstorydev/grpcurl ）。如果你熟悉 cURL，那么这个工具基本上是一个类似的工具，但它能理解 gRPC 协议。

虽然我们将使用这个工具来探索服务器反射，但需要注意的是，它也可以发起其他普通请求。如果你对这样的工具感兴趣，可以查看该仓库的 README，其中充满了如何使用它进行其他任务的示例。

首先，我们来创建一个简单的命令，使用 grpcurl。我们将使用类似于 ghz 中的选项，使用 CA 证书并通过 -cacert 和 -authority 来覆盖域名。然后，我们将添加一个 auth_token 头用于反射，最后我们将使用 list 动词来列出服务器上的服务：

$ grpcurl -cacert ./certs/ca_cert.pem \
    -authority "check.test.example.com" \
    -reflect-header 'auth_token: authd' \
    0.0.0.0:50051 list

运行此命令后，我们应该看到以下输出：

grpc.reflection.v1alpha.ServerReflection
todo.v2.TodoService

我们可以看到，除了我们之前注册的 TodoService 服务，还有 ServerReflection 服务。通过这些信息，我们可以描述服务并获取它包含的所有 RPC 端点。我们可以使用 describe 动词，后跟服务名称：

$ grpcurl -cacert ./certs/ca_cert.pem \
    -authority "check.test.example.com" \
    -reflect-header 'auth_token: authd' \
    0.0.0.0:50051 describe todo.v2.TodoService

运行此命令将显示服务的定义：

todo.v2.TodoService is a service:
service TodoService {
  rpc AddTask ( .todo.v2.AddTaskRequest ) returns ( .todo.v2.AddTaskResponse );
  rpc DeleteTasks ( stream .todo.v2.DeleteTasksRequest ) returns ( stream .todo.v2.DeleteTasksResponse );
  rpc ListTasks ( .todo.v2.ListTasksRequest ) returns ( stream .todo.v2.ListTasksResponse );
  rpc UpdateTasks ( stream .todo.v2.UpdateTasksRequest ) returns ( .todo.v2.UpdateTasksResponse );
}

我们还可以通过替换服务名称后面的 describe 来查看消息内容。以下是 AddTaskRequest 的示例：

$ grpcurl -cacert ./certs/ca_cert.pem \
    -authority "check.test.example.com" \
    -reflect-header 'auth_token: authd' \
    0.0.0.0:50051 describe todo.v2.AddTaskRequest

todo.v2.AddTaskRequest is a message:
message AddTaskRequest {
  string description = 1 [(.validate.rules) = { string:<min_len:1> }];
  .google.protobuf.Timestamp due_date = 2 [( .validate.rules) = { timestamp:<gt_now:true> }];
}

现在，由于我们正在讨论调试这一部分，我们希望能够调用这些 RPC 端点并使用不同的数据进行测试。这非常简单，因为我们甚至不需要拥有 proto 文件。服务器反射将帮助 grpcurl 为我们处理一切。让我们通过无效的请求来调用 AddTask 端点：

$ grpcurl -cacert ./certs/ca_cert.pem \
    -authority "check.test.example.com" \
    -rpc-header 'auth_token: authd' \
    -reflect-header 'auth_token: authd' \
    -d '' \
    -use-reflection \
    0.0.0.0:50051 todo.v2.TodoService.AddTask

请注意，在这里我们使用了其他选项。我们使用 -d 选项来设置我们希望发送的数据作为 AddTaskRequest。我们使用 --use-reflection 选项，以便 grpcurl 验证数据是否有效（我们很快会看到这一点），并且 --rpc-header 选项加上 --reflect-header，因为 --reflect-header 仅将头部发送到 ServerReflection 服务，我们还需要将头部发送到 TodoService。

如预期的那样，之前的命令返回以下错误：

ERROR:
    Code: Unknown
    Message: invalid AddTaskRequest.Description: value length must be at least 1 runes

如前所述，grpcurl 不允许我们执行没有保护措施的命令。使用反射非常有用，因为它不允许我们发送无法反序列化的请求消息。举个例子：

$ grpcurl #... \
    -d '{"notexisting": true}' \
    0.0.0.0:50051 todo.v2.TodoService.AddTask

Error invoking method "todo.v2.TodoService.AddTask": error getting request data: message type todo.v2.AddTaskRequest has no known field named notexisting

最后，由于我们也有一个非单次 RPC 端点（UpdateTasks）需要测试，我们可以使用交互式终端。这将允许我们发送和接收多个消息。为此，我们将数据设置为 @ 并以 <<EOF 结束命令，其中 EOF 表示文件结束（实际上你可以使用任何后缀）。这将让我们交互式地输入数据，当完成时，我们写 EOF 来让 grpcurl 知道。

让我们开始给服务器添加两个新任务：

$ grpcurl #… \
    -d '{"description": "a task!"}' \
    0.0.0.0:50051 todo.v2.TodoService.AddTask
$ grpcurl #… \
    -d '{"description": "another task!"}' \
    0.0.0.0:50051 todo.v2.TodoService.AddTask

然后，我们可以使用 ListTasks 来显示任务：

$ grpcurl #... \
        -d '' \
        0.0.0.0:50051 todo.v2.TodoService.ListTasks

{
  "task": {
    "id": "1",
    "description": "a task!",
    "dueDate": "1970-01-01T00:00:00Z"
  },
  "overdue": true
}
{
  "task": {
    "id": "2",
    "description": "another task!",
    "dueDate": "1970-01-01T00:00:00Z"
  },
  "overdue": true
}

你能在这里发现任何错误吗？如果没有，别担心，我们稍后会回到这个问题。

接下来，调用我们的客户端流式 API（UpdateTasks），在 Linux/Mac 上可以使用以下命令（在最后一个 EOF 后按 Enter）：

$ grpcurl #… \
        -d @ \
        0.0.0.0:50051 todo.v2.TodoService.UpdateTasks <<EOF
{ "id": 1, "description": "a better task!" }
{ "id": 2, "description": "another better task!" }
EOF

Windows（PowerShell）用户应该使用以下命令：

$ $Messages = @"
{ "id": 1, "description": "new description" }
{ "id": 2, "description": "new description" }
"@
$ grpcurl #… \
    -d $Messages \
    0.0.0.0:50051 todo.v2.TodoService.UpdateTasks

之后，再次调用 ListTasks 应该会显示带有新描述的数据。

在执行这些函数时，你可能已经注意到一个 bug。如果没有注意到，也不用担心，我们将一起解决这个问题。问题在于我们可以发送一个空的 DueDate，这会被转换成 Unix 时间中的 0 值（1970-01-01）。这个 bug 源于 protoc-gen-validate 只会检查已设置的 DueDate。

为了解决这个问题，我们可以在 todo.proto 文件中为 due_date 添加一个新的验证规则。这个规则是必需的，它将使该字段不能不被设置。你可能会认为一个任务不需要 due date，但我们可以为添加备注创建一个不同的端点，并说任务应该有 due date，但备注不需要。

due_date 现在将定义如下：

google.protobuf.Timestamp due_date = 2 [
  (validate.rules).timestamp.gt_now = true,
  (validate.rules).timestamp.required = true
];

然后，我们重新生成 validate 插件（在第 9 章）：

$ protoc -Iproto --validate_out="lang=go, paths=source_relative:proto" proto/todo/v2/*.proto

接着，我们关闭服务器并重新启动：

$ go run ./server 0.0.0.0:50051 0.0.0.0:50052
metrics server listening at 0.0.0.0:50052
gRPC server listening at 0.0.0.0:50051

如果我们重新运行之前的 AddTask 命令，它应该会失败：

$ grpcurl #… \
-d '{"description": "a task!"}' \
0.0.0.0:50051 todo.v2.TodoService.AddTask

ERROR:
    Code: Unknown
    Message: invalid AddTaskRequest.DueDate: value is required

我们解决了一个 bug！是不是很棒？

如果你现在想发送带有 due_date 值的请求，你必须指定一个符合 RFC3339 格式的日期字符串。例如，使用一个在写这篇文章时 500 年后的日期：

$ ghz #… \
    -d '{"description":"task", "due_date": "2523-06-01T14:18:25+00:00"}' \
    0.0.0.0:50051

Bazel

为了使用 Bazel 运行服务器，你需要更新依赖项。你可以运行 Gazelle 来更新 //server:server：

$ bazel run //:gazelle

然后，你就可以正常运行服务器了：

$ bazel run //server:server 0.0.0.0:50051 0.0.0.0:50052

总结一下，我们看到我们可以启用服务器反射来获取信息并与服务器进行交互以进行调试。我们展示了如何列出服务并描述服务和消息。我们还展示了如何调用单次 RPC 端点，最后，我们还展示了如何使用交互式终端调用流式 API。

使用 Wireshark

有时候，我们需要能够检查通过网络传输的数据。这可以帮助我们了解负载的大小、请求是否过多等。在这一节中，我们将看到如何使用 Wireshark 分析负载和请求。

首先，为了能够获取可读的信息，我们需要禁用第 7 章中启用的 TLS 加密。请注意，这在开发模式下是可以的，但在推送到生产环境时，你需要确保启用加密。

为了禁用加密，我们将创建一个开关变量。通过设置 ENABLE_TLS 环境变量为 false，我们就能禁用 TLS。显然，由于我们希望 TLS 是默认启用的，我们将检查环境变量的值是否与 false 不同，这样如果值有错误或未设置时，TLS 仍然会启用。

在 server/main.go 中，我们可以这样做：

func newGrpcServer(lis net.Listener, srvMetrics *grpcprom.ServerMetrics) (*grpc.Server, error) {
    var credsOpt grpc.ServerOption
    enableTls := os.Getenv("ENABLE_TLS") != "false"

    if enableTls {
        creds, err := credentials.NewServerTLSFromFile("./certs/server_cert.pem", "./certs/server_key.pem")
        if err != nil {
            return nil, err
        }
        credsOpt = grpc.Creds(creds)
    }
    //...
    opts := []grpc.ServerOption{/*…*/}
    if credsOpt != nil {
        opts = append(opts, credsOpt)
    }
    //...
}

我们在客户端（client/main.go）做类似的操作：

func main() {
    //...
    var credsOpt grpc.DialOption
    enableTls := os.Getenv("ENABLE_TLS") != "false"

    if enableTls {
        creds, err := credentials.NewClientTLSFromFile("./certs/ca_cert.pem", "x.test.example.com")
        if err != nil {
            log.Fatalf("failed to load credentials: %v", err)
        }
        credsOpt = grpc.WithTransportCredentials(creds)
    } else {
        credsOpt = grpc.WithTransportCredentials(insecure.NewCredentials())
    }
    //...
    opts := []grpc.DialOption{
        credsOpt,
        //...
    }
    //...
}

这样，我们就可以轻松启用/禁用 TLS。要在没有 TLS 的情况下在 Linux 或 Mac 上运行服务器，可以执行以下命令：

$ ENABLE_TLS=false go run ./server 0.0.0.0:50051 0.0.0.0:50052

对于 Windows（PowerShell），可以运行以下命令：

$env:ENABLE_TLS='false'; go run ./server 0.0.0.0:50051 0.0.0.0:50052; $env:ENABLE_TLS=$null

类似地，对于客户端，在 Linux/Mac 上我们可以运行：

$ ENABLE_TLS=false go run ./client 0.0.0.0:50051

在 Windows（PowerShell）上，我们可以运行：

$env:ENABLE_TLS='false'; go run ./client 0.0.0.0:50051; $env:ENABLE_TLS=$null

现在，我们已经准备好开始检查通过网络传输的数据。在 Wireshark 中，我们将首先检查我们想要拦截负载的网络接口：

Figure 1. Figure 9.1 – Selecting the network interface

我们正在使用的回环接口是 localhost。通过双击它，我们将进入录制界面。但在此之前，我们需要告诉 Wireshark 在哪里可以找到我们的 proto 文件。没有这些文件，Wireshark 只会显示字段标签和对应的值。为了能够显示字段名称，我们需要做一些配置。

首先，我们需要进入 Wireshark 的设置（Mac 上是 Preferences），然后导航到 Settings | Protocols | Protobuf，并选择一个用于 Protobuf 搜索的路径。在我们的案例中，我们将使用 chapter9/proto 文件夹，并且还需要访问 Well-Known Types 的文件夹。最后一个路径取决于你安装 protoc 的方式，以下是最常见的路径：

如果通过 GitHub 发布版安装，并且将 include 文件夹移动到了 /usr/local，那么第二个路径就是 /usr/local/include。
如果通过 Homebrew 安装 protobuf，可以通过运行 brew --prefix protobuf 命令来获取安装路径。该命令会返回一个路径，你只需要在路径后加上 /include 即可。
如果通过 Chocolatey 安装 protobuf，可以运行 choco list --local-only --exact protoc --trace 命令，这会列出一个以 .files 结尾的路径。打开该路径并使用工具（例如 Notepad），查找包含 include/google/protobuf 的路径，选择路径直到 include 文件夹。例如，路径可能是 C:\ProgramData\chocolatey\lib\protoc\tools\include。

Figure 2. Figure 9.2 – Adding path to proto files

完成上述设置后，我们可以返回到回环接口并双击它。现在我们应该会看到如下的录制界面。

接下来，我们将输入一个过滤器，只显示端口 50051 上的请求，并且仅显示与 gRPC 和 Protobuf 相关的请求。确保点击过滤器区域旁边的箭头，否则你将看到接口上所有的请求。

Figure 3. Figure 9.3 – Entering a filter

之后，我们可以继续运行服务器和客户端。一旦客户端执行完毕，你将在 Wireshark 中看到一些日志。这应该类似于以下内容：

Figure 4. Figure 9.4 – Logs appearing in Wireshark

现在我们可以理解通过网络发送的数据。如果我们查看负载，我们应该关注 DATA (GRPC) (PROTOBUF) 帧。例如，AddTask 的 DATA 帧如下：

Protocol Buffers: /todo.v2.TodoService/AddTask, request
    Message: todo.v2.AddTaskRequest
        Field(1): description = This is another task (string)
        Field(2): due_date = 2023-06-01T17:06:20.531406+0800 (message)
            Message: google.protobuf.Timestamp
              Field(1): seconds = 1685610380 (int64)
              Field(2): nanos = 531406000 (int32)
              [Message Value: 2023-06-01T17:06:20.531406+0800]

最后，如果我们查看与 gRPC 相关的记录，我们可以查看 HEADERS 和 DATA (GRPC) 帧。这些帧可以告诉你何时发送了半关闭标志以及 trailer 的大小。以下是 ListTasks 的半关闭示例：

HyperText Transfer Protocol 2
    Stream: DATA, Stream ID: 7, Length 45
        Length: 45
        Type: DATA (0)
        Flags: 0x00
            0000 .00. = Unused: 0x00
            .... 0... = Padded: False
            .... ...0 = End Stream: False
        0... .... .... .... .... .... ... = Reserved: 0x0
        .000 0000 0000 0000 0000 0000 0000 0111 = Stream Identifier: 7
        [Pad Length: 0]
        DATA payload (45 bytes)

以下是 DeleteTasks 的 trailer 示例：

HyperText Transfer Protocol 2
    Stream: HEADERS, Stream ID: 13, Length 2
        Length: 2
        Type: HEADERS (1)
        Flags: 0x05, End Headers, End Stream
            00.0 ..0. = Unused: 0x00
            ..0. .... = Priority: False
            .... 0... = Padded: False
            .... .1.. = End Headers: True
            .... ...1 = End Stream: True
        0... .... .... .... .... .. .... = Reserved: 0x0
        .000 0000 0000 0000 0000 0000 0000 1101 = Stream Identifier: 13
        [Pad Length: 0]
        Header Block Fragment: bfbe
        [Header Length: 40]
        [Header Count: 2]
        Header: grpc-status: 0
        Header: grpc-message:

为了保持本书的可读性，我们将在此结束本节。但实际上还有很多内容值得探讨和发现。我们看到可以使用 Wireshark 拦截通过网络传输的消息。我们创建了一个切换变量，临时禁用了 TLS 以便读取未加密的数据。我们将 protobuf 消息加载到 Wireshark 中，让它知道如何反序列化消息。最后，我们看到可以查看消息内容以及 HTTP2 协议的低层部分。

启用 gRPC 日志

最后，如果你准备深入到比 Wireshark 更低的层次来调试 gRPC 应用，gRPC 提供了两个重要的环境变量来获取框架的日志。

第一个环境变量是 GRPC_GO_LOG_SEVERITY_LEVEL。它会根据特定的严重性级别（如 debug、info 或 error）输出由 gRPC 写入的日志。要启用它，你可以像设置我们之前自定义的 ENABLE_TLS 变量那样，在执行你的二进制文件或 Go 命令时设置 GRPC_GO_LOG_SEVERITY_LEVEL。

在启动和关闭服务器时，设置 GRPC_GO_LOG_SEVERITY_LEVEL 为 info 的示例如下（适用于 Linux/Mac）：

$ GRPC_GO_LOG_SEVERITY_LEVEL=info go run ./server 0.0.0.0:50051 0.0.0.0:50052
INFO: [core] [Server #1] Server created
metrics server listening at 0.0.0.0:50052
gRPC server listening at 0.0.0.0:50051
INFO: [core] [Server #1 ListenSocket #2] ListenSocket created
shutting down servers, please wait...
INFO: [core] [Server #1 ListenSocket #2] ListenSocket deleted
gRPC server shutdown
metrics server shutdown

在 Windows (PowerShell) 中，命令如下：

$ $env:GRPC_GO_LOG_SEVERITY_LEVEL='info'; go run ./server 0.0.0.0:50051 0.0.0.0:50052
$env:GRPC_GO_LOG_SEVERITY_LEVEL=$null

除了严重性级别外，你还可以使用 GRPC_GO_LOG_VERBOSITY_LEVEL 设置日志的详细程度，该值为 2 到 99 之间的数字，数字越大，日志越详细。这通常在长期运行的服务器中更有用，而不是短期运行的情况。要启用它，你只需在 GRPC_GO_LOG_SEVERITY_LEVEL 后添加 GRPC_GO_LOG_VERBOSITY_LEVEL：

$ GRPC_GO_LOG_SEVERITY_LEVEL=info GRPC_GO_LOG_VERBOSITY_LEVEL=99 go run ./server 0.0.0.0:50051 0.0.0.0:50052

最后，虽然我说了有两个重要的环境变量，但还有一个值得一提的环境变量。如果你计划解析日志，这个环境变量非常重要。你可以设置日志的格式。现在，日志的默认格式如下：

INFO: [core] [Server #1] Server created

但是你可以将日志格式设置为 JSON，从而获得如下格式的日志：

{
  "message": "[core] [Server #1] Server created\n",
  "severity": "INFO"
}

这样，你就可以反序列化 JSON 并实现各种工具来监控和报告错误。

总结一下，在这一小节中，我们看到我们可以获取来自我们没有编写的代码的日志信息：gRPC 框架。我知道本节中的示例较为浅显，但通常这些标志在出现严重问题时使用，或者当你参与 gRPC Go 本身的开发时使用。我仍然认为了解它们的存在非常重要，并鼓励你尝试获取更有趣的日志信息。

调试的方法多种多样，取决于需求和设置。因此，我们无法涵盖所有内容，但至少你已经掌握了开始调试所需的基本技能和工具。在本节中，我们看到可以启用服务器反射来获取服务器信息并与之互动（使用 grpcurl）。我们还看到了如何通过 Wireshark 拦截消息，以了解请求的大小和内容。最后，我们了解了如何通过设置某些标志来获取 gRPC 的日志。

在进入下一节之前，我还想提到一个你可能会发现有用但我们没有覆盖的工具，它叫做 Channelz（ https://grpc.io/blog/a-short-introduction-to-channelz/ ）。它的作用是调试网络问题，你可能会想了解一下它。