《Java 编程实战》10.3 异步边界:阻塞、上下文与可观测性

异步任务换线程之后,MDC 里的 requestId 会变成空,ThreadLocal 也读不到;InheritableThreadLocal 只在创建线程时复制一次,线程池复用后照样丢。本节用真实日志展示这三类丢失,给出 MdcExecutor 传递与清理方案,并讨论阻塞 JDBC、orTimeout 不取消上游、异常解包这几个边界。

本节目标:让异步任务在换线程之后仍然带着 requestId,并且让阻塞、超时和异常在边界上可解释。
适用版本:JDK 25(Temurin 25.0.5);SLF4J 2.0.20;Logback 1.5.38(本机验证用)。

承接的问题

10.2 的 MemberLoansService 把查询拆成两波,第一波两个任务、第二波一个任务。请求线程提交完任务就返回,真正执行 SQL 的是 libraryd-worker-* 线程。第 7 章在请求入口把 requestId 放进 MDC,第 8 章用它生成 Problem Details 的 requestId 字段。现在这些值到了工作线程里还在吗?

答案通常是不在。MDC 底层是 ThreadLocal<Map<String, String>>,每个线程一份;工作线程不是请求线程,它没有那份 map。日志里 requestId= 后面是空的,排查问题时只能看到「member loans failed」,不知道是哪个请求。

比日志更隐蔽的是异常。异步任务的异常被包在 CompletionException 里,再经过 join() 或 get() 包一层;如果只打 e.getMessage(),看到的可能只是 java.util.concurrent.CompletionException,真正的原因在 getCause() 里。上下文和异常一起丢,异步链路就变成了黑盒。

这一节处理四个边界:

  • 上下文:MDC、ThreadLocal、InheritableThreadLocal 在异步线程里的真实行为。
  • 阻塞:JDBC 是阻塞 API,应该放在哪个执行器里。
  • 超时:orTimeout 完成的是 future,不是数据库查询。
  • 异常:从 CompletionException 里解出领域异常,再映射成 HTTP。

上下文不会自动过线程

先写一个最小实验:主线程设置 requestId=req-42,然后分别在普通工作池、包装后的工作池、common pool 里读 MDC;再用 ThreadLocal 和 InheritableThreadLocal 对比。本机输出:

17:53:57.791 [main] requestId=req-42 - main thread
17:53:57.793 [lib-pool] requestId= - plain submit in pool
17:53:57.811 [lib-pool] requestId=req-42 - wrapped submit in pool
ThreadLocal in pool = null
ThreadLocal in main = tl-main
InheritableThreadLocal in fresh thread = created-before
InheritableThreadLocal in reused pool thread = null
17:53:57.816 [ForkJoinPool.commonPool-worker-1] requestId= - supplyAsync common pool
MDC in common pool = null
17:53:57.817 [lib-io] requestId=req-42 - thenApplyAsync in wrapped executor
MDC in wrapped async = req-42

四行结论对应四个事实:

  • 普通 submit 到线程池,MDC 是空的。工作线程没有请求线程的 ThreadLocal。
  • 包装后的 executor 在提交时复制 MDC,执行时设置,执行完恢复,日志里能看到 req-42。
  • InheritableThreadLocal 只在创建线程时复制一次。新建的 fresh 线程拿到了 created-before;线程池里的线程早就创建好了,再改值也不会同步,所以复用线程读到 null。
  • common pool 的线程同样没有上下文;thenApplyAsync 如果传的是包装 executor,就能拿到 req-42。

包装 executor 的核心是「提交时抓取、执行时设置、结束时恢复」:

package com.plume.library.app;

import org.slf4j.MDC;

import java.util.Map;
import java.util.concurrent.Executor;

public final class MdcExecutor implements Executor {

    private final Executor delegate;

    public MdcExecutor(Executor delegate) {
        this.delegate = delegate;
    }

    @Override
    public void execute(Runnable task) {
        Map<String, String> captured = MDC.getCopyOfContextMap();
        delegate.execute(() -> {
            Map<String, String> previous = MDC.getCopyOfContextMap();
            if (captured == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(captured);
            }
            try {
                task.run();
            } finally {
                if (previous == null) {
                    MDC.clear();
                } else {
                    MDC.setContextMap(previous);
                }
            }
        });
    }
}

