fix: allowログの決定論的サンプリングを実装 (#259)

* feat(observability): apply deterministic allow sampling

* ci(dependabot): defer incompatible toolchain majors

* refactor(observability): improve sampling hash distribution

Author: albert-einshutoin

.github/dependabot.yml

@@ -27,3 +27,10 @@ updates:
     groups:
       dev-dependencies:
         dependency-type: "development"
+    # c8 12 requires Node >=20.19 while this package supports >=20.17.
+    # TypeScript 7 removes compiler options still required by this project.
+    ignore:
+      - dependency-name: "c8"
+        versions: [">=12.0.0"]
+      - dependency-name: "typescript"
+        versions: [">=7.0.0"]

docs/observability.ja.md

@@ -15,13 +15,13 @@
 
 ## 構造化 JSON ログ（生成ランタイム）
 
-`observability.log_format: json`（既定）を指定すると、生成された viewer-request / origin-request / Cloudflare Worker は判定 1 件につき 1 行の JSON を `console.log` に出力します。フィールド:
+`observability.log_format: json`（既定）を指定すると、生成された viewer-request / origin-request / Cloudflare Worker は拒否・monitor・audit・error の判定を `console.log` に出力します。許可リクエストは `observability.sample_rate` に従って出力します。フィールド:
 
 | フィールド | 説明 | 例 |
 |------------|------|-----|
-| `ts` | ISO-8601 タイムスタンプ | `2026-04-23T12:34:56.789Z` |
-| `level` | block/monitor/audit は `info`、実行エラーは `error` | `info` |
-| `event` | `block` / `monitor`（monitor モード）/ `audit` / `error` | `block` |
+| `ts` | Unix タイムスタンプ（ミリ秒） | `1776947696789` |
+| `level` | block は `warn`、allow/monitor/audit は `info`。実行エラーは出力元により `info` または `error` | `warn` |
+| `event` | `allow` / `block` / `monitor`（monitor モード）/ `audit` / `error` | `block` |
 | `status` | 返した HTTP ステータス | `405` |
 | `block_reason` | ブロック理由（下表参照） | `method_not_allowed` |
 | `method` | リクエストメソッド | `POST` |
@@ -40,7 +40,7 @@
 ブロックイベント例:
 
 ```json
-{"ts":"2026-04-23T12:34:56.789Z","level":"info","event":"block","status":405,"block_reason":"method_not_allowed","method":"POST","uri":"/anything","correlation_id":"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}
+{"ts":1776947696789,"level":"warn","event":"block","status":405,"block_reason":"method_not_allowed","method":"POST","uri":"/anything","correlation_id":"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}
 ```
 
 ### ポリシー
@@ -49,7 +49,7 @@
 observability:
   log_format: "json"               # "json"（既定）または "text"
   correlation_id_header: "traceparent"  # もしくは "x-request-id"
-  sample_rate: 1                   # 0..1（現状は advisory — block/audit は常時出力）
+  sample_rate: 1                   # 0..1（許可リクエストを抽出。block/audit は常時出力）
   audit_log_auth: true             # 認証ゲート成功時に audit イベントを出す
   audit_hash_sub: true             # sub を SHA-256 先頭 16 hex にハッシュ（PII 対策）
 ```
@@ -58,6 +58,8 @@ observability:
 
 Lambda@Edge / Worker は受信リクエストに `correlation_id_header` が無いとき自動採番（`crypto.randomUUID` / `crypto.getRandomValues`）して origin への転送ヘッダに付与します。これにより Edge / WAF / Origin のログを同一 ID で串刺しできます。
 
+allow のサンプリング判定は決定論的です。受信時の相関 ID があればそれを使い、無ければリクエストメソッドと URI パスを使います。Lambda@Edge / Worker は相関 ID の自動採番前にこのキーを確定するため、同じ method/path の再試行は同じサンプルバケットに入ります。`sample_rate: 0` は allow ログを無効化し、`1` はすべての許可リクエストを記録します。block / monitor / audit / error はサンプリングしません。
+
 ---
 
 ## ブロック理由の対応表

docs/observability.md

@@ -15,13 +15,13 @@ This document describes recommended **logging and metrics** for the Edge Securit
 
 ## Structured JSON Logs (generated runtime)
 
-When `observability.log_format: json` is set (default), the generated viewer-request / origin-request / Cloudflare Worker emit one JSON line per decision to `console.log`. Fields:
+When `observability.log_format: json` is set (default), the generated viewer-request / origin-request / Cloudflare Worker emit denied, monitor, audit, and error decisions to `console.log`. Allowed requests are emitted according to `observability.sample_rate`. Fields:
 
 | Field | Description | Example |
 |-------|-------------|---------|
-| `ts` | ISO-8601 timestamp | `2026-04-23T12:34:56.789Z` |
-| `level` | `info` on block/monitor/audit, `error` on runtime error | `info` |
-| `event` | `block`, `monitor` (monitor mode), `audit`, `error` | `block` |
+| `ts` | Unix timestamp in milliseconds | `1776947696789` |
+| `level` | `warn` on block; `info` on allow/monitor/audit; runtime errors use `info` or `error` depending on the emitter | `warn` |
+| `event` | `allow`, `block`, `monitor` (monitor mode), `audit`, `error` | `block` |
 | `status` | HTTP status returned | `405` |
 | `block_reason` | Why the request was blocked (see mapping below) | `method_not_allowed` |
 | `method` | Request method | `POST` |
@@ -40,7 +40,7 @@ Audit events (`audit_log_auth: true`) add:
 Example block event:
 
 ```json
-{"ts":"2026-04-23T12:34:56.789Z","level":"info","event":"block","status":405,"block_reason":"method_not_allowed","method":"POST","uri":"/anything","correlation_id":"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}
+{"ts":1776947696789,"level":"warn","event":"block","status":405,"block_reason":"method_not_allowed","method":"POST","uri":"/anything","correlation_id":"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"}
 ```
 
 ### Policy
@@ -49,7 +49,7 @@ Example block event:
 observability:
   log_format: "json"               # "json" (default) or "text"
   correlation_id_header: "traceparent"  # or "x-request-id"
-  sample_rate: 1                   # 0..1; currently advisory (block/audit always emit)
+  sample_rate: 1                   # 0..1; sample allowed requests (block/audit always emit)
   audit_log_auth: true             # emit audit events on auth gate success
   audit_hash_sub: true             # SHA-256 truncate sub to 16 hex (PII-safe)
 ```
@@ -58,6 +58,8 @@ observability:
 
 At Lambda@Edge / Worker, if the incoming request does **not** carry `correlation_id_header`, the runtime mints one (`crypto.randomUUID` / `crypto.getRandomValues`) and sets it on the forwarded request. Downstream services then see a consistent ID across edge logs, WAF logs, and origin logs.
 
+Allow sampling is deterministic. The runtime uses the incoming correlation ID when present, otherwise it uses the request method and URI path. Lambda@Edge and Workers capture that key before minting a missing correlation ID, so retries for the same method/path remain in the same sample bucket. `sample_rate: 0` disables allow logs; `1` emits every allowed request. Block, monitor, audit, and error logs are never sampled.
+
 ---
 
 ## Block Reason Mapping

src/scripts/cloudflare-runtime-tests.ts

@@ -703,6 +703,119 @@ response_headers:
   assert.strictEqual(fetchCalls.length, 1, 'report mode should forward GraphQL violations');
 });
 
+test('cloudflare sample_rate 1 emits an allow decision', async () => {
+  const generated = compileCloudflare(`
+version: 1
+project: cf-allow-sampling-test
+request:
+  allow_methods: ["GET"]
+response_headers:
+  hsts: "max-age=31536000"
+observability:
+  log_format: json
+  correlation_id_header: traceparent
+  sample_rate: 1
+`);
+  const captured: string[] = [];
+  const originalLog = console.log;
+  console.log = (line: any) => { captured.push(String(line)); };
+  try {
+    const request = new Request('https://edge.example.com/sampled', {
+      method: 'GET',
+      headers: { 'user-agent': 'runtime-test', traceparent: '00-cf-allow-test-01' },
+    });
+    const { res, fetchCalls } = await runGeneratedWorkerRequest(generated, request);
+    assert.strictEqual(res.status, 200);
+    assert.strictEqual(fetchCalls.length, 1);
+  } finally {
+    console.log = originalLog;
+  }
+  const allowLine = captured.find((line) => line.includes('"event":"allow"'));
+  assert.ok(allowLine, 'expected a sampled allow JSON log; got: ' + captured.join('\n'));
+  const record = JSON.parse(allowLine as string);
+  assert.strictEqual(record.method, 'GET');
+  assert.strictEqual(record.uri, '/sampled');
+  assert.strictEqual(record.correlation_id, '00-cf-allow-test-01');
+});
+
+test('cloudflare sample_rate 0 suppresses allow logs but preserves block logs', async () => {
+  const generated = compileCloudflare(`
+version: 1
+project: cf-zero-sampling-test
+request:
+  allow_methods: ["GET"]
+response_headers:
+  hsts: "max-age=31536000"
+observability:
+  log_format: json
+  correlation_id_header: traceparent
+  sample_rate: 0
+`);
+  const captured: string[] = [];
+  const originalLog = console.log;
+  console.log = (line: any) => { captured.push(String(line)); };
+  try {
+    await runGeneratedWorkerRequest(generated, new Request('https://edge.example.com/allowed', {
+      method: 'GET', headers: { 'user-agent': 'runtime-test' },
+    }));
+    const blocked = await runGeneratedWorkerRequest(generated, new Request('https://edge.example.com/blocked', {
+      method: 'POST', headers: { 'user-agent': 'runtime-test' },
+    }));
+    assert.strictEqual(blocked.res.status, 405);
+    assert.strictEqual(blocked.fetchCalls.length, 0);
+  } finally {
+    console.log = originalLog;
+  }
+  assert.strictEqual(captured.filter((line) => line.includes('"event":"allow"')).length, 0);
+  assert.strictEqual(captured.filter((line) => line.includes('"event":"block"')).length, 1);
+});
+
+test('cloudflare sampling is deterministic before correlation ID minting', async () => {
+  const generated = compileCloudflare(`
+version: 1
+project: cf-stable-sampling-test
+request:
+  allow_methods: ["GET"]
+response_headers:
+  hsts: "max-age=31536000"
+observability:
+  log_format: json
+  correlation_id_header: traceparent
+  sample_rate: 0.5
+`);
+  const originalCrypto = globalThis.crypto;
+  let sequence = 0;
+  Object.defineProperty(globalThis, 'crypto', {
+    configurable: true,
+    value: {
+      ...originalCrypto,
+      subtle: originalCrypto.subtle,
+      getRandomValues(bytes: Uint8Array) {
+        bytes.fill(++sequence % 2 === 0 ? 0x05 : 0x12);
+        return bytes;
+      },
+    },
+  });
+  const captured: string[] = [];
+  const originalLog = console.log;
+  console.log = (line: any) => { captured.push(String(line)); };
+  try {
+    for (let i = 0; i < 8; i++) {
+      const request = new Request('https://edge.example.com/stable-path', {
+        method: 'GET',
+        headers: { 'user-agent': 'runtime-test' },
+      });
+      await runGeneratedWorkerRequest(generated, request);
+    }
+  } finally {
+    console.log = originalLog;
+    Object.defineProperty(globalThis, 'crypto', { configurable: true, value: originalCrypto });
+  }
+  const allowCount = captured.filter((line) => line.includes('"event":"allow"')).length;
+  assert.ok(allowCount === 0 || allowCount === 8,
+    'minted correlation IDs changed the sampling bucket; allow logs=' + allowCount);
+});
+
 test('cloudflare compile fails when allowed_algorithms includes an alg the verifier cannot validate', () => {
   let caught: any;
   try {

src/scripts/compile-unit-tests.ts

@@ -1917,6 +1917,68 @@ test('viewer-request: structured JSON block log includes status, block_reason, u
   }
 });
 
+test('viewer-request: allow sampling respects sample_rate without suppressing blocks', () => {
+  const tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'compile-unit-obs-allow-'));
+  try {
+    build({
+      version: 1,
+      request: { allow_methods: ['GET'] },
+      response_headers: {},
+      observability: { log_format: 'json', correlation_id_header: 'traceparent', sample_rate: 1 },
+      routes: [],
+    }, { outDir: tmpDir, allowPlaceholderToken: true });
+    const code = fs.readFileSync(path.join(tmpDir, 'edge', 'viewer-request.js'), 'utf8');
+    const captured: string[] = [];
+    const origLog = console.log;
+    console.log = (line: any) => { captured.push(String(line)); };
+    try {
+      const handler = eval('(function(){' + code + '; return handler;})()');
+      handler({
+        request: {
+          method: 'GET',
+          uri: '/sampled',
+          querystring: '',
+          headers: {
+            'user-agent': { value: 'runtime-test' },
+            'traceparent': { value: '00-viewer-allow-test-01' },
+          },
+        },
+      });
+    } finally {
+      console.log = origLog;
+    }
+
+    const allowLine = captured.find((line: string) => line.includes('"event":"allow"'));
+    assert.ok(allowLine, 'expected a sampled allow JSON log; got: ' + captured.join('\n'));
+    const parsed = JSON.parse(allowLine as string);
+    assert.strictEqual(parsed.method, 'GET');
+    assert.strictEqual(parsed.uri, '/sampled');
+    assert.strictEqual(parsed.correlation_id, '00-viewer-allow-test-01');
+
+    build({
+      version: 1,
+      request: { allow_methods: ['GET'] },
+      response_headers: {},
+      observability: { log_format: 'json', correlation_id_header: 'traceparent', sample_rate: 0 },
+      routes: [],
+    }, { outDir: tmpDir, allowPlaceholderToken: true });
+    const zeroCode = fs.readFileSync(path.join(tmpDir, 'edge', 'viewer-request.js'), 'utf8');
+    const zeroLogs: string[] = [];
+    console.log = (line: any) => { zeroLogs.push(String(line)); };
+    try {
+      const zeroHandler = eval('(function(){' + zeroCode + '; return handler;})()');
+      zeroHandler({ request: { method: 'GET', uri: '/allowed', querystring: '', headers: { 'user-agent': { value: 'runtime-test' } } } });
+      zeroHandler({ request: { method: 'POST', uri: '/blocked', querystring: '', headers: { 'user-agent': { value: 'runtime-test' } } } });
+    } finally {
+      console.log = origLog;
+    }
+    assert.strictEqual(zeroLogs.filter((line) => line.includes('"event":"allow"')).length, 0);
+    assert.strictEqual(zeroLogs.filter((line) => line.includes('"event":"block"')).length, 1);
+  } finally {
+    fs.rmSync(tmpDir, { recursive: true, force: true });
+  }
+});
+
 test('validateOriginAuth warns when secret_env is unset (non-strict)', () => {
   const policy = { origin: { auth: { type: 'custom_header', header: 'X-Origin-Verify', secret_env: 'NONEXISTENT_FOR_TEST' } } };
   const warnings: string[] = [];

src/scripts/lib/compile-core.ts

@@ -538,6 +538,11 @@ function build(policy: any, options: any = {}) {
     '/* {{FEATURE_VIEWER_AUTH}} */ true',
     String(authGates.some((gate) => gate.type === 'static_token' || gate.type === 'basic_auth')),
   );
+  code = injectTemplateCode(
+    code,
+    '/* {{FEATURE_ALLOW_SAMPLING}} */ true',
+    String(requestBase.obs.sampleRate > 0),
+  );
   assertInjectedConstDeclarations(code, ['CFG']);
 
   const distDir = path.join(outDir, 'edge');