使用 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 ->