previous 不是多余的。工作线程可能被嵌套包装,或者上一次任务留下了脏值;恢复而不是直接 clear(),可以保证外层上下文不被内层破坏。captured == null 时显式 clear(),避免复用线程上残留上一个请求的 requestId。

这个包装只解决「提交时上下文是什么」。如果请求线程在提交之后修改 MDC,工作线程看到的仍是提交那一刻的快照,这是有意的:一个异步任务应该绑定它被创建时的请求上下文,而不是执行时碰巧在哪个请求里。

阻塞任务放在哪里

上下文解决的是日志,阻塞解决的是资源。JDBC 是阻塞 API,Statement.executeQuery() 会一直占着线程直到数据库返回。它不能放在 common pool,因为 common pool 的线程数是 CPU 核数减一,占住后会影响其他使用 common pool 的库;也不能无限制地开虚拟线程,因为 Hikari 只有 10 个连接。

libraryd 的选择是:

  • HTTP 请求线程用虚拟线程,等待不占载体线程。
  • 数据库任务交给有界的 libraryd-worker-* 池,队列满时按 9.3 的规则返回 503。
  • 池的大小和 Hikari 的 maximumPoolSize 对齐,信号量再限制同时进入数据库的任务数。

如果坚持用虚拟线程执行数据库任务,也必须加信号量:

package com.plume.library.app;

import java.util.concurrent.Callable;
import java.util.concurrent.Semaphore;

public final class DbConcurrencyGate {

    private final Semaphore permits;

    public DbConcurrencyGate(int maxConcurrent) {
        this.permits = new Semaphore(maxConcurrent, true);
    }

    public <T> T call(Callable<T> task) throws Exception {
        permits.acquire();
        try {
            return task.call();
        } finally {
            permits.release();
        }
    }
}

虚拟线程让「等待」变便宜,但不会让连接变多。10000 个虚拟线程同时 getConnection(),Hikari 仍然只给 10 个,其余 9990 个在连接池的等待队列里。连接池的 connectionTimeout 要设成有限值,不能是默认的 30 秒甚至无限,否则请求会挂很久才失败。

超时与异常:边界上要解包

orTimeout 在 10.1 已经看过:500ms 的任务配 200ms 超时,208ms 时 join() 抛 CompletionException,原因是 TimeoutException。它完成的是 CompletableFuture,不是数据库查询。数据库查询要继续跑,直到 Statement.setQueryTimeout 生效,或者驱动自己返回。

所以超时要分三层:

层手段作用
HTTPJavalin/Jetty 请求超时客户端不会无限等
异步orTimeout / completeOnTimeout调用方在指定时间拿到失败或降级值
数据库Statement.setQueryTimeout让 PostgreSQL 取消查询,释放连接

异常也要在边界上解包。join() 抛 CompletionException,get() 抛 ExecutionException,里面可能还有一层 CompletionException。写一个统一的解包方法:

package com.plume.library.app;

import com.plume.library.domain.ErrorCode;
import com.plume.library.domain.LibraryException;

import java.util.concurrent.CompletionException;
import java.util.concurrent.ExecutionException;

public final class AsyncErrors {

    private AsyncErrors() {
    }

    public static LibraryException translate(Throwable error) {
        Throwable cause = unwrap(error);
        if (cause instanceof LibraryException libraryException) {
            return libraryException;
        }
        if (cause instanceof java.util.concurrent.TimeoutException) {
            return new LibraryException(ErrorCode.DB_UNAVAILABLE,
                    "async task timed out", cause);
        }
        if (cause instanceof java.util.concurrent.RejectedExecutionException) {
            return new LibraryException(ErrorCode.SERVICE_OVERLOADED,
                    "worker queue is full", cause);
        }
        return new LibraryException(ErrorCode.INTERNAL,
                "async task failed", cause);
    }

    public static Throwable unwrap(Throwable error) {
        Throwable current = error;
        while ((current instanceof CompletionException
                || current instanceof ExecutionException)
                && current.getCause() != null) {
            current = current.getCause();
        }
        return current;
    }
}

unwrap 只剥 CompletionException 和 ExecutionException,不剥业务异常。LibraryException 的 cause 可能是 SQLException,但它的类型本身是要传给 HTTP 层的,不能再往下剥。这个区分要在代码里写清楚,否则容易把 LibraryException 剥成 SQLException,最后映射成 500。

日志里要同时记录 requestId、任务名、耗时和异常。一个可接受的格式是:

INFO  [libraryd-worker-3] requestId=req-7a2 task=member-loans elapsedMs=214 loans=3
ERROR [libraryd-worker-5] requestId=req-7a3 task=member-loans elapsedMs=2003 error=TimeoutException

第一条是成功路径,第二条是超时路径。两条都带 requestId,因为工作线程执行的是包装后的 executor。没有这个字段,两条日志无法和 HTTP 访问日志对上。

在 libraryd 里落地

先定义请求上下文,再把它包进异步执行器。RequestContext 只保存需要在异步边界传递的字段:

package com.plume.library.app;

public record RequestContext(String requestId, String memberId) {
}

入口处由第 7 章的中间件生成 requestId,第 8 章的异常映射把它写进 Problem Details。异步服务不直接读 RequestContext,而是读 MDC;这样日志框架、异常映射和业务代码共用同一份上下文。

AsyncBookQueryService 用包装后的 executor 提交任务:

package com.plume.library.app;

import com.plume.library.web.BookDto;
import com.plume.library.web.PageResponse;

import java.util.List;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CompletionException;
import java.util.concurrent.Executor;
import java.util.concurrent.TimeUnit;

public final class AsyncBookQueryService {

    private final BookSearchRepository repository;
    private final Executor io;

    public AsyncBookQueryService(BookSearchRepository repository, Executor io) {
        this.repository = repository;
        this.io = new MdcExecutor(io);
    }

    public PageResponse<BookDto> search(String q, int page, int size) {
        int offset = page * size;
        CompletableFuture<List<BookDto>> items = CompletableFuture.supplyAsync(
                () -> repository.search(q, offset, size).stream()
                        .map(BookDto::from)
                        .toList(),
                io);
        CompletableFuture<Long> total = CompletableFuture.supplyAsync(
                () -> repository.count(q), io);

        try {
            return items.thenCombine(total,
                            (list, count) -> new PageResponse<>(list, count, page, size))
                    .orTimeout(2, TimeUnit.SECONDS)
                    .join();
        } catch (CompletionException e) {
            throw AsyncErrors.translate(e);
        }
    }
}

构造函数里包一层 MdcExecutor,调用方传进来的仍然是原来的 ThreadPoolExecutor,但所有通过 supplyAsync 提交的任务都会带上提交时的 MDC。thenCombine 的合并函数在完成线程上执行,不涉及新的任务提交;如果合并函数里要写日志,它已经在带有 MDC 的线程上,或者已经回到请求线程。

如果任务内部还要提交子任务,子任务必须继续使用包装 executor,否则上下文在第二层断掉。更稳妥的做法是把 executor 作为依赖注入到需要提交任务的服务里,而不是在任务体里临时 CompletableFuture.supplyAsync 不传 executor。

AppMain 的装配顺序:

ThreadPoolExecutor workers = ExecutorConfig.newWorkerPool(
        config.workerThreads(), config.workerQueueCapacity(), "libraryd-worker-");
Executor mdcWorkers = new MdcExecutor(workers);
AsyncBookQueryService queryService = new AsyncBookQueryService(repository, mdcWorkers);

请求入口设置 MDC 的代码在第 12 章会完整展开;这里只需要保证:进入 Javalin 处理器时 MDC.put("requestId", requestId),离开时 MDC.remove("requestId")。异步任务在提交时复制这份 map,执行时设置,执行完恢复。

可观测性:没有 requestId 的日志等于没有

异步链路的日志至少要能回答:

  • 这是哪个请求(requestId)。
  • 这是哪个任务(task)。
  • 跑了多久(elapsedMs)。
  • 结果是什么(成功、超时、拒绝、业务错误)。
  • 当时池里有多满(queue、active,可以从 PoolSnapshot 取)。

一个轻量的计时包装可以在不引入 Micrometer 的情况下先满足日志需求:

private static final Logger LOG = LoggerFactory.getLogger(AsyncBookQueryService.class);

static <T> CompletableFuture<T> timed(String task, CompletableFuture<T> future) {
    long start = System.nanoTime();
    return future.whenComplete((value, error) -> {
        long elapsedMs = (System.nanoTime() - start) / 1_000_000;
        if (error == null) {
            LOG.info("task={} elapsedMs={}", task, elapsedMs);
        } else {
            LOG.warn("task={} elapsedMs={} error={}", task, elapsedMs,
                    AsyncErrors.unwrap(error).getClass().getSimpleName());
        }
    });
}

Logger 与 LoggerFactory 来自 org.slf4j;本机用 SLF4J 2.0.20 与 Logback 1.5.38 验证,MDC 的键值会被 %X{requestId} 输出。whenComplete 不改变结果,异常会继续往下传,所以它适合做旁路日志。注意 whenComplete 里的日志同样需要 MDC;如果这个 future 是在包装 executor 上完成的,MDC 还在;如果是在 common pool 或调用线程上完成,可能已经丢了。第 12 章会把日志格式统一成 JSON,第 13 章再用 Micrometer 把耗时变成指标;本节先把字段留出来。

常见错误与边界

「用 InheritableThreadLocal 传递请求上下文。」 它只在创建线程时复制一次。线程池的线程是复用的,第一次任务可能碰巧继承到值,第二次就变成 null 或上一个请求的值。本机输出里,fresh 线程拿到了 created-before,复用池线程读到 null,这就是它的边界。

「包装 executor 后忘记清理 MDC。」 工作线程执行完任务,如果只 setContextMap 不恢复,下一个任务会看到上一个请求的 requestId。日志里出现「请求 A 的日志带着请求 B 的 ID」,比没有 ID 更难排查。finally 里的恢复逻辑不能省。

「把 orTimeout 当成查询取消。」 它只让 CompletableFuture 以 TimeoutException 结束,SQL 还在数据库里跑,连接还被占着。必须同时设置 Statement.setQueryTimeout,并在必要时 cancel(true);cancel(true) 也只是中断线程,JDBC 驱动不一定响应。

「只打 CompletionException 的 message。」 CompletionException 的 message 往往是 java.util.concurrent.CompletionException 或空,真正的原因在 getCause()。用 AsyncErrors.unwrap 剥到业务异常或根因,再决定日志级别和 HTTP 状态。

「在请求线程上 join() 所有异步任务。」 join() 仍然阻塞。它的价值是把阻塞收在一个边界上,而不是让每个 repository 调用都阻塞一次。如果请求线程是平台线程,join() 会占住它;如果是虚拟线程,等待便宜一些,但请求延迟仍然存在。能组合的 future 尽量组合,最后只 join() 一次。

「在异步任务里用 ThreadLocal 存大对象。」 工作线程是复用的,ThreadLocal 不清理会一直持有对象;虚拟线程数量大时,每个线程一份 ThreadLocal 也会放大内存。上下文只放 requestId 这类小字段,任务结束就清理。

小结

  • MDC 底层是 ThreadLocal,异步任务换线程后默认读不到;普通提交、common pool、复用池线程都会丢。
  • InheritableThreadLocal 只在创建线程时复制一次,不能作为线程池的上下文传递方案。
  • MdcExecutor 在提交时复制、执行时设置、结束时恢复,能覆盖 supplyAsync 和 thenApplyAsync 的提交点。
  • JDBC 是阻塞调用,放在有界工作池或虚拟线程加信号量里;连接池容量才是并发上限。
  • 超时要分 HTTP、异步、数据库三层;orTimeout 不取消上游查询。
  • CompletionException 和 ExecutionException 要解包到业务异常,再交给第 8 章的映射。
  • 异步日志至少带 requestId、task、elapsedMs 和错误类型,否则无法和访问日志对齐。

异步的请求路径已经有了上下文和超时,接下来把视角从「一次请求」转到「按时间重复执行的任务」:每天扫逾期、每月结算罚金,以及这些任务如何不重复执行。

阅读导航:上一节:10.2 异步编排:并行查询与结果合并 · 下一节:11.1 ScheduledExecutorService:周期任务与时钟 。

继续阅读

探索更多技术文章

浏览归档,发现更多关于系统设计、工具链和工程实践的内容。

全部文章 返回首页

「java」更多文章

  1. 《Netty 高性能网络编程》15.3 linkd-v2 验收与复盘
  2. 《Netty 高性能网络编程》15.2 限流、超时与降级
  3. 《Netty 高性能网络编程》15.1 网关路由与转发