使用 logpoint 绕开超时进行调试

阅读其他语言: EnglishEspañolFrançaisDeutsch日本語한국어Português

现代开发工具,尤其是 IntelliJ IDEA,提供了太多调试功能, 以至于光是记住有哪些功能都需要一点时间。几乎任何小众场景,都能找到对应的工具。

在这篇文章里,我想从另一个方向看调试,回到基础部分。 如果你刚开始学习调试工具,并且希望学习投入获得最大的回报, 最值得先看的功能就是 logpoint。

我很喜欢 logpoint,因为它们和使用普通 println 语句调试一样简单 (甚至可以说更简单), 却能极大扩展你可以调试的问题范围:对某些问题来说,logpoint 是唯一实际可行的方法。 而对其他问题来说,logpoint 也能带来很多便利,节省大量时间和精力。

另外,在 IntelliJ IDEA 2026.2 中,logpoint 获得了 一些非常不错的改进, 所以现在正适合做一次回顾。

问题说明

这里有一个迷你客户端/服务器示例, 使用 gRPC 进行通信。服务器里有一个 bug,会导致它 对某些 tenant 返回错误的折扣值。

所以我们会按照常规调试流程来走:复现问题,观察服务器内部的运行情况, 发送有问题的请求,然后准确看清它是怎样产生错误结果的。

复现 bug

为了模拟在另一个环境中运行,项目附带了一个 Dockerfile, 并暴露了监听端口和调试端口。 你可以使用项目提供的 GrpcQuoteServer in Docker 运行配置启动它,也可以直接从命令行启动:

docker build -t grpc-timeout .
docker run --rm -p 50051:50051 -p 5005:5005 grpc-timeout

然后,对于有问题的请求,使用 GrpcQuoteClientLoop 运行配置,它会定期 查询服务器。这样我们就不用手动发送请求,可以把更多注意力放在服务器上发生了什么。

当服务器和客户端循环都在运行时,控制台会显示:

tenant='JetBrains' region='EMEA' status=OK symbol=IDEA price=100.00 USD source=live detail=region=emea, discount_bps=0

… 而不是预期的:

tenant='JetBrains' region='EMEA' status=OK symbol=IDEA price=80.00 USD source=live detail=region=emea, discount_bps=2000

附加到服务器

服务器不是从本地 IntelliJ IDEA 调试会话中启动的,但它会监听调试器连接,因此 我们仍然可以使用提供的 GrpcQuoteServer attach 运行配置附加到它。

有一件事很多人容易理解错,也值得在这里说明: 对调试器来说,进程是在本地运行、在单独环境中运行, 还是在远程主机上运行,并没有区别。 无论哪种情况,通信都是通过 socket 完成的,所以这个练习同样适用于调试任何 Java 进程, 不管它在哪里运行。

Logpoints

Logpoint 和使用 println 语句调试类似:它们不会挂起程序, 只会把需要的细节记录到控制台。不同于 println 语句, 它们可以在不重新构建或重新部署应用的情况下修改。

你可能已经知道如何设置 logpoint,但从 IntelliJ IDEA 2026.2 开始,有了一种新的、更快的方法。 在任意两行可执行代码之间的 gutter 中点击,然后输入你想记录的表达式。 作为起点,我们可以使用查询处理方法的开头 ( QuoteEndpoint:12 ):

IntelliJ IDEA editor showing an inline Log field for a logpoint expression between two Java statements
Info icon

小心热点路径中的重计算。它们会在同一个 VM 中执行, 并且不会神奇地免费。 从 2026.2 开始,IntelliJ IDEA 会通过 instrumentation 移除调试器引入的 overhead,但 重的 logging 表达式本身仍然可能需要时间执行。

现在,对于每个传入请求,控制台都会打印:

EMEA JetBrains

现在,请求循环继续运行,我们可以逐步修改和添加 logpoint, 直到输出指向 bug。 只要继续添加 logpoint 或更新已有 logpoint,然后观察新请求到来时控制台里的新消息。

沿着调用链排查并排除最初的怀疑之后, 我们来到了 discountBpsFor() 方法:

IntelliJ IDEA editor showing logpoints inside the discountBpsFor method

控制台输出表明 tenant 名称没有被正确规范化:

tenant = JetBrains expected: jetbrains

另外,没有出现 discount applied 也说明包含正确折扣的代码块从未进入。 规范化 tenant 名称应该就能修复这个 bug。

Info icon

专业提示:如果不确定某条控制台输出是由什么产生的,可以点击控制台中的那一行, IntelliJ IDEA 会带你跳转到相关代码或 logpoint:

IntelliJ IDEA debug console showing logpoint output with an Open popup that navigates back to the code

即使你使用 println 做 logging,只要进程是在 IntelliJ IDEA 的调试器下运行, 这个导航功能也会生效。

测试修复

既然已经在这里了,我们可以测试一下修复。Logpoint 是用来记录日志的, 不是用来修改程序的,但实际上没有什么能阻止我们测试某个具体修复会怎样表现:

IntelliJ IDEA editor showing a logpoint that normalizes the tenant name before the discount check

结果符合预期:

EMEA JetBrains
jetbrains
discount applied

为什么不用 println

你可能会想,logpoint 看起来很像更好用的 println 语句。 某种意义上这是对的,因为核心技术是一样的: 用一种简单的方式添加探针,并且不影响程序的运行方式。

Logpoint 可以是更好选择,有几个原因:

到这个时候,logpoint 不再像 println,而开始像一种专业的调试工具。

为什么不用普通断点

使用调试器时,大多数开发者都会先想到断点。 但这个特定场景正是 logpoint 更合适的地方, 而且这不仅仅是偏好问题。

我们看看使用普通断点会发生什么。 附加到服务器后,在 GrpcQuoteServer.java:55 设置一个行断点。 循环中的下一个请求会挂起服务器:

IntelliJ IDEA debugger paused at a breakpoint in the getQuote method of GrpcQuoteServer.java

但是在查看程序状态并单步执行几次之后,我们会进入取消路径:

IntelliJ IDEA debugger paused on a Status.CANCELLED exception while the remaining discount calculation code is greyed out

到这里之后,代码已经走上了另一条执行路径。 你可以看到 IntelliJ IDEA 把不会继续执行的代码部分变灰了。 为了把有问题的状态带回来,我们必须一次又一次发送请求, 并且把调试操作塞进 timeout 窗口里。

这是因为我们的客户端为远程调用设置了 deadline。 不同于典型 HTTP/REST 客户端的 timeout,后者通常只在客户端侧报告失败, gRPC 可以把客户端的 deadline 传播到服务器。结果就是,客户端实际上可以取消 服务器端的工作,而不只是停止等待响应。

另一方面,logpoint 能给我们和调试器 UI 中相同的信息,只是我们在控制台里观察它。 重要的是,这不会挂起服务器,所以我们可以提取需要的信息,而不会触发 timeout。

附加内容:移除 timeout

如果你更喜欢用另一种方式处理这个场景,也可以这样调试。 在我们的 gRPC 示例中,有问题的部分是 timeout, 而使用 logpoint 可以在运行时把它移除。

正如你刚刚看到的, logpoint 表达式可以通过副作用修改正在运行的程序。 这里,我们可以用这个技巧来调整传入请求。

首先,找到设置 timeout 的库方法。有几个地方可以做这件事。 其中一个是 io.grpc.internal.ServerImpl.createContext :

IntelliJ IDEA Search Everywhere dialog showing the io.grpc.internal.ServerImpl.createContext symbol

在这个方法里,我们可以在局部变量 timeoutNanos 被赋值后立即 重写它的值:

IntelliJ IDEA editor showing a logpoint that changes timeoutNanos in ServerImpl.createContext

有了这个 logpoint,每次从请求 headers 中读取 gRPC timeout 值时, 它都会立刻被替换为五分钟的 deadline。这意味着我们又可以挂起服务器了。

如果你只想为 reproducer 请求延长 timeout,并让服务器在其他情况下照常工作, 例如它运行在共享 staging 实例上时,可以在 logpoint 中使用多行逻辑:

IntelliJ IDEA editor showing a multiline logpoint that extends timeoutNanos only for requests with a Debug header

下面是可以复制到 logpoint 中的代码:

Metadata.Key<String> DEBUG_HEADER =
        Metadata.Key.of("Debug", Metadata.ASCII_STRING_MARSHALLER);

String debugHeader = headers.get(DEBUG_HEADER);

if ("Debug".equals(debugHeader)) {
    timeoutNanos = java.util.concurrent.TimeUnit.MINUTES.toNanos(5L);
    return "Timeout reset";
}

这个多行表达式会解析请求 headers,并且只为带有 Debug header 的请求 (我们的测试客户端会添加它)延长 timeout。其他请求会保留正常的 deadline。 if 分支会返回 "Timeout reset",用于确认该分支何时被访问。


Info icon

你可以把 logpoint 与 IntelliJ IDEA 中更高级的功能结合起来,比如 标记对象 (Mark Object)。 如果这听起来有意思,可以看看这篇文章。

当然,这种方法要求你熟悉该库,或者花时间探索它。 如果两者都没有,只是想快速改变运行时行为,也可以使用内置的 AI agent skill 把任务交给 AI agent:

OpenAI Codex terminal showing a prompt to add a logpoint that resets incoming request timeouts to five minutes IntelliJ IDEA AI Agents terminal showing a non-suspending logpoint added to GrpcQuoteServer.java

总结

在这篇文章中,我们看到了一个使用场景:logpoint 可以作为比断点或 println logging 更简单、更优雅的替代方案。我们:

希望你学到了一些新东西,并且下次当 println 语句或断点碍事时, 能多一个更好的选择。 在本系列的下一篇文章中,我们会看看 debugger instrumentation 是如何工作的, 也就是让新的 logpoint 如此快速的底层机制。

祝你调试愉快!

all posts ->