feat：下单操作写入日志

2026-10-23 16:07:22 +08:00
1 parent 0259445866
commit 42e0323080
@@ -0,0 +1,58 @@
+# 消费机创建订单分段耗时
+
+外部接口 `/hard/hard-api/ad/create-order` 对应 hard 服务内部
+`POST /hard-api/ad/create-order`。本次诊断仅观察该请求，不改变请求协议、
+事务注解、分布式锁、支付顺序、重试和返回值。
+
+## 日志策略与开销
+
+- 通过 `System.nanoTime()` 和请求内存中的阶段表计时，不新增 SQL、Redis 或 Feign 请求。
+- 正常且小于 1 秒的请求不新增摘要；慢请求、失败及阶段内被业务处理的异常输出一条 warning。
+- 摘要在过滤器链返回或抛错后统一生成，不在扣款写事务中逐阶段输出日志。
+- 专用 Logback 异步队列容量为 256，`neverBlock=true`。队列满时丢弃诊断摘要，不等待落盘。
+- 使用已有 `debug.log` 文件；不写入 DTO、人员资料、金额、令牌、付款码、图片或异常消息。
+
+计时与内存分配存在少量开销，不能承诺零开销。异步队列优先保障请求返回，
+日志管道持续拥堵时可能缺少部分诊断记录。
+
+## 取日志与匹配
+
+部署包含 Java 代码和 `logback-spring.xml` 改动的 hard 服务后，在 `debug.log`
+搜索 `|终端支付耗时|`。按 `androidOrderCode` 与消费机的 `|支付耗时|` 摘要、
+原有订单 SQL 对齐；同号重试可通过不同的 `trace` 区分请求。
+
+`outcome:failed` 是请求未正常完成，不能单凭这一字段判断钱包是否已经扣款；
+仍需按原有订单对账逻辑确认。旁路通知或证据登记异常被业务自行处理时，
+请求可能保持 `outcome:success`，异常类型保存在 `stageErrorTypes` 中。
+
+## 主要阶段
+
+| 字段 | 范围 |
+| --- | --- |
+| `pre_controller` | 请求监听器开始至 Controller 进入，含期间租户检查、认证、解析及校验 |
+| `controller` | Controller 参数整理、Service 调用和返回对象创建 |
+| `redis.lock` / `redis.unlock` | 原有 Redis 加锁、持锁检查及解锁 |
+| `idempotency.lookup` / `idempotency.validate` | 原订单查询及重复请求一致性校验 |
+| `prepare` | 下单准备整体，含下面的远程及本地查询 |
+| `prepare.merchant` / `prepare.hardware` | 商户远程查询、设备本地查询 |
+| `prepare.user` / `prepare.wallet` / `prepare.cart` | 用户、钱包及商品计价准备 |
+| `transaction` | 原有代理事务调用，包含事务开始、提交及同步 afterCommit |
+| `db.cart` / `db.orderInsert` | 购物车和订单写入 |
+| `wallet.debit` | 原有钱包扣款远程调用 |
+| `db.orderPaid` / `db.cartPaid` | 已支付状态更新 |
+| `afterCommit.evidence` | 原有同步人脸证据元数据登记 |
+| `postCommit.notify` | 原有提交后打印/播报分支 |
+
+`stagesInclusiveMs` 单位为毫秒，父阶段包含子阶段，不能直接相加。
+其他支付方式仍按原逻辑执行，日志可出现核销、库存及第三方支付阶段。
+
+## 时间边界
+
+监听器在 Servlet 过滤器之前记录起点，专用过滤器在原有租户过滤器之后、
+安全过滤器之前绑定请求追踪，不调整已有过滤器顺序。
+若请求在更早的租户过滤器中直接拒绝，尚未进入计时过滤器，则不会产生本摘要。
+
+`totalMs` 截止过滤器链返回，不是客户端端到端耗时；不覆盖网关和入站网络、
+容器调用请求监听器前的排队、最后的响应传输，以及客户端本地处理。
+因此“客户端 4500ms、服务摘要 200ms”只能证明还需排查摘要计时区间之外的等待，
+不能直接认定为 Flutter 程序卡顿。
@@ -0,0 +1,56 @@
+package com.bsd.pjcloud.hard.config;
+
+import com.bsd.pjcloud.hard.config.filter.CreateOrderPaymentTimingFilter;
+import jakarta.servlet.DispatcherType;
+import jakarta.servlet.ServletRequestEvent;
+import jakarta.servlet.ServletRequestListener;
+import jakarta.servlet.http.HttpServletRequest;
+import org.springframework.boot.web.servlet.FilterRegistrationBean;
+import org.springframework.boot.web.servlet.ServletListenerRegistrationBean;
+import org.springframework.context.annotation.Bean;
+import org.springframework.context.annotation.Configuration;
+import org.springframework.core.Ordered;
+
+import java.util.function.LongSupplier;
+
+@Configuration(proxyBeanMethods = false)
+public class PaymentTimingConfiguration {
+    /** 请求监听器先于全部过滤器，避免调整现有 Integer.MIN_VALUE 的租户过滤器顺序。 */
+    @Bean
+    public ServletListenerRegistrationBean<RequestStartListener> paymentTimingRequestStartListener() {
+        return new ServletListenerRegistrationBean<>(new RequestStartListener(System::nanoTime));
+    }
+
+    /** 租户检查之后、安全认证之前建立线程内追踪，耗时仍从监听器记录的时间开始。 */
+    @Bean
+    public FilterRegistrationBean<CreateOrderPaymentTimingFilter> paymentTimingFilter() {
+        FilterRegistrationBean<CreateOrderPaymentTimingFilter> registration =
+                new FilterRegistrationBean<>(new CreateOrderPaymentTimingFilter());
+        registration.setName("createOrderPaymentTimingFilter");
+        registration.addUrlPatterns(CreateOrderPaymentTimingFilter.PATH);
+        registration.setDispatcherTypes(DispatcherType.REQUEST);
+        registration.setAsyncSupported(true);
+        registration.setOrder(Ordered.HIGHEST_PRECEDENCE + 1);
+        return registration;
+    }
+
+    public static final class RequestStartListener implements ServletRequestListener {
+        private final LongSupplier clock;
+
+        public RequestStartListener(LongSupplier clock) {
+            this.clock = clock;
+        }
+
+        @Override
+        public void requestInitialized(ServletRequestEvent event) {
+            try {
+                if (event.getServletRequest() instanceof HttpServletRequest request
+                        && CreateOrderPaymentTimingFilter.matches(request)) {
+                    request.setAttribute(CreateOrderPaymentTimingFilter.STARTED_AT_ATTRIBUTE, clock.getAsLong());
+                }
+            } catch (Throwable ignored) {
+                // 诊断监听器不参与请求受理；没有时间戳时过滤器从自身入口开始计时。
+            }
+        }
+    }
+}
@@ -0,0 +1,54 @@
+package com.bsd.pjcloud.hard.config.filter;
+
+import com.bsd.pjcloud.hard.support.PaymentTimingTrace;
+import jakarta.servlet.FilterChain;
+import jakarta.servlet.ServletException;
+import jakarta.servlet.http.HttpServletRequest;
+import jakarta.servlet.http.HttpServletResponse;
+import org.springframework.web.filter.OncePerRequestFilter;
+
+import java.io.IOException;
+import java.util.function.LongFunction;
+
+/** 只观察同步的终端下单请求，不读取请求体、不更改响应或安全配置。 */
+public class CreateOrderPaymentTimingFilter extends OncePerRequestFilter {
+    public static final String PATH = "/hard-api/ad/create-order";
+    public static final String STARTED_AT_ATTRIBUTE = CreateOrderPaymentTimingFilter.class.getName() + ".startedAtNanos";
+    private final LongFunction<PaymentTimingTrace.Scope> opener;
+
+    public CreateOrderPaymentTimingFilter() {
+        this(PaymentTimingTrace::open);
+    }
+
+    public CreateOrderPaymentTimingFilter(LongFunction<PaymentTimingTrace.Scope> opener) {
+        this.opener = opener;
+    }
+
+    public static boolean matches(HttpServletRequest request) {
+        String contextPath = request.getContextPath();
+        return "POST".equals(request.getMethod())
+                && ((contextPath == null ? "" : contextPath) + PATH).equals(request.getRequestURI());
+    }
+
+    @Override
+    protected boolean shouldNotFilter(HttpServletRequest request) {
+        return !matches(request);
+    }
+
+    @Override
+    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
+            throws ServletException, IOException {
+        Object start = request.getAttribute(STARTED_AT_ATTRIBUTE);
+        long startedAtNanos = start instanceof Long ? (Long) start : System.nanoTime();
+        try (PaymentTimingTrace.Scope scope = opener.apply(startedAtNanos)) {
+            try {
+                chain.doFilter(request, response);
+            } catch (IOException | ServletException | RuntimeException | Error error) {
+                PaymentTimingTrace.markFailure(error);
+                throw error;
+            } finally {
+                scope.finish(response.getStatus());
+            }
+        }
+    }
+}
@@ -28,6 +28,7 @@ import com.bsd.pjcloud.hard.api.vo.order.HardCreateHardQrCodeScanOrderVo;
 import com.bsd.pjcloud.hard.api.vo.order.HardOrderVo;
 import com.bsd.pjcloud.hard.api.vo.order.HardOrderByAndroidCodeVo;
 import com.bsd.pjcloud.hard.service.*;
+import com.bsd.pjcloud.hard.support.PaymentTimingTrace;
 import io.swagger.v3.oas.annotations.Operation;
 import io.swagger.v3.oas.annotations.security.SecurityRequirement;
 import io.swagger.v3.oas.annotations.tags.Tag;
@@ -160,18 +161,28 @@ public class HardApiController {
    @Operation(summary = "创建订单")
    // Service 按设备和 androidOrderCode 加自动续期锁并复用已支付订单，旧终端无需新增字段。
    public R<Long> createOrder(@Valid @RequestBody HardCreateOrderDto dto) {
-        // 处理商品类型
-        if (ObjectUtil.isNotEmpty(dto.getList())) {
-            for (HardCreateCarDto item : dto.getList()) {
-                if (ObjectUtil.isEmpty(item.getProductNature())) continue;
-                if (ObjectUtil.isNotEmpty(item.getProductWeight()) && item.getProductWeight().compareTo(BigDecimal.valueOf(0)) != 0) {
-                    item.setProductNature(HardProductNatureEnum.WEIGHT);
-                } else if (ObjectUtil.isNotEmpty(item.getProductCount())) {
-                    item.setProductNature(HardProductNatureEnum.DEFAULT);
+        PaymentTimingTrace.markControllerEntered();
+        PaymentTimingTrace.bind(dto.getAndroidOrderCode(), dto.getHardwareId());
+        try {
+            return PaymentTimingTrace.call("controller", () -> {
+                // 处理商品类型
+                if (ObjectUtil.isNotEmpty(dto.getList())) {
+                    for (HardCreateCarDto item : dto.getList()) {
+                        if (ObjectUtil.isEmpty(item.getProductNature())) continue;
+                        if (ObjectUtil.isNotEmpty(item.getProductWeight()) && item.getProductWeight().compareTo(BigDecimal.valueOf(0)) != 0) {
+                            item.setProductNature(HardProductNatureEnum.WEIGHT);
+                        } else if (ObjectUtil.isNotEmpty(item.getProductCount())) {
+                            item.setProductNature(HardProductNatureEnum.DEFAULT);
+                        }
+                    }
                }
-            }
+                return R.ok(hardwareOrderService.createOrder(dto));
+            });
+        } catch (RuntimeException | Error failure) {
+            // 业务异常可能被统一异常处理器转换为 HTTP 200，仍保留失败请求的计时摘要。
+            PaymentTimingTrace.markFailure(failure);
+            throw failure;
        }
-        return R.ok(hardwareOrderService.createOrder(dto));
    }

    @PostMapping("/create-hard-qr-code-order")
@@ -73,6 +73,7 @@ import com.bsd.pjcloud.hard.mapper.HardThirdMiOrderMapper;
 import com.bsd.pjcloud.hard.mapper.order.HardOrderMapper;
 import com.bsd.pjcloud.hard.service.*;
 import com.bsd.pjcloud.hard.service.order.HardOrderCartSnapshot;
+import com.bsd.pjcloud.hard.support.PaymentTimingTrace;
 import com.bsd.pjcloud.supermarket.api.feign.RemoteMallProductService;
 import com.bsd.pjcloud.supermarket.api.feign.RemoteShopSkuService;
 import com.bsd.pjcloud.supermarket.api.feign.RemoteSupermarketSpuService;
@@ -282,24 +283,28 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
            throw new RuntimeException("安卓订单code不能为空");
        }
        RLock lock = redissonClient.getLock(keyStrResolver.extract("hard:order:create:" + dto.getHardwareId() + ":" + dto.getAndroidOrderCode(), ":"));
-        if (!lock.tryLock()) throw new RuntimeException("正在创建订单中，请勿重复操作");
+        if (!PaymentTimingTrace.call("redis.lock", lock::tryLock)) throw new RuntimeException("正在创建订单中，请勿重复操作");
        Long orderId;
        CreateOrderContext context;
        try {
-            HardOrderEntity existing = findTerminalOrder(dto.getAndroidOrderCode(), dto.getHardwareId());
+            HardOrderEntity existing = PaymentTimingTrace.call("idempotency.lookup",
+                    () -> findTerminalOrder(dto.getAndroidOrderCode(), dto.getHardwareId()));
            if (existing != null) {
-                validateReusableOrder(existing, dto);
+                PaymentTimingTrace.run("idempotency.validate", () -> validateReusableOrder(existing, dto));
                return existing.getId();
            }
            // 远程只读查询全部先完成，数据库写事务不等待商户、用户、钱包和商品查询。
-            context = prepareCreateOrder(dto);
-            orderId = getSelf().createOrderInTransaction(dto, context);
+            context = PaymentTimingTrace.call("prepare", () -> prepareCreateOrder(dto));
+            // 包住代理调用，包含原事务的开启、提交及同步 afterCommit；阶段可嵌套，不能直接相加。
+            orderId = PaymentTimingTrace.call("transaction", () -> getSelf().createOrderInTransaction(dto, context));
        } finally {
-            if (lock.isHeldByCurrentThread()) lock.unlock();
+            PaymentTimingTrace.run("redis.unlock", () -> {
+                if (lock.isHeldByCurrentThread()) lock.unlock();
+            });
        }
        // 提交后再生成打印/播报任务；旁路失败不能把已经扣款的订单反向报告为失败。
        try {
-            getSelf().createOrderAfterSendMqMsg(orderId, context.userDetail);
+            PaymentTimingTrace.run("postCommit.notify", () -> getSelf().createOrderAfterSendMqMsg(orderId, context.userDetail));
        } catch (Exception exception) {
            log.warn("|{}|订单已提交，通知失败|orderId:{}|", TAG, orderId, exception);
        }
@@ -310,7 +315,7 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
     * 无写事务的准备阶段，保留 PJ 原有钱包选择、额外餐费和一次商品查询的计价规则。
     */
    private CreateOrderContext prepareCreateOrder(HardCreateOrderDto dto) {
-        MchManageVo mch = validateCreateOrderDto(dto);
+        MchManageVo mch = PaymentTimingTrace.call("prepare.validate", () -> validateCreateOrderDto(dto));
        if (ObjectUtil.isEmpty(mch)) throw new RuntimeException("机器绑定的商户不存在");
        // 是否需要钱包支付
        boolean isWalletPay = isPay(dto.getOrderType(), dto.getOrderPayType());
@@ -327,7 +332,8 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        UserInfo userDetail = null;
        SysUser sysUser = null;
        if (isWalletPay || isVerify) {
-            userDetail = requireCreateOrderData(userService.getInnerByUserId(dto.getUserId()), "用户不存在");
+            userDetail = PaymentTimingTrace.call("prepare.user",
+                    () -> requireCreateOrderData(userService.getInnerByUserId(dto.getUserId()), "用户不存在"));
            if (ObjectUtil.isEmpty(userDetail.getSysUser())) throw new RuntimeException("用户不存在");
            sysUser = userDetail.getSysUser();
        }
@@ -337,19 +343,23 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        WalletManageEntity wallet = null;
        if (isWalletPay) {
            if (ObjectUtil.isNotEmpty(dto.getWalletId()) && ObjectUtil.equals(dto.getSysType(), HardTypeEnum.SUPERMARKET)) {
-                R<WalletManageVo> walletResult = remoteWalletService.getWalletById(dto.getWalletId());
+                R<WalletManageVo> walletResult = PaymentTimingTrace.call("prepare.wallet",
+                        () -> remoteWalletService.getWalletById(dto.getWalletId()));
                wallet = requireCreateOrderData(walletResult, "用户钱包不存在");
            } else {
                if (ObjectUtil.isEmpty(mch.getDefaultWalletTypeId())) {
                    if (dto.getSysType().equals(HardTypeEnum.CANTEEN)) {
-                        R<WalletManageEntity> walletResult = remoteWalletService.getWallet(dto.getUserId(), WalletTypeEnum.EAT);
+                        R<WalletManageEntity> walletResult = PaymentTimingTrace.call("prepare.wallet",
+                                () -> remoteWalletService.getWallet(dto.getUserId(), WalletTypeEnum.EAT));
                        wallet = requireCreateOrderData(walletResult, "用户钱包不存在");
                    } else {
-                        R<WalletManageEntity> walletResult = remoteWalletService.getWallet(dto.getUserId(), WalletTypeEnum.PAY);
+                        R<WalletManageEntity> walletResult = PaymentTimingTrace.call("prepare.wallet",
+                                () -> remoteWalletService.getWallet(dto.getUserId(), WalletTypeEnum.PAY));
                        wallet = requireCreateOrderData(walletResult, "用户钱包不存在");
                    }
                } else {
-                    R<WalletManageEntity> walletResult = remoteWalletService.getWalletByWalletTypeId(dto.getUserId(), mch.getDefaultWalletTypeId());
+                    R<WalletManageEntity> walletResult = PaymentTimingTrace.call("prepare.wallet",
+                            () -> remoteWalletService.getWalletByWalletTypeId(dto.getUserId(), mch.getDefaultWalletTypeId()));
                    wallet = requireCreateOrderData(walletResult, "用户钱包不存在");
                }
            }
@@ -364,15 +374,20 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
            }
        } else if (isVerify) {
            // 判断该二维码有没有被核销
-            boolean isCancel = validateCodeIsCancel(dto.getOrderType(), dto.getOrderSourceTypeId());
+            boolean isCancel = PaymentTimingTrace.call("prepare.verifyCode",
+                    () -> validateCodeIsCancel(dto.getOrderType(), dto.getOrderSourceTypeId()));
            if (isCancel) throw new RuntimeException("该二维码已被核销");
        }
-        HardOrderCartSnapshot cart = hardCarService.prepareCardWithCompute(dto.getSysType(), dto.getOrderType(), dto.getList());
+        HardOrderCartSnapshot cart = PaymentTimingTrace.call("prepare.cart",
+                () -> hardCarService.prepareCardWithCompute(dto.getSysType(), dto.getOrderType(), dto.getList()));
        if (cart == null) {
            // 非收银业态仍沿用旧计价/摘要规则，所有商品查询同样在写事务外完成。
-            int total = hardCarService.computerCarTotalPrice(dto.getSysType(), dto.getOrderType(), dto.getList());
-            String subject = hardCarService.computerCarSubject(dto.getSysType(), dto.getOrderType(), dto.getList());
-            cart = new HardOrderCartSnapshot(total, subject, hardCarService.prepareCard(dto.getSysType(), dto.getOrderType(), dto.getList()));
+            int total = PaymentTimingTrace.call("prepare.cartTotal",
+                    () -> hardCarService.computerCarTotalPrice(dto.getSysType(), dto.getOrderType(), dto.getList()));
+            String subject = PaymentTimingTrace.call("prepare.cartSubject",
+                    () -> hardCarService.computerCarSubject(dto.getSysType(), dto.getOrderType(), dto.getList()));
+            cart = new HardOrderCartSnapshot(total, subject, PaymentTimingTrace.call("prepare.cartDetails",
+                    () -> hardCarService.prepareCard(dto.getSysType(), dto.getOrderType(), dto.getList())));
        }
        int extraPrice = isExtraPrice && dto.getExtraPrice() != null ? dto.getExtraPrice() : 0;
        int payPrice = Math.addExact(cart.totalPrice(), extraPrice);
@@ -399,7 +414,8 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        int totalPrice = context.cart.totalPrice(), extraPrice = context.extraPrice;
        int payPrice = Math.addExact(totalPrice, extraPrice);
        String subject = context.cart.subject();
-        Long parentCarId = hardCarService.createCardFromSnapshot(dto.getUserId(), dto.getMerchantId(), dto.getSysType(), context.cart);
+        Long parentCarId = PaymentTimingTrace.call("db.cart",
+                () -> hardCarService.createCardFromSnapshot(dto.getUserId(), dto.getMerchantId(), dto.getSysType(), context.cart));
        // 添加硬件订单
        HardOrderEntity orderObj = HardOrderEntity.builder()
                .androidOrderCode(dto.getAndroidOrderCode())
@@ -430,20 +446,20 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        if (isWalletPay) {
            orderObj.setWalletId(wallet.getId());
        }
-        baseMapper.insert(orderObj);
+        PaymentTimingTrace.run("db.orderInsert", () -> baseMapper.insert(orderObj));
        registerEvidenceAfterCommit(orderObj, dto);
        // 扣减库存
-        getSelf().fastenerInventory(orderObj, YesNoEnum.YES);
+        PaymentTimingTrace.run("stock.reduce", () -> getSelf().fastenerInventory(orderObj, YesNoEnum.YES));
        // 钱包支付或者核销
        if (isVerify || isWalletPay) {
            // 钱包扣款
            try {
-                reduceOrderBalance(orderObj, false);
+                PaymentTimingTrace.run("payment", () -> reduceOrderBalance(orderObj, false));
            } catch (InsufficientWalletBalanceException rejected) {
                // 不透支扣款可能因另一台终端抢先消费而明确失败，此时库存服务已经提交。
                // 仅在余额不足的确定结果下恢复库存；超时等未知资金结果不能据此做补偿。
                try {
-                    getSelf().fastenerInventory(orderObj, YesNoEnum.NO);
+                    PaymentTimingTrace.run("stock.restore", () -> getSelf().fastenerInventory(orderObj, YesNoEnum.NO));
                } catch (Exception compensationFailure) {
                    rejected.addSuppressed(compensationFailure);
                    log.error("|{}|余额不足后的库存恢复失败，需核对库存|orderId:{}|", TAG, orderObj.getId(), compensationFailure);
@@ -451,40 +467,44 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
                throw rejected;
            }
            // 核销二维码
-            getSelf().cancelCode(orderObj, userDetail);
+            PaymentTimingTrace.run("verifyCode", () -> getSelf().cancelCode(orderObj, userDetail));
        }
        // 现金支付
        if (isOffline) {
            // 更改为支付成功
-            getSelf().orderSuccess(orderObj, Boolean.FALSE);
+            PaymentTimingTrace.run("payment.offlineSuccess", () -> getSelf().orderSuccess(orderObj, Boolean.FALSE));
        }
        // 微信支付
        if (isWeChatPay) {
            WechatMicropayDto wechatPayDto = WechatMicropayDto.builder().merId(orderObj.getMerchantId()).orderId(orderObj.getId()).price(payPrice).wechatQrCode(String.valueOf(dto.getOrderSourceTypeId())).build();
-            WechatMicropayVo wechatPayVo = wechatPayService.micropay(wechatPayDto);
+            WechatMicropayVo wechatPayVo = PaymentTimingTrace.call("payment.wechat",
+                    () -> wechatPayService.micropay(wechatPayDto));
            if (ObjectUtil.isEmpty(wechatPayVo)) {
                throw new RuntimeException("微信支付失败");
            }
            boolean wehcantPaySuccess = wechatPayVo.isAllSuccess();
            if (!wehcantPaySuccess) {
                // 如果微信支付订单返回不明确(不是支付成功)直接撤销支付
-                wechatPayService.reverse(WechantReverseDto.builder().orderId(orderObj.getId()).build());
+                PaymentTimingTrace.run("payment.wechatReverse",
+                        () -> wechatPayService.reverse(WechantReverseDto.builder().orderId(orderObj.getId()).build()));
                throw new RuntimeException(wechatPayVo.getErr_code_des());
            } else {
-                getSelf().orderSuccess(orderObj, Boolean.TRUE);
+                PaymentTimingTrace.run("payment.wechatSuccess", () -> getSelf().orderSuccess(orderObj, Boolean.TRUE));
            }
        }
        // 支付宝支付
        if (isAliPay) {
            AliMicropayDto wechatPayDto = AliMicropayDto.builder().merId(orderObj.getMerchantId()).orderId(orderObj.getId()).price(payPrice).subject(subject).authCode(String.valueOf(dto.getOrderSourceTypeId())).build();
-            AlipayTradePayResponse micropay = alipayService.micropay(wechatPayDto);
+            AlipayTradePayResponse micropay = PaymentTimingTrace.call("payment.alipay",
+                    () -> alipayService.micropay(wechatPayDto));
            if (ObjectUtil.isEmpty(micropay) || !micropay.isSuccess()) {
                // 如果支付宝支付订单返回不明确(不是支付成功)直接撤销支付
-                alipayService.reverse(AliReverseDto.builder().orderId(orderObj.getId()).build());
+                PaymentTimingTrace.run("payment.alipayReverse",
+                        () -> alipayService.reverse(AliReverseDto.builder().orderId(orderObj.getId()).build()));
                throw new RuntimeException(micropay == null ? "支付宝支付失败" : micropay.getSubMsg());
            } else {
                orderObj.setOrderNo(micropay.getTradeNo());
-                getSelf().orderSuccess(orderObj, Boolean.TRUE);
+                PaymentTimingTrace.run("payment.alipaySuccess", () -> getSelf().orderSuccess(orderObj, Boolean.TRUE));
            }
        }
        return orderObj.getId();
@@ -616,7 +636,8 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        }
        Runnable action = () -> {
            try {
-                hardOrderEvidenceImageService.registerOrderEvidence(order, dto.getEvidenceMetadataList(), dto.getAppVersion());
+                PaymentTimingTrace.run("afterCommit.evidence",
+                        () -> hardOrderEvidenceImageService.registerOrderEvidence(order, dto.getEvidenceMetadataList(), dto.getAppVersion()));
            } catch (Exception exception) {
                // 终端本地队列仍会按 androidOrderCode 补交，服务端占位失败不得改变订单支付结果。
                log.warn("|{}|订单证据占位登记失败|orderId:{}|error:{}|", TAG, order.getId(), exception.getMessage());
@@ -1630,7 +1651,8 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
                reduceBuild.setForce(force);
                R<WalletTransactionEntity> reduceRes;
                try {
-                    reduceRes = walletTransactionService.reduceWalletBalance(reduceBuild);
+                    reduceRes = PaymentTimingTrace.call("wallet.debit",
+                            () -> walletTransactionService.reduceWalletBalance(reduceBuild));
                } catch (FeignException rejected) {
                    // 钱包的全局异常处理器把余额不足包装成 HTTP 500 + R；Feign 会直接抛异常，
                    // 必须只识别这个明确业务结果，不能把一般 500 或网关超时当作扣款未发生。
@@ -1647,7 +1669,7 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        }
        // 订单成功
        if (isWalletPay || isVerify) {
-            getSelf().orderSuccess(order, isWalletPay);
+            PaymentTimingTrace.run("payment.success", () -> getSelf().orderSuccess(order, isWalletPay));
        }
    }

@@ -1679,11 +1701,11 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
        if (ObjectUtil.isNotEmpty(order.getOrderNo())) {
            update.setOrderNo(order.getOrderNo());
        }
-        baseMapper.updateById(update);
+        PaymentTimingTrace.run("db.orderPaid", () -> baseMapper.updateById(update));
        // 父购物车订单表订单状态
        if (ObjectUtil.isNotEmpty(order.getParentCarId())) {
            HardParentCarEntity updateParentCar = HardParentCarEntity.builder().id(order.getParentCarId()).orderStatus(HardOrderStatusEnum.PAY.getType()).build();
-            hardParentCarServiceImpl.updateById(updateParentCar);
+            PaymentTimingTrace.run("db.cartPaid", () -> hardParentCarServiceImpl.updateById(updateParentCar));
        }
    }

@@ -2240,9 +2262,11 @@ public class HardOrderServiceImpl extends ServiceImpl<HardOrderMapper, HardOrder
    }

    private MchManageVo validateCreateOrderDto(HardCreateOrderDto dto) {
-        MchManageVo mch = requireCreateOrderData(remoteMchService.getById(dto.getMerchantId()), "商户不存在");
+        MchManageVo mch = PaymentTimingTrace.call("prepare.merchant",
+                () -> requireCreateOrderData(remoteMchService.getById(dto.getMerchantId()), "商户不存在"));
        // 此处只取 deptId，按主键直查即可；getByHardId 还会联查部门和商户两次远程调用
-        HardManagerEntity hard = hardManagerService.getById(dto.getHardwareId());
+        HardManagerEntity hard = PaymentTimingTrace.call("prepare.hardware",
+                () -> hardManagerService.getById(dto.getHardwareId()));
        if (ObjectUtil.isEmpty(hard)) {
            throw new RuntimeException("设备不存在");
        }
@@ -0,0 +1,191 @@
+package com.bsd.pjcloud.hard.support;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import java.util.LinkedHashMap;
+import java.util.LinkedHashSet;
+import java.util.Map;
+import java.util.Set;
+import java.util.concurrent.atomic.AtomicLong;
+import java.util.function.Consumer;
+import java.util.function.LongSupplier;
+import java.util.function.Supplier;
+import java.util.regex.Pattern;
+import java.util.stream.Collectors;
+
+/** 终端下单的请求内计时；不修改支付结果，也不记录 DTO、金额、人员或异常消息。 */
+public final class PaymentTimingTrace {
+    private static final Logger LOG = LoggerFactory.getLogger(PaymentTimingTrace.class);
+    private static final ThreadLocal<Scope> CURRENT = new ThreadLocal<>();
+    private static final AtomicLong SEQUENCE = new AtomicLong();
+    private static final Pattern SAFE_IDENTIFIER = Pattern.compile("[A-Za-z0-9_.-]+");
+    private static final long SLOW_NANOS = 1_000_000_000L;
+
+    private PaymentTimingTrace() {
+    }
+
+    /** 时间由 ServletRequestListener 在过滤器之前采集，包含租户与安全过滤器的等待。 */
+    public static Scope open(long startedAtNanos) {
+        return open(startedAtNanos, System::nanoTime, LOG::warn);
+    }
+
+    /** 可注入单调时钟与日志接收器，测试无需休眠或启动真实服务。 */
+    public static Scope open(long startedAtNanos, LongSupplier clock, Consumer<String> log) {
+        Scope scope = new Scope(startedAtNanos, clock, log, CURRENT.get());
+        CURRENT.set(scope);
+        return scope;
+    }
+
+    public static Scope current() {
+        return CURRENT.get();
+    }
+
+    public static void bind(String androidOrderCode, Long hardId) {
+        Scope scope = CURRENT.get();
+        if (scope == null) return;
+        scope.androidOrderCode = safeIdentifier(androidOrderCode, 128, null);
+        scope.hardId = hardId;
+    }
+
+    /** Controller 参数解析及校验完成后调用，之前的时间统一计入 pre_controller。 */
+    public static void markControllerEntered() {
+        Scope scope = CURRENT.get();
+        if (scope == null || scope.controllerEntered) return;
+        scope.controllerEntered = true;
+        scope.record("pre_controller", scope.elapsedNanos(), null);
+    }
+
+    /** 只有请求最终失败时标记；阶段内被业务自行处理的异常不改变最终成功状态。 */
+    public static void markFailure(Throwable error) {
+        Scope scope = CURRENT.get();
+        if (scope == null) return;
+        scope.failed = true;
+        if (error != null) scope.errorTypes.add(errorType(error));
+    }
+
+    public static <T> T call(String stage, Supplier<T> callback) {
+        Scope scope = CURRENT.get();
+        if (scope == null || scope.finished) return callback.get();
+        long started = scope.elapsedNanos();
+        Throwable failure = null;
+        try {
+            return callback.get();
+        } catch (RuntimeException | Error error) {
+            failure = error;
+            throw error;
+        } finally {
+            scope.record(stage, scope.elapsedNanos() - started, failure);
+        }
+    }
+
+    public static void run(String stage, Runnable callback) {
+        call(stage, () -> {
+            callback.run();
+            return null;
+        });
+    }
+
+    public static final class Scope implements AutoCloseable {
+        private final long startedAtNanos;
+        private final LongSupplier clock;
+        private final Consumer<String> log;
+        private final Scope previous;
+        private final String id;
+        private final Map<String, Long> stages = new LinkedHashMap<>();
+        private final Map<String, String> stageErrors = new LinkedHashMap<>();
+        private final Set<String> errorTypes = new LinkedHashSet<>();
+        private String androidOrderCode;
+        private Long hardId;
+        private long lastElapsedNanos;
+        private boolean controllerEntered;
+        private boolean failed;
+        private boolean finished;
+        private boolean closed;
+
+        private Scope(long startedAtNanos, LongSupplier clock, Consumer<String> log, Scope previous) {
+            this.startedAtNanos = startedAtNanos;
+            this.clock = clock;
+            this.log = log;
+            this.previous = previous;
+            this.id = Long.toUnsignedString(startedAtNanos, 36) + "_" + SEQUENCE.incrementAndGet();
+        }
+
+        public String id() {
+            return id;
+        }
+
+        /** 正常快请求不落日志，慢请求、失败及含被处理异常的请求只输出一条汇总。 */
+        public void finish(int httpStatus) {
+            if (finished) return;
+            finished = true;
+            try {
+                long total = elapsedNanos();
+                boolean requestFailed = failed || httpStatus >= 400;
+                if (total < SLOW_NANOS && !requestFailed && stageErrors.isEmpty()) return;
+                String stageSummary = stages.entrySet().stream()
+                        .map(entry -> entry.getKey() + "=" + toMillis(entry.getValue()))
+                        .collect(Collectors.joining(","));
+                String stageErrorSummary = stageErrors.entrySet().stream()
+                        .map(entry -> entry.getKey() + "=" + entry.getValue())
+                        .collect(Collectors.joining(","));
+                log.accept("|终端支付耗时|trace:" + id
+                        + (androidOrderCode == null ? "" : "|androidOrderCode:" + androidOrderCode)
+                        + (hardId == null ? "" : "|hardId:" + hardId)
+                        + "|httpStatus:" + httpStatus + "|outcome:" + (requestFailed ? "failed" : "success")
+                        + "|totalMs:" + toMillis(total) + "|controllerEntered:" + controllerEntered
+                        + "|stagesInclusiveMs:" + stageSummary
+                        + "|stageErrorTypes:" + (stageErrorSummary.isEmpty() ? "-" : stageErrorSummary)
+                        + "|errorTypes:" + (errorTypes.isEmpty() ? "-" : String.join(",", errorTypes)) + "|");
+            } catch (Throwable ignored) {
+                // 诊断输出失败不能覆盖原请求结果或阻止 ThreadLocal 清理。
+            }
+        }
+
+        @Override
+        public void close() {
+            if (closed) return;
+            closed = true;
+            if (previous == null) CURRENT.remove();
+            else CURRENT.set(previous);
+        }
+
+        private long elapsedNanos() {
+            try {
+                long elapsed = clock.getAsLong() - startedAtNanos;
+                lastElapsedNanos = Math.max(lastElapsedNanos, elapsed);
+            } catch (Throwable ignored) {
+                // 测量来源故障时保留最近值，业务继续执行。
+            }
+            return lastElapsedNanos;
+        }
+
+        private void record(String stage, long durationNanos, Throwable failure) {
+            try {
+                if (finished) return;
+                String name = safeIdentifier(stage, 64, "unknown_stage");
+                stages.merge(name, Math.max(0, durationNanos), Long::sum);
+                if (failure != null) {
+                    String type = errorType(failure);
+                    stageErrors.put(name, type);
+                    errorTypes.add(type);
+                }
+            } catch (Throwable ignored) {
+                // 计时不可改变回调返回值、异常对象或业务异常传播路径。
+            }
+        }
+    }
+
+    private static long toMillis(long nanos) {
+        return nanos / 1_000_000L;
+    }
+
+    private static String errorType(Throwable error) {
+        return safeIdentifier(error.getClass().getSimpleName(), 128, "Throwable");
+    }
+
+    private static String safeIdentifier(String value, int maxLength, String fallback) {
+        return value != null && !value.isEmpty() && value.length() <= maxLength
+                && SAFE_IDENTIFIER.matcher(value).matches() ? value : fallback;
+    }
+}
@@ -54,6 +54,18 @@
 		</filter>
 	</appender>

+	<!-- 支付诊断仅写慢请求/失败摘要；队列满时丢弃诊断日志，禁止请求线程等待磁盘。 -->
+	<appender name="paymentTimingAsync" class="ch.qos.logback.classic.AsyncAppender">
+		<queueSize>256</queueSize>
+		<discardingThreshold>0</discardingThreshold>
+		<neverBlock>true</neverBlock>
+		<includeCallerData>false</includeCallerData>
+		<appender-ref ref="debug"/>
+	</appender>
+	<logger name="com.bsd.pjcloud.hard.support.PaymentTimingTrace" level="WARN" additivity="false">
+		<appender-ref ref="paymentTimingAsync"/>
+	</logger>
+
 	<logger name="org.activiti.engine.impl.db" level="DEBUG">
 		<appender-ref ref="debug"/>
 	</logger>
@@ -0,0 +1,104 @@
+package com.bsd.pjcloud.hard.config.filter;
+
+import com.bsd.pjcloud.hard.config.PaymentTimingConfiguration;
+import com.bsd.pjcloud.hard.support.PaymentTimingTrace;
+import jakarta.servlet.ServletException;
+import jakarta.servlet.ServletRequestEvent;
+import org.junit.jupiter.api.Test;
+import org.springframework.core.Ordered;
+import org.springframework.mock.web.MockHttpServletRequest;
+import org.springframework.mock.web.MockHttpServletResponse;
+import org.springframework.mock.web.MockServletContext;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.concurrent.atomic.AtomicLong;
+
+import static org.junit.jupiter.api.Assertions.*;
+import static org.mockito.Mockito.*;
+
+class CreateOrderPaymentTimingFilterTest {
+    @Test
+    void listenerTimeIncludesEarlierTenantFilterWaitAndRequestBodyIsNeverRead() throws Exception {
+        AtomicLong clock = new AtomicLong(10_000_000L);
+        List<String> logs = new ArrayList<>();
+        MockHttpServletRequest request = spy(new MockHttpServletRequest("POST", "/api" + CreateOrderPaymentTimingFilter.PATH));
+        request.setContextPath("/api");
+        var listener = new PaymentTimingConfiguration.RequestStartListener(clock::get);
+        listener.requestInitialized(new ServletRequestEvent(new MockServletContext(), request));
+        clock.set(1_210_000_000L); // 在计时过滤器之前，租户或其他过滤器已经消耗 1200ms。
+        var filter = new CreateOrderPaymentTimingFilter(start -> PaymentTimingTrace.open(start, clock::get, logs::add));
+        filter.doFilter(request, new MockHttpServletResponse(), (req, response) -> {
+            PaymentTimingTrace.markControllerEntered();
+            PaymentTimingTrace.bind("android_order", 77L);
+            PaymentTimingTrace.run("controller", () -> clock.set(1_360_000_000L));
+        });
+
+        assertEquals(1, logs.size());
+        assertTrue(logs.get(0).contains("totalMs:1350"));
+        assertTrue(logs.get(0).contains("pre_controller=1200"));
+        assertTrue(logs.get(0).contains("controller=150"));
+        assertNull(PaymentTimingTrace.current());
+        verify(request, never()).getInputStream();
+        verify(request, never()).getReader();
+    }
+
+    @Test
+    void exactPostRouteOnlyAndContextPathIsSupported() throws Exception {
+        AtomicInteger opened = new AtomicInteger();
+        var filter = new CreateOrderPaymentTimingFilter(start -> {
+            opened.incrementAndGet();
+            return PaymentTimingTrace.open(start);
+        });
+        for (String path : List.of("/other", CreateOrderPaymentTimingFilter.PATH + "/", "/hard" + CreateOrderPaymentTimingFilter.PATH)) {
+            var request = new MockHttpServletRequest("POST", path);
+            filter.doFilter(request, new MockHttpServletResponse(), (req, response) -> assertNull(PaymentTimingTrace.current()));
+        }
+        var get = new MockHttpServletRequest("GET", CreateOrderPaymentTimingFilter.PATH);
+        filter.doFilter(get, new MockHttpServletResponse(), (req, response) -> assertNull(PaymentTimingTrace.current()));
+        assertEquals(0, opened.get());
+        assertTrue(CreateOrderPaymentTimingFilter.matches(new MockHttpServletRequest("POST", CreateOrderPaymentTimingFilter.PATH)));
+    }
+
+    @Test
+    void originalServletExceptionPropagatesAndLoggingFailureCannotLeakThreadLocal() {
+        var request = new MockHttpServletRequest("POST", CreateOrderPaymentTimingFilter.PATH);
+        request.setAttribute(CreateOrderPaymentTimingFilter.STARTED_AT_ATTRIBUTE, 0L);
+        var filter = new CreateOrderPaymentTimingFilter(start -> PaymentTimingTrace.open(start, () -> 0,
+                ignored -> { throw new IllegalStateException("logger failure"); }));
+        ServletException failure = new ServletException("private-request-data");
+        ServletException caught = assertThrows(ServletException.class,
+                () -> filter.doFilter(request, new MockHttpServletResponse(), (req, response) -> { throw failure; }));
+        assertSame(failure, caught);
+        assertNull(PaymentTimingTrace.current());
+    }
+
+    @Test
+    void resolverHandledBusinessFailureStillProducesOneFailedSummary() throws Exception {
+        List<String> logs = new ArrayList<>();
+        var request = new MockHttpServletRequest("POST", CreateOrderPaymentTimingFilter.PATH);
+        request.setAttribute(CreateOrderPaymentTimingFilter.STARTED_AT_ATTRIBUTE, 0L);
+        var filter = new CreateOrderPaymentTimingFilter(start -> PaymentTimingTrace.open(start, () -> 0, logs::add));
+        filter.doFilter(request, new MockHttpServletResponse(), (req, response) -> {
+            RuntimeException failure = new RuntimeException("business-secret");
+            PaymentTimingTrace.markFailure(failure);
+            // 模拟 MVC 异常处理器已接住错误，最终仍以 HTTP 200 返回业务错误。
+        });
+        assertEquals(1, logs.size());
+        assertTrue(logs.get(0).contains("httpStatus:200|outcome:failed"));
+        assertFalse(logs.get(0).contains("business-secret"));
+        assertNull(PaymentTimingTrace.current());
+    }
+
+    @Test
+    void listenerIsSelectiveAndConfigurationPreservesExistingFilterOrder() {
+        var listener = new PaymentTimingConfiguration.RequestStartListener(() -> 42L);
+        var skipped = new MockHttpServletRequest("GET", CreateOrderPaymentTimingFilter.PATH);
+        listener.requestInitialized(new ServletRequestEvent(new MockServletContext(), skipped));
+        assertNull(skipped.getAttribute(CreateOrderPaymentTimingFilter.STARTED_AT_ATTRIBUTE));
+        var registration = new PaymentTimingConfiguration().paymentTimingFilter();
+        assertEquals(Ordered.HIGHEST_PRECEDENCE + 1, registration.getOrder());
+        assertEquals(List.of(CreateOrderPaymentTimingFilter.PATH), List.copyOf(registration.getUrlPatterns()));
+    }
+}
@@ -0,0 +1,267 @@
+package com.bsd.pjcloud.hard.service.impl.order;
+
+import cn.hutool.extra.spring.SpringUtil;
+import com.baomidou.mybatisplus.core.conditions.Wrapper;
+import com.bsd.pjcloud.admin.api.dto.UserInfo;
+import com.bsd.pjcloud.admin.api.entity.SysUser;
+import com.bsd.pjcloud.admin.api.feign.RemoteUserService;
+import com.bsd.pjcloud.common.core.constant.enums.YesNoEnum;
+import com.bsd.pjcloud.common.core.util.KeyStrResolver;
+import com.bsd.pjcloud.common.core.util.R;
+import com.bsd.pjcloud.hard.api.constant.HardTypeEnum;
+import com.bsd.pjcloud.hard.api.constant.order.HardOrderTypeEnum;
+import com.bsd.pjcloud.hard.api.constant.order.HardPayTypeEnum;
+import com.bsd.pjcloud.hard.api.dto.hard.HardCreateOrderDto;
+import com.bsd.pjcloud.hard.api.dto.order.HardCreateCarDto;
+import com.bsd.pjcloud.hard.api.entity.manager.HardManagerEntity;
+import com.bsd.pjcloud.hard.api.entity.order.HardCarEntity;
+import com.bsd.pjcloud.hard.api.entity.order.HardOrderEntity;
+import com.bsd.pjcloud.hard.mapper.order.HardOrderMapper;
+import com.bsd.pjcloud.hard.service.HardCarService;
+import com.bsd.pjcloud.hard.service.HardManagerService;
+import com.bsd.pjcloud.hard.service.order.HardOrderCartSnapshot;
+import com.bsd.pjcloud.hard.support.PaymentTimingTrace;
+import com.bsd.pjcloud.wallet.api.entity.WalletManageEntity;
+import com.bsd.pjcloud.wallet.api.entity.WalletTransactionEntity;
+import com.bsd.pjcloud.wallet.api.feign.RemoteMchService;
+import com.bsd.pjcloud.wallet.api.feign.RemoteWalletService;
+import com.bsd.pjcloud.wallet.api.feign.RemoteWalletTransactionService;
+import com.bsd.pjcloud.wallet.api.vo.MchManageVo;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.mockito.InOrder;
+import org.redisson.api.RLock;
+import org.redisson.api.RedissonClient;
+import org.springframework.context.ApplicationContext;
+import org.springframework.context.support.GenericApplicationContext;
+import org.springframework.test.util.ReflectionTestUtils;
+
+import java.math.BigDecimal;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.atomic.AtomicLong;
+import java.util.function.Supplier;
+
+import static org.junit.jupiter.api.Assertions.*;
+import static org.mockito.ArgumentMatchers.*;
+import static org.mockito.Mockito.*;
+
+/** Active timing must observe existing payment calls without repeating or reordering them. */
+class HardOrderPaymentTimingRegressionTest {
+    private HardOrderServiceImpl service;
+    private HardOrderMapper orders;
+    private HardCarService carts;
+    private HardManagerService managers;
+    private RemoteMchService merchants;
+    private RemoteUserService users;
+    private RemoteWalletService wallets;
+    private RemoteWalletTransactionService payments;
+    private RLock lock;
+    private GenericApplicationContext context;
+    private ApplicationContext previousContext;
+    private final List<String> logs = new ArrayList<>();
+
+    @BeforeEach
+    void setup() {
+        service = mock(HardOrderServiceImpl.class, CALLS_REAL_METHODS);
+        orders = mock(HardOrderMapper.class);
+        carts = mock(HardCarService.class);
+        managers = mock(HardManagerService.class);
+        merchants = mock(RemoteMchService.class);
+        users = mock(RemoteUserService.class);
+        wallets = mock(RemoteWalletService.class);
+        payments = mock(RemoteWalletTransactionService.class);
+        RedissonClient redis = mock(RedissonClient.class);
+        KeyStrResolver keys = mock(KeyStrResolver.class);
+        lock = mock(RLock.class);
+        when(keys.extract(anyString(), eq(":"))).thenAnswer(call -> call.getArgument(0));
+        when(redis.getLock(anyString())).thenReturn(lock);
+        when(lock.tryLock()).thenReturn(true);
+        when(lock.isHeldByCurrentThread()).thenReturn(true);
+        ReflectionTestUtils.setField(service, "baseMapper", orders);
+        ReflectionTestUtils.setField(service, "hardCarService", carts);
+        ReflectionTestUtils.setField(service, "hardManagerService", managers);
+        ReflectionTestUtils.setField(service, "remoteMchService", merchants);
+        ReflectionTestUtils.setField(service, "userService", users);
+        ReflectionTestUtils.setField(service, "remoteWalletService", wallets);
+        ReflectionTestUtils.setField(service, "walletTransactionService", payments);
+        ReflectionTestUtils.setField(service, "redissonClient", redis);
+        ReflectionTestUtils.setField(service, "keyStrResolver", keys);
+        // Only resolve the existing getSelf() lookup; no Boot, transaction or remote connection starts.
+        previousContext = SpringUtil.getApplicationContext();
+        context = new GenericApplicationContext();
+        context.registerBean("paymentTimingTestOrderService", HardOrderServiceImpl.class, () -> service);
+        context.refresh();
+        new SpringUtil().setApplicationContext(context);
+        doNothing().when(service).fastenerInventory(any(), any(YesNoEnum.class));
+        doNothing().when(service).orderSuccess(any(), anyBoolean());
+        doNothing().when(service).cancelCode(any(), any());
+        doNothing().when(service).createOrderAfterSendMqMsg(anyLong(), any());
+    }
+
+    @AfterEach
+    void cleanup() {
+        new SpringUtil().setApplicationContext(previousContext);
+        context.close();
+        assertNull(PaymentTimingTrace.current());
+    }
+
+    @Test
+    void busyLockKeepsRejectionWithoutLookupPaymentOrUnlock() {
+        when(lock.tryLock()).thenReturn(false);
+
+        RuntimeException failure = assertThrows(RuntimeException.class,
+                () -> observed(() -> service.createOrder(request())));
+
+        assertEquals("正在创建订单中，请勿重复操作", failure.getMessage());
+        verify(lock).tryLock();
+        verifyNoMoreInteractions(lock);
+        verifyZeroInteractions(orders, carts, managers, merchants, users, wallets, payments);
+        verify(service, never()).createOrderInTransaction(any(), any());
+        assertTrue(logs.get(0).contains("outcome:failed"));
+    }
+
+    @Test
+    void paidOrderReuseKeepsOneLocalLookupAndNoRemoteOrPaymentCalls() {
+        HardOrderEntity paid = HardOrderEntity.builder().id(100L).parentCarId(10L)
+                .hardId(3L).merchantId(2L).sysType(HardTypeEnum.CANTEEN.getType())
+                .hourType("1").orderType(HardOrderTypeEnum.BELOW.getType())
+                .payType(HardPayTypeEnum.FACE.getType()).userId(4L)
+                .extraPrice(0).orderStatus("5").build();
+        when(orders.selectOne(any(Wrapper.class))).thenReturn(paid);
+        when(carts.getByParentCarId(10L)).thenReturn(snapshot().items());
+
+        assertEquals(100L, observed(() -> service.createOrder(request())));
+
+        InOrder calls = inOrder(lock, orders, carts);
+        calls.verify(lock).tryLock();
+        calls.verify(orders).selectOne(any(Wrapper.class));
+        calls.verify(carts).getByParentCarId(10L);
+        calls.verify(lock).isHeldByCurrentThread();
+        calls.verify(lock).unlock();
+        calls.verifyNoMoreInteractions();
+        verifyZeroInteractions(managers, merchants, users, wallets, payments);
+        verify(service, never()).createOrderInTransaction(any(), any());
+        verify(service, never()).createOrderAfterSendMqMsg(anyLong(), any());
+    }
+
+    @Test
+    void lookupFailurePropagatesSameExceptionAndStillReleasesHeldLock() {
+        RuntimeException databaseFailure = new RuntimeException("database unavailable");
+        when(orders.selectOne(any(Wrapper.class))).thenThrow(databaseFailure);
+
+        assertSame(databaseFailure, assertThrows(RuntimeException.class,
+                () -> observed(() -> service.createOrder(request()))));
+
+        InOrder calls = inOrder(lock, orders);
+        calls.verify(lock).tryLock();
+        calls.verify(orders).selectOne(any(Wrapper.class));
+        calls.verify(lock).isHeldByCurrentThread();
+        calls.verify(lock).unlock();
+        calls.verifyNoMoreInteractions();
+        verifyZeroInteractions(carts, managers, merchants, users, wallets, payments);
+        verify(service, never()).createOrderInTransaction(any(), any());
+        verify(service, never()).createOrderAfterSendMqMsg(anyLong(), any());
+        assertFalse(logs.get(0).contains("database unavailable"));
+    }
+
+    @Test
+    void successKeepsPreparationWriteDebitUnlockAndNotificationOrder() {
+        stubPreparedOrder();
+        when(orders.insert(any(HardOrderEntity.class))).thenAnswer(call -> {
+            assertTrue(logs.isEmpty(), "timing must not write logs inside order persistence");
+            call.<HardOrderEntity>getArgument(0).setId(100L);
+            return 1;
+        });
+        when(payments.reduceWalletBalance(any())).thenAnswer(call -> {
+            assertTrue(logs.isEmpty(), "timing must not write logs inside wallet debit");
+            return R.ok(new WalletTransactionEntity());
+        });
+
+        assertEquals(100L, observed(() -> service.createOrder(request())));
+
+        InOrder calls = inOrder(lock, orders, merchants, managers, users, wallets, carts, payments, service);
+        calls.verify(lock).tryLock();
+        calls.verify(orders).selectOne(any(Wrapper.class));
+        calls.verify(merchants).getById(2L);
+        calls.verify(managers).getById(3L);
+        calls.verify(users).getInnerByUserId(4L);
+        calls.verify(wallets).getWallet(eq(4L), any());
+        calls.verify(carts).prepareCardWithCompute(any(), any(), anyList());
+        calls.verify(service).createOrderInTransaction(any(), any());
+        calls.verify(carts).createCardFromSnapshot(any(), any(), any(), any());
+        calls.verify(orders).insert(any(HardOrderEntity.class));
+        calls.verify(service).fastenerInventory(any(), eq(YesNoEnum.YES));
+        calls.verify(payments).reduceWalletBalance(argThat(dto ->
+                Boolean.FALSE.equals(dto.getForce()) && dto.getPrice() == 350));
+        calls.verify(service).orderSuccess(any(), eq(true));
+        calls.verify(service).cancelCode(any(), any());
+        calls.verify(lock).isHeldByCurrentThread();
+        calls.verify(lock).unlock();
+        calls.verify(service).createOrderAfterSendMqMsg(eq(100L), any());
+        // Ignore service entry/private internal calls, but prohibit extra database or remote calls.
+        verifyNoMoreInteractions(orders, merchants, managers, users, wallets, carts, payments, lock);
+        verify(service, times(1)).createOrderInTransaction(any(), any());
+        verify(service, times(1)).orderSuccess(any(), anyBoolean());
+        verify(service, times(1)).createOrderAfterSendMqMsg(anyLong(), any());
+        assertTrue(logs.get(0).contains("outcome:success"));
+    }
+
+    private void stubPreparedOrder() {
+        MchManageVo merchant = new MchManageVo();
+        merchant.setId(2L);
+        when(merchants.getById(2L)).thenReturn(R.ok(merchant));
+        when(managers.getById(3L)).thenReturn(new HardManagerEntity());
+        SysUser user = new SysUser();
+        user.setUserId(4L);
+        UserInfo info = new UserInfo();
+        info.setSysUser(user);
+        when(users.getInnerByUserId(4L)).thenReturn(R.ok(info));
+        WalletManageEntity wallet = new WalletManageEntity();
+        wallet.setId(5L);
+        wallet.setUserId(4L);
+        wallet.setBalance(500);
+        when(wallets.getWallet(eq(4L), any())).thenReturn(R.ok(wallet));
+        when(carts.prepareCardWithCompute(any(), any(), anyList())).thenReturn(snapshot());
+        when(carts.createCardFromSnapshot(any(), any(), any(), any())).thenReturn(10L);
+    }
+
+    private <T> T observed(Supplier<T> action) {
+        AtomicLong clock = new AtomicLong();
+        try (PaymentTimingTrace.Scope scope = PaymentTimingTrace.open(0, clock::get, logs::add)) {
+            PaymentTimingTrace.bind("legacy-code", 3L);
+            PaymentTimingTrace.markControllerEntered();
+            int status = 200;
+            try {
+                T result = action.get();
+                assertTrue(logs.isEmpty(), "stages must buffer until the request is complete");
+                return result;
+            } catch (RuntimeException | Error failure) {
+                status = 500;
+                PaymentTimingTrace.markFailure(failure);
+                throw failure;
+            } finally {
+                clock.set(2_000_000_000L);
+                scope.finish(status);
+                assertEquals(1, logs.size());
+            }
+        }
+    }
+
+    private HardCreateOrderDto request() {
+        HardCreateCarDto item = new HardCreateCarDto();
+        item.setProductId(6L);
+        item.setProductCount(1);
+        item.setProductWeight(BigDecimal.ZERO);
+        return HardCreateOrderDto.builder().androidOrderCode("legacy-code").hardwareId(3L).merchantId(2L)
+                .sysType(HardTypeEnum.CANTEEN).hourType(1).userId(4L).orderType(HardOrderTypeEnum.BELOW)
+                .orderPayType(HardPayTypeEnum.FACE).list(List.of(item)).build();
+    }
+
+    private HardOrderCartSnapshot snapshot() {
+        HardCarEntity item = HardCarEntity.builder().productId(6L).productCount(1).productWeight(BigDecimal.ZERO)
+                .productPrice(350).totalPrice(350L).isDiscountsProduct(YesNoEnum.NO.getCode()).build();
+        return new HardOrderCartSnapshot(350, "饭菜x1;", List.of(item));
+    }
+}
@@ -0,0 +1,132 @@
+package com.bsd.pjcloud.hard.support;
+
+import org.junit.jupiter.api.Test;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicLong;
+
+import static org.junit.jupiter.api.Assertions.*;
+
+class PaymentTimingTraceTest {
+    @Test
+    void fastSuccessfulRequestDoesNotLogAndAlwaysClearsThreadLocal() {
+        AtomicLong clock = new AtomicLong();
+        List<String> logs = new ArrayList<>();
+        try (PaymentTimingTrace.Scope scope = PaymentTimingTrace.open(0, clock::get, logs::add)) {
+            assertSame(scope, PaymentTimingTrace.current());
+            assertEquals(7, PaymentTimingTrace.call("local_sql", () -> {
+                clock.set(20_000_000L);
+                return 7;
+            }));
+            scope.finish(200);
+            scope.finish(500);
+        }
+        assertTrue(logs.isEmpty());
+        assertNull(PaymentTimingTrace.current());
+        assertEquals(9, PaymentTimingTrace.call("inactive", () -> 9));
+    }
+
+    @Test
+    void summaryIncludesPreControllerAndInclusiveNestedStagesOnce() {
+        AtomicLong clock = new AtomicLong();
+        List<String> logs = new ArrayList<>();
+        try (PaymentTimingTrace.Scope scope = PaymentTimingTrace.open(0, clock::get, logs::add)) {
+            PaymentTimingTrace.bind("android_123_456", 123L);
+            clock.set(1_200_000_000L);
+            PaymentTimingTrace.markControllerEntered();
+            PaymentTimingTrace.markControllerEntered();
+            PaymentTimingTrace.run("controller", () -> {
+                clock.set(1_300_000_000L);
+                PaymentTimingTrace.run("wallet_remote", () -> clock.set(1_500_000_000L));
+                clock.set(1_600_000_000L);
+            });
+            scope.finish(200);
+            scope.finish(200);
+        }
+        assertEquals(1, logs.size());
+        String summary = logs.get(0);
+        assertTrue(summary.contains("androidOrderCode:android_123_456|hardId:123"));
+        assertTrue(summary.contains("outcome:success|totalMs:1600|controllerEntered:true"));
+        assertTrue(summary.contains("pre_controller=1200"));
+        assertTrue(summary.contains("controller=400"));
+        assertTrue(summary.contains("wallet_remote=200"));
+    }
+
+    @Test
+    void handledStageErrorDoesNotReclassifySuccessfulPaymentOrExposePayload() {
+        AtomicLong clock = new AtomicLong();
+        List<String> logs = new ArrayList<>();
+        IllegalStateException failure = new IllegalStateException("secret-token-and-user-body");
+        try (PaymentTimingTrace.Scope scope = PaymentTimingTrace.open(0, clock::get, logs::add)) {
+            IllegalStateException caught = assertThrows(IllegalStateException.class,
+                    () -> PaymentTimingTrace.run("notify", () -> { throw failure; }));
+            assertSame(failure, caught);
+            scope.finish(200);
+        }
+        assertEquals(1, logs.size());
+        assertTrue(logs.get(0).contains("outcome:success"));
+        assertTrue(logs.get(0).contains("stageErrorTypes:notify=IllegalStateException"));
+        assertFalse(logs.get(0).contains("secret"));
+    }
+
+    @Test
+    void explicitBusinessFailureIsLoggedEvenWhenExceptionResolverReturnsHttp200() {
+        List<String> logs = new ArrayList<>();
+        try (PaymentTimingTrace.Scope scope = PaymentTimingTrace.open(0, () -> 0, logs::add)) {
+            PaymentTimingTrace.bind("unsafe|payload=secret", 123L);
+            PaymentTimingTrace.markFailure(new IllegalArgumentException("secret"));
+            scope.finish(200);
+        }
+        assertEquals(1, logs.size());
+        assertTrue(logs.get(0).contains("httpStatus:200|outcome:failed"));
+        assertTrue(logs.get(0).contains("errorTypes:IllegalArgumentException"));
+        assertFalse(logs.get(0).contains("androidOrderCode"));
+        assertFalse(logs.get(0).contains("secret"));
+    }
+
+    @Test
+    void sinkAndClockFailuresDoNotReplaceResultAndNestedScopeRestoresPreviousTrace() {
+        try (PaymentTimingTrace.Scope outer = PaymentTimingTrace.open(0, () -> 0, ignored -> {})) {
+            try (PaymentTimingTrace.Scope inner = PaymentTimingTrace.open(0,
+                    () -> { throw new IllegalStateException("clock"); },
+                    ignored -> { throw new IllegalStateException("sink"); })) {
+                assertEquals(8, PaymentTimingTrace.call("paid", () -> 8));
+                assertDoesNotThrow(() -> inner.finish(500));
+            }
+            assertSame(outer, PaymentTimingTrace.current());
+        }
+        assertNull(PaymentTimingTrace.current());
+    }
+
+    @Test
+    void concurrentRequestsKeepSeparateThreadLocals() throws Exception {
+        var executor = Executors.newFixedThreadPool(2);
+        CountDownLatch opened = new CountDownLatch(2);
+        try {
+            var first = executor.submit(() -> isolatedRequest("first_order", opened));
+            var second = executor.submit(() -> isolatedRequest("second_order", opened));
+            assertTrue(first.get(5, TimeUnit.SECONDS).contains("androidOrderCode:first_order"));
+            assertTrue(second.get(5, TimeUnit.SECONDS).contains("androidOrderCode:second_order"));
+            assertNull(PaymentTimingTrace.current());
+        } finally {
+            executor.shutdownNow();
+        }
+    }
+
+    private String isolatedRequest(String order, CountDownLatch opened) throws InterruptedException {
+        List<String> logs = new ArrayList<>();
+        try (PaymentTimingTrace.Scope scope = PaymentTimingTrace.open(0, () -> 0, logs::add)) {
+            PaymentTimingTrace.bind(order, 123L);
+            opened.countDown();
+            assertTrue(opened.await(5, TimeUnit.SECONDS));
+            assertSame(scope, PaymentTimingTrace.current());
+            scope.finish(500);
+        }
+        assertNull(PaymentTimingTrace.current());
+        return logs.get(0);
+    }
+}