一次请求的响应期限设为 50 ms,最终返回 504;响应流随后终止,安排在 500 ms 的合成后台完成回调仍然执行。另一次请求先得到 200,客户端读取 16 KiB 后关闭真实 TCP 连接;服务端只生产了 3 块、共 49152 字节,流的完成回调却没有异常。

这两个结果要求指标说明观察位置。Result 可用、响应流终止、后台工作完成、客户端收全,都不能用同一个“请求成功”计数代替。

每个事件对应哪一步

Play 3.0.6 的固定源码提交为 2e56aff7d4e7a74af61e4bd39ec9e3ed7f300cd6。Java Filter.apply 接收一个从 RequestHeader 到 CompletionStage 的函数。这个 Stage 提供 Result;Result 内部的 body 还可以包含尚未完全运行的 Source。

实验的 ObservationFilter 在调用 next 前记录 request_started,在 Stage 产生 Result 后记录 result_ready,再包装 body 的字节流,用 watchTermination 记录 stream_terminal。Controller 在业务判断或有限后台工作结束处记录 business_result。过滤器只覆盖 /gov/observe/ 路径,观察接口自身不继续制造观察事件。

事件 触发位置 没有证明的事项
request_started 观测 Filter 接到请求 parser 成功、认证成功
result_ready next 的 Stage 产生 Result body 发送完成
stream_terminal 响应 body 的运行终止 客户端收到并处理全部字节
business_result 合成业务判断或工作终态 数据库提交、外部系统接收遥测

请求、流和业务结果的分阶段观察

1
2
3
4
普通决策:  request_started → business_result → result_ready → stream_terminal
解析失败: request_started ──────────────────→ result_ready → stream_terminal
超时工作: request_started ──────────────────→ result_ready → stream_terminal
后台工作继续 ───────────────────→ business_result

解析失败通常没有进入业务 Controller,因此没有 business_result。超时结果可以先于后台终态。若要求所有请求都必须出现同一顺序的四条日志,告警就会把正常的拒绝路径当成采集缺失,或者迫使代码伪造一次没有发生的业务完成。

包装响应 body 时保存什么

app/observabilitylab/ObservationFilter.java 将原实体的 dataStream 接上终止观察,再构造 Streamed 实体,并保留内容长度、类型、状态、响应头、session、flash、cookies 和 attributes。这种转换在实验中简化了统一观察,但可能改变原 Chunked 实体的表达方式;不能不加验证地套用到所有响应、SSE 或 WebSocket。

HttpEntity.Streamed 的 Java 实现 分别保存 Source、可选长度和类型。下面的完整示例只展示实体层观察,JDK 21 与累计工程依赖下已编译。业务系统需要决定在哪个具体响应类型上使用它,而不是将它视作完整通用日志 Filter。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
import java.util.Optional;
import java.util.function.Consumer;
import org.apache.pekko.stream.javadsl.Source;
import org.apache.pekko.util.ByteString;
import play.http.HttpEntity;

public final class ObservedBody {
private ObservedBody() {}

public static HttpEntity create(
Source<ByteString, ?> source,
Optional<Long> contentLength,
String contentType,
Consumer<String> terminal) {
Source<ByteString, ?> observed = source.watchTermination((materialized, done) -> {
done.whenComplete((value, failure) -> terminal.accept(
failure == null ? "completed_or_cancelled" : "failed"));
return materialized;
});
return new HttpEntity.Streamed(observed, contentLength, Optional.of(contentType));
}
}

Pekko Streams 1.0.3 固定提交为 4f77c8108aaf548a65531d2c8807da13dbba8146。Java DSL watchTermination 暴露的是该流的终止 Stage。实验因此使用 completed_or_cancelled 作为无异常终态名称,保留它不能区分完整消费和下游取消的事实。

真实取消场景的 Source 上限是 2048 块,每块 16384 字节,总计 32 MiB。客户端读一块后关闭连接,最终产生计数为 3,stream_terminal 为 completed_or_cancelled。源端生产 49152 字节也不等于客户端读取了这些字节,差额可能停留在服务器与内核缓冲中。

把该回调命名为 response_delivered 并计为“下载成功”,是可直接构造的反例。脚本已经关闭客户端且远未读满,回调仍会发生。需要对端完成语义时,应单独设计应用回执、字节数或内容校验,而不是修改指标名称。

请求 ID 与指标标签使用不同容量模型

实验账本最多保留 128 个请求 ID,每个 ID 最多 12 条阶段事件;满额时淘汰最早记录,并累计 evictions。它允许诊断历史丢失,包括尚未结束的活动记录,因此不具有持久审计语义。单元测试插入 300 个不同 ID,断言保留 128 条、淘汰 172 条。

请求 ID 限制为 1–48 个安全 ASCII 字符,缺失或格式不合格时生成 UUID。ID 用于账本与日志关联,不写入 metrics 标签。指标只有代码内部给定的 phase:outcome 组合,最终样本为九个组合;没有按 URL、用户名、对象 id 或异常全文拆分序列。

1
2
3
诊断记录: request-id → 最多12条事件 → 最多128个ID → 显式计数淘汰
指标聚合: 固定phase + 固定outcome → 累加计数
日志输出: request-id + phase + outcome,不记录Cookie、token或body

低基数不能只靠把 label 变量命名成 category。如果 category 直接来自路径或用户输入,仍然会随请求增长。本实验的 outcome 在代码中枚举,外部 X-Gov-Id 只进入受限记录和结构化日志。原始敏感正文不参与事件格式化。

有界 Map 也不能代替有界业务工作。/gov/observe/timeout 单独用 16 个 permit 限制尚未完成的合成任务。50 ms 的响应期限到达时不释放 permit;直到安排在 500 ms 的合成完成回调才归还。这个回调表示有限任务的终态,并未模拟持续消耗 500 ms CPU 的业务计算。若在发送 504 时归还,就会低估尚未终止的已接受任务数量。

并发、解析失败、超时和容量拒绝

网络脚本以四个客户端线程提交 12 次金额判断,输入重复覆盖 1、100、0、101。每个请求都在 default.log 中匹配到四个阶段,共 48 条关联日志。允许的金额返回 200,被拒绝的金额返回 400;business_result 分别为 accepted、rejected。

JSON 解析失败请求返回 400,记录 request_started、result_ready:error 和 stream_terminal,没有 business_result。输入错误在 parser 层结束,业务层没有发生一次“拒绝金额”的判断,两种 400 因此具有不同事件形状。

单次 timeout 的记录顺序为 request_started、result_ready:error、stream_terminal、business_result:completed_after_deadline。它说明响应期限没有自动停止后台工作。业务结果名称还需限定在本实验的合成任务,不能将这个事件解释成真实数据库提交。

过载场景用八个并发客户端发出 32 次 timeout 请求,实测 16 个 504、16 个 503。所有接受的后台工作结束后,16 个 permit 全部归还。容量拒绝在业务事件中标为 capacity_rejected,与已经接受工作后才超时的路径区分。

场景 result_ready business_result 必须继续观察的终态
合法金额 success accepted 响应流
非法金额 error rejected 响应流
非法 JSON error 不发生 parser 返回的错误实体
响应期限到达 error 稍后 completed_after_deadline 有限后台工作与 permit
容量已满 error capacity_rejected 无新增后台任务
客户端 TCP 关闭 success 已发生 accepted 已发生 源生产计数与流终态

日志配置本身也需要证据

内存账本有事件,不意味着日志已经输出。一次中间运行中,完整 HTTP 矩阵通过,但默认生产 logger 没有输出 observabilitylab 的 INFO 事件;48 条关联日志验收失败。专项 governance-logback.xml 显式启用该包 INFO 后,日志匹配才通过。

最终脚本在三个进程退出后检查日志:随机运行密钥和敏感正文哨兵均不存在。该检查只覆盖本地收集的日志和字面量,没有验证远端日志平台收到记录,也没有验证落盘持久性或采集失败后的补偿。异步遥测队列若另行加入,还需要自己的容量、丢弃计数和关闭期限。

累计源码入口见第00篇。JDK 21 环境下,在 play-lab 执行:

1
2
bash sbtw clean test stage
python3 lab/governance_checks.py --evidence evidence/batch26-29/replay

历史观测为 evidence/batch26-29/isolated/run-final3/observations.json 的 observations、boundedTimerWork、logCorrelation 节点;default.log 保留关联日志。隔离批次 37 项 JUnit 与 stage 通过,三个自建服务进程最后均为 exit 143,脚本中的关闭发生在收集终态之后。父工程后续集成测试数量不由这个历史记录推断。

共享工程另外执行49个不同JUnit方法并完成stage,五个治理class与生产jar字节一致。evidence/batch26-29/shared-http/observations.json 记录本次32请求中16个504、16个503、最终16个permit归还;12个关联请求的四个阶段匹配48条日志。TCP取消时读取16384字节、源生产49152字节,仍记录 completed_or_cancelled;这些值属于本次有限输入,未变成完整接收或数据库提交的证明。

改动练习:将 timeout permit 的释放移动到 50 ms 响应期限,保持合成终态回调延迟 500 ms,增加一项“响应超时后仍运行多少任务”的计数。比较达到相同请求速率时,已接受任务数是否超出 16,再恢复终态释放。

另一个练习将账本容量改为四并发出 12 个请求。断言淘汰计数增长,同时确认指标标签仍是固定集合。这样可以分别检查诊断留存损失与指标序列数量,而不是把两者混成一个“日志太多”的问题。

上一篇:Web安全与信任边界。下一篇:分层测试与证据。