flaky/possible mask race: streaming SLS full-capture intermittently contains raw PII on CI (sls-content-capture-masked-e2e)

[jarvis9443]

CI run https://github.com/api7/aisix/actions/runs/30912950213 (PR #886, commit b07ccda) failed sls-content-capture-masked-e2e.test.ts > full-capture exporter receives the masked stream text, never the raw PII:

AssertionError: expected '\n<binary>...' not to contain 'alice@example.com'

Evidence this is not the PR's doing and not (only) a test-decode flake:

• The PR's diff (main...b07ccda) touches the quota gate, policy loader, and error envelope — nothing on the guardrail/mask/capture/exporter path; the identical test passed on the same PR's previous commit ae14c0a ~40 min earlier, the last 15 main CI runs are green, and 4 consecutive local runs of the spec pass.
• The interesting part is what failed: fullText is the lz4-block-decompressed PutLogs payload (sls-mock.ts decompresses with the x-log-bodyrawsize size before asserting). lz4 decompression can only reproduce byte runs present in the source literals, so an intact alice@example.com in the decompressed text means that one captured payload actually carried the raw, pre-mask email on the wire. The replacement-char noise around it is just protobuf field bytes rendered as UTF-8 — present in green runs too.

So under CI load this looks like a timing window where a streaming capture chunk is exported before the mask pass rewrites it — the exact class #932 x AISIX-Cloud#947 addressed, surviving in some scheduling interleaving that a loaded 2-vCPU runner hits and a dev machine doesn't. I couldn't reproduce locally (including repeated runs), so I'm filing the evidence instead of guessing at a fix.

Worth ruling out first: whether the mock's hand-rolled lz4DecompressBlock can mis-decode a multi-request capture (each request decompressed independently — a wrong rawSize on one request would corrupt that segment, though it still couldn't fabricate the email bytes out of nothing).

Happy to dig further if someone can hand me a second failing run's raw payload; PR #886 is unblocked via re-run in the meantime.

[coderabbitai]

🔗 Related PRs

#781 - feat(guardrails): preserve Aliyun's upstream RequestId and correlate it to the gateway request [merged]
#785 - feat(metrics): extend client_type coverage and add operator UA mapping rules [merged]
#797 - test(e2e): fix propagation race in status-config resource-count asserts [merged]
#804 - fix(anthropic): preserve client cache_control through the OpenAI-to-Anthropic bridge [merged]
#815 - fix(guardrails): scan the union of content and content_blocks [merged]

---

📝 Issue Planner

_{Check the box below or use the @coderabbitai plan command to generate an implementation plan and prompts that you can use with your favorite coding assistant.}

• Create Plan

---

🧪 Issue enrichment is currently in open beta.

You can configure auto-planning by selecting labels in the issue_enrichment configuration.

To disable automatic issue enrichment, add the following to your .coderabbit.yaml:

issue_enrichment:
  auto_enrich:
    enabled: false

💬 Have feedback or questions? Drop into our discord!

[jarvis9443]

Resolved by #890 (merged). My mask-race hypothesis above was wrong — there is no product bug here, the assertion population was.

waitConfigPropagation drives warm-up chats until the masked form shows up on the wire, and those warm-up requests get exported to SLS too. The ones served before the guardrail went live carry the unmasked reply, which is correct behaviour for a gateway that has no masking rule yet. decodedTextFor joined every PutLogs body the mock had ever received, so not.toContain(EMAIL) was also asserting over those pre-propagation exports. On a fast machine the guardrail is live by the first warm-up and nothing unmasked is ever exported; on a loaded runner it isn't. #890 snapshots sls.requests.length once the config is confirmed live and scopes the assertions to what shipped after it.

That also answers the lz4 question I raised — the decoder is fine. The email is deliberately split across two SSE deltas, so the wire never carries it whole and only the assembled capture does; an intact address in the decompressed payload therefore just means some request's capture legitimately carried it. It did: a pre-guardrail one.

I forced the window deterministically to confirm it rather than waiting for another CI hit — seed the model, wait until it serves, send one request, and only then seed the guardrail:

[probe889] boundary=2 unscopedHasEmail=true unscopedHasPreToken=true
           scopedHasEmail=false scopedHasPostToken=true

The raw address is present in the unscoped population and traceable to the pre-guardrail request's own token; with #890's boundary it is gone, and the scope still contains what the spec is there to assert. The masked spec is green 3/3 locally on current main.

On the product side there is no window to race even in principle: on the hold-back path redact_chat_chunks (wire) and redact_captured_output (capture accumulator) run in the same synchronous block in chat.rs, and CapturedContent is built once in the stream's on_complete from comp.response_text — the capture is never exported per chunk. #890's drain-marker premise holds too: SinkPipeline::run is a single worker that awaits each flush inline, so PutLogs bodies are strictly ordered per exporter.

Checked the other six SLS specs for the same shape while I was in here — none are exposed. Their forbidden strings are unique planted tokens that warm-up traffic never produces. This spec was the only one where the upstream returns the PII on every request and whether it is masked depends on the guardrail being live, which is exactly what made it the one that flaked.