From 2cf184e6ba464e67a1c1a349876be5099f55fb25 Mon Sep 17 00:00:00 2001 From: hmmhmmhm Date: Tue, 29 Sep 2026 09:43:08 +0900 Subject: [PATCH] =?UTF-8?q?feat:=20=EB=A6=B4=EB=A0=88=EC=9D=B4=20=EA=B3=B5?= =?UTF-8?q?=ED=86=B5=20=EC=BA=90=EC=8B=9C=EC=99=80=20=EB=94=94=EC=8A=A4?= =?UTF-8?q?=ED=81=AC=20=EC=95=88=EC=A0=84=20=EC=A7=84=EB=8B=A8=20=EC=B6=94?= =?UTF-8?q?=EA=B0=80?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- docs/relay-observability.md | 50 ++++ .../plans/2026-09-29-relay-observability.md | 13 + .../2026-09-29-relay-observability-design.md | 14 ++ package-lock.json | 4 +- package.json | 2 +- scripts/relay/cache.ts | 46 ++++ scripts/relay/dtryx-start.ts | 37 ++- scripts/relay/dtryx.ts | 33 ++- scripts/relay/lifecycle.ts | 31 ++- scripts/relay/logging.ts | 132 ++++++++++ scripts/relay/observed.ts | 56 +++++ scripts/relay/oliveyoung.ts | 148 +++++++++-- scripts/relay/quota.ts | 25 +- scripts/relay/start.ts | 38 ++- src/api/routes/oliveyoungRoutes.ts | 13 +- src/core/registry.ts | 4 + src/index.ts | 5 +- src/middleware/diagnostics.ts | 24 ++ src/services/dtryx/transport.ts | 2 + src/services/oliveyoung/transport.ts | 2 + src/utils/diagnostics.ts | 90 +++++++ src/utils/http.ts | 6 + src/utils/oliveyoungCacheKey.ts | 26 ++ tests/app/app-daily-rate-limit.test.ts | 2 +- tests/app/app-mcp-client.test.ts | 18 ++ .../app/app-rate-limit-stats-logging.test.ts | 8 +- tests/relay/cache.test.ts | 28 +++ tests/relay/dtryx-events.test.ts | 49 ++++ tests/relay/lifecycle.test.ts | 11 + tests/relay/logging.test.ts | 238 ++++++++++++++++++ tests/relay/observed.test.ts | 52 ++++ tests/relay/oliveyoung.test.ts | 224 ++++++++++++++++- tests/relay/quota.test.ts | 43 ++++ tests/utils/diagnostics-integration.test.ts | 57 +++++ tests/utils/diagnostics.test.ts | 61 +++++ tests/utils/oliveyoungCacheKey.test.ts | 24 ++ vitest.config.ts | 2 +- wrangler.toml | 8 +- 38 files changed, 1573 insertions(+), 53 deletions(-) create mode 100644 docs/relay-observability.md create mode 100644 docs/superpowers/plans/2026-09-29-relay-observability.md create mode 100644 docs/superpowers/specs/2026-09-29-relay-observability-design.md create mode 100644 scripts/relay/cache.ts create mode 100644 scripts/relay/logging.ts create mode 100644 scripts/relay/observed.ts create mode 100644 src/middleware/diagnostics.ts create mode 100644 src/utils/diagnostics.ts create mode 100644 src/utils/oliveyoungCacheKey.ts create mode 100644 tests/relay/cache.test.ts create mode 100644 tests/relay/dtryx-events.test.ts create mode 100644 tests/relay/logging.test.ts create mode 100644 tests/relay/observed.test.ts create mode 100644 tests/utils/diagnostics-integration.test.ts create mode 100644 tests/utils/diagnostics.test.ts create mode 100644 tests/utils/oliveyoungCacheKey.test.ts diff --git a/docs/relay-observability.md b/docs/relay-observability.md new file mode 100644 index 00000000..b2793751 --- /dev/null +++ b/docs/relay-observability.md @@ -0,0 +1,50 @@ +# 릴레이 캐시 및 장애 추적 + +## 요청 ID로 찾기 + +REST/MCP HTTP 응답의 `x-request-id`를 확보한다. Worker 진단 로그의 `requestId`와 맥 릴레이 JSONL에서 같은 값을 찾으면 요청 경계를 연결할 수 있다. 동시에 합쳐진 OY 요청은 `parentRequestId`로 실제 실행을 맡은 요청을 찾는다. 내부 Actions 호출도 같은 ID를 유지한다. + +Worker는 모든 REST/MCP 요청 경계와 MCP 도구 결과, 공용 HTTP 유틸리티에서 실패를 기록한다. 성공은 요청 단위 1% 표본이며 요청당 최대 32개 이벤트를 기록한다. 개별 서비스가 자체 fetch를 쓸 경우 공용 HTTP 단계는 없을 수 있지만 REST/MCP 경계와 두 릴레이에는 기록이 남는다. 재시도·기존 결과 반환으로 최종 성공한 요청도 중간 HTTP 오류는 기록될 수 있다. Cloudflare 자체 장애로 코드가 실행되지 않은 경우에는 플랫폼 상태/Analytics를 함께 확인한다. + +Cloudflare Workers Observability에서 `event = diagnostic`, `requestId = `로 조회한다. 로그는 플랫폼에서 보존한다(현재 Free 3일/Paid 7일). 무제한 로컬 복사 작업은 없다. 자동 invocation 로그는 비활성화하고 커스텀 로그만 사용한다. 로그 비용/계정 한도는 Cloudflare 정책의 영향을 받는다. + +- https://developers.cloudflare.com/workers/observability/logs/workers-logs/ +- https://developers.cloudflare.com/workers/runtime-apis/nodejs/asynclocalstorage/ + +## 맥 로그 위치와 상한 + +각 `OY_RELAY_STATE_DIR/logs`, `DTRYX_RELAY_STATE_DIR/logs`에 `서비스-생성시각-uuid.jsonl`이 생성된다. 디렉터리 0700, 새 로그 파일 0600이다. + +| 항목 | 제한 | +| --- | --- | +| 파일 하나 | 4 MiB | +| 서비스 하나 합계 | 64 MiB | +| 현재 두 서비스 합계 | 128 MiB | +| 보존 | 생성 시각부터 7일, 용량 초과 시 오래된 파일부터 제거 | +| 디스크 여유 | 기록 후 최소 2 GiB 유지 확인 | +| 기록 대기 | 최대 256개, 각 이벤트 2 KiB 미만 | +| 유휴 정리 | 시작 시 및 1분 heartbeat 시 정리 | + +로그 파일만 정리하며 다른 파일은 삭제하지 않는다. 새 프로세스도 기존 로그를 합산한다. 디스크 부족/ENOSPC/기록 오류/큐 초과에서는 이벤트를 버리고 요청 처리 자체는 계속한다. 여유가 회복되면 자동 기록 재개한다. 다른 프로그램의 디스크 사용까지 통제하는 기능은 아니다. 프로세스 강제 종료나 시스템 장애 직전의 대기 이벤트는 유실될 수 있다. + +인증된 health의 `logging`에서 `queued`, `written`, `dropped`, `errors`, `lowSpace`를 확인한다. 이 카운터는 프로세스 재시작 시 초기화된다. 시작과 heartbeat에 quota 잔여량이 기록되고 `quota/consumed`는 OY 실제 실행 전에 차감된 호출을 의미한다. 집계는 JSONL의 UTC time, operation, stage, outcome을 사용한다. 보존 기간/용량/드롭을 함께 보고 숫자를 해석한다. + +기록하는 값은 고정 분류, 요청 ID, 작업 종류, 단계, 상태, 소요 시간, 캐시 결과, 제한 사유, quota 잔여량이다. 검색어, 위치 좌표, 요청/응답 본문, 인증 헤더, IP, 임의 예외 메시지는 넣지 않는다. 조회 예: + +```sh +rg --fixed-strings '확인할-request-id' "$OY_RELAY_STATE_DIR/logs" "$DTRYX_RELAY_STATE_DIR/logs" +``` + +## 원인 분류 + +- Worker 실패 로그는 있고 같은 ID의 릴레이 로그가 없음: relay 설정·네트워크·Cloudflare Access/Tunnel을 확인한다. 로컬 `logging.dropped/errors/lowSpace`도 먼저 점검한다. +- `quota` 단계와 429: health `quota.blockedBy`로 minute/daily를 구분하고 resetAt/Retry-After 이후 재시도한다. OY 응답은 `x-relay-quota-reason`도 제공한다. +- `queue/expired` 또는 busy: 큐/동시 요청 과부하와 클라이언트 취소를 확인한다. +- `upstream/error`: 서비스 원본/브라우저 실패. OY `lifecycle`의 launch-failed/startup-failed/request-failed/page-crash/rotation 원인과 비교한다. +- `process/startup-failed` 또는 heartbeat 단절: LaunchAgent 상태와 프로세스 시작 환경을 점검한다. cloudflared는 자체 플랫폼 상태도 확인한다. + +## OY 캐시 + +인증과 payload 검증 뒤 공통 릴레이 캐시를 확인한다. REST와 MCP가 같은 조건을 요청하면 공유된다. 상품 검색/매장은 5분, 상품 ID는 10분, 재고는 1분 TTL이다. 최대 256항목 및 키·값 직렬화 16MiB, 오래된 항목부터 퇴출한다. 성공만 저장하며 동일 진행 요청은 합친다. 탭이나 브라우저를 추가하지 않는다. + +캐시 적중은 quota를 소비하지 않는다. `x-relay-cache: hit/miss/coalesced` 및 health.cache로 확인한다. 서로 다른 검색이 대부분이면 절감 효과는 작다. quota는 기존 분당30/UTC 일일3000을 유지한다. REST 캐시도 별도로 존재하며 products5분/stores24시간/inventory10분이므로 외부 REST 응답의 최신성은 두 계층의 영향을 받는다. `_healthCheck`는 REST 캐시를 새로 조회하지만 공통 릴레이 캐시는 계속 적용된다. diff --git a/docs/superpowers/plans/2026-09-29-relay-observability.md b/docs/superpowers/plans/2026-09-29-relay-observability.md new file mode 100644 index 00000000..48280223 --- /dev/null +++ b/docs/superpowers/plans/2026-09-29-relay-observability.md @@ -0,0 +1,13 @@ +# Relay Observability Implementation Plan + +> **For agentic workers:** Use superpowers:subagent-driven-development for isolated implementation and review. + +**Goal:** OY 반복 upstream 호출을 절감하고 디스크 안전 추적을 배포한다. +**Architecture:** bounded relay cache + 공통 로컬 JSONL logger + Worker request context. +**Tech Stack:** TypeScript, Node24, Hono, Cloudflare Workers, Vitest. + +- [x] Task 1: scripts/relay/cache.ts, quota.ts, oliveyoung.ts와 tests/relay 확장. 동일 요청 3회 차감1, 동시합치기, TTL/용량 퇴출, 오류미저장, abort/queue/권한 회귀를 먼저 재현한다. quota 함수의 boolean 계약 유지하며 status()로 분/일 원인과 Retry-After를 얻는다. +- [x] Task 2: scripts/relay/logging.ts + tests/relay. 고정 schema append(event), flush(), status() API. 4MiB rotation/64MiB retention/7일/2GiB reserve/256 pending/2KiB event. statfs/IO는 주입해서 디스크부족과 ENOSPC, restart 파일 정리를 검증한다. start.ts,dtryx-start.ts 연결은 root가 수행한다. +- [x] Task 3: src/utils/diagnostics.ts, src/index.ts, core/registry.ts, utils/http.ts, relay transports. request-scoped context에서 경계 기록 및 ID 전달. src/api/routes/oliveyoungRoutes.ts 키 정규화. Worker config logs 설정. 테스트는 개인정보 미노출·동시 context 격리·오류 기록·기존 응답 계약 보존. +- [x] Task 4: 루트에서 start/lifecycle/Dtryx integration, 운영 문서, 전체 npm run check / build / test:coverage, 독립 spec/quality review 및 수정. +- [ ] Task 5: PR 생성 및 CI 확인 후 병합. Mac runtime 복사/원자적 교체·LaunchAgent 재시작, Worker 배포 확인, REST/MCP 실조회 및 로그 상관/권한/크기/캐시절감 확인. 운영상태 기록. diff --git a/docs/superpowers/specs/2026-09-29-relay-observability-design.md b/docs/superpowers/specs/2026-09-29-relay-observability-design.md new file mode 100644 index 00000000..1ac3313d --- /dev/null +++ b/docs/superpowers/specs/2026-09-29-relay-observability-design.md @@ -0,0 +1,14 @@ +# 릴레이 호출 절감 및 추적 설계 + +사용자가 2026-09-29 승인한 공통 캐시/중복 합치기와 디스크 안전 로깅을 구현한다. + +- OY 인증/검증 후 정규 payload 키로 캐시한다. 상품 5분, 상품 ID 10분, 매장 5분, 재고 1분. 최대 256항목 및 직렬화 16MiB. 성공만 저장한다. 동일 진행 요청을 합치며 기존 queue/body/timeout/인증 제한을 유지한다. 캐시 적중은 quota 미차감. +- quota 분/일 차단을 구분하고 Retry-After와 현재 잔여/초기화 시각을 인증 health에서 제공한다. 과거 집계는 로그에서 보존한다. +- 두 로컬 릴레이에 공통 JSONL 로깅. 서비스별 64MiB(합계128MiB), 파일4MiB, 7일. 디스크 가용2GiB 미만이면 자체 오래된 로그 정리 후 기록을 중단한다. 다른 파일은 삭제하지 않는다. 재검사로 여유 회복 시 자동 재개. 큐는256개 이하, 이벤트2KiB 이하. logger 실패가 서비스 실패로 번지지 않는다. +- 로그 필드는 고정 allowlist: 시각/요청ID/상위ID/서비스/operation/단계/상태/소요시간/캐시결과/차단사유. URL query, 요청/응답 본문, 검색어, 좌표, 토큰, 임의 에러 메시지 제외. 로그0700/0600. health에 로그드롭/기록실패/디스크중단 상태를 노출한다. +- Worker 요청 컨텍스트별 ID를 응답 및 relay 요청에 전달. 모든 REST/MCP 서비스에 경계 이벤트를 적용하고 실패는 모두, 성공은 샘플링. Cloudflare managed logs 사용, 자동 invocation 로그는 꺼 민감 query가 기록되지 않게 한다. CLI stdout은 MCP 프로토콜 보호를 위해 사용하지 않는다. +- REST OY 캐시 키는 허용 query 및 기본값 정규화. 의도적 health fresh 파라미터는 보존한다. +- 릴레이 lifecycle 시작/회전/실패와 프로세스 시작/종료 기록. 터널은 기존 cloudflared 상태와 상관관계로 조사하며 무제한 stdout 파일을 만들지 않는다. +- 실패/만료/중복/용량초과/디스크부족/재시작 보존 및 민감값 미기록 테스트. 전체 check/build/100% coverage 후 PR 검토·병합, Worker 및 Mac 두 런타임 배포와 실조회 검증. + +한도 증가는 하지 않는다. fresh cache가 재고를 최대1분 지연시킬 수 있다. 디스크부족에서는 서비스 가용성과 디스크 보존을 위해 파일 로그를 버리며 health로 누락을 알린다. diff --git a/package-lock.json b/package-lock.json index a4efa12a..f659ee57 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "daiso", - "version": "1.2.5", + "version": "1.2.6", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "daiso", - "version": "1.2.5", + "version": "1.2.6", "license": "MIT", "dependencies": { "@modelcontextprotocol/sdk": "^1.30.0", diff --git a/package.json b/package.json index 2cf6d506..88bddd87 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "daiso", - "version": "1.2.5", + "version": "1.2.6", "description": "Korean retail and cinema MCP server, CLI, and Codex Skill for Daiso, convenience stores, marts, Olive Young, and theaters", "main": "dist/index.js", "bin": { diff --git a/scripts/relay/cache.ts b/scripts/relay/cache.ts new file mode 100644 index 00000000..c88ea0ab --- /dev/null +++ b/scripts/relay/cache.ts @@ -0,0 +1,46 @@ +/** 검증된 평면 입력용 키와 바이트·항목 상한을 가진 TTL LRU 캐시. */ +export function canonicalKey(operation: string, body: Record): string { + return JSON.stringify([ + operation, + Object.keys(body) + .sort() + .map((key) => [key, body[key]]), + ]); +} +export function createResponseCache(maxEntries = 256, maxBytes = 16 * 1024 * 1024, now = Date.now) { + const entries = new Map(); + let bytes = 0; + const remove = (key: string) => { + bytes -= entries.get(key)!.bytes; + entries.delete(key); + }; + const prune = () => { + const time = now(); + for (const [key, entry] of entries) if (entry.expires <= time) remove(key); + }; + return { + get(key: string): string | undefined { + prune(); + const entry = entries.get(key); + if (!entry) return undefined; + entries.delete(key); + entries.set(key, entry); + return entry.value; + }, + set(key: string, value: string, ttl: number) { + prune(); + if (entries.has(key)) remove(key); + const size = Buffer.byteLength(key) + Buffer.byteLength(value); + if (size > maxBytes) return; + while (entries.size >= maxEntries || bytes + size > maxBytes) { + remove(entries.keys().next().value!); + } + entries.set(key, { value, bytes: size, expires: now() + ttl }); + bytes += size; + }, + stats() { + prune(); + return { entries: entries.size, bytes, maxEntries, maxBytes }; + }, + }; +} diff --git a/scripts/relay/dtryx-start.ts b/scripts/relay/dtryx-start.ts index ccf9d842..b5c4d787 100644 --- a/scripts/relay/dtryx-start.ts +++ b/scripts/relay/dtryx-start.ts @@ -1,3 +1,5 @@ +import { createRelayLogger } from './logging.js'; +import { observeRelay } from './observed.js'; /** 브라우저 없이 별도 프로세스로 디트릭스 중계를 실행합니다. */ import { createServer } from 'node:http'; import { Readable } from 'node:stream'; @@ -7,6 +9,7 @@ import { pathToFileURL } from 'node:url'; import { createFileQuota } from './quota.js'; import { createDtryxRelay } from './dtryx.js'; +let logger: ReturnType | undefined; async function main() { const token = process.env.DTRYX_RELAY_TOKEN; const stateDir = process.env.DTRYX_RELAY_STATE_DIR; @@ -15,9 +18,28 @@ async function main() { throw new Error('Invalid relay configuration'); } await mkdir(stateDir, { recursive: true, mode: 0o700 }); - const handler = createDtryxRelay(token, { - takeQuota: await createFileQuota(join(stateDir, 'quota.json')), - }); + logger = createRelayLogger(join(stateDir, 'logs'), { service: 'dtryx' }); + const log = logger; + log.append({ stage: 'process', outcome: 'starting' }); + const takeQuota = await createFileQuota(join(stateDir, 'quota.json')); + log.append({ stage: 'quota', outcome: 'snapshot', ...takeQuota.status() }); + const heartbeat = setInterval( + () => log.append({ stage: 'process', outcome: 'heartbeat', ...takeQuota.status() }), + 60000, + ); + heartbeat.unref(); + const relay = createDtryxRelay(token, { takeQuota, onEvent: log.append }); + const handler = observeRelay(async (request) => { + const response = await relay(request); + if (response.ok && new URL(request.url).pathname === '/v1/dtryx/health') { + return Response.json({ + ...(await response.json()), + quota: takeQuota.status(), + logging: log.status(), + }); + } + return response; + }, log.append); const server = createServer(async (req, res) => { const controller = new AbortController(); res.once('close', () => controller.abort()); @@ -32,12 +54,14 @@ async function main() { } as RequestInit & { duplex: 'half' }), ); res.writeHead(response.status, { + ...Object.fromEntries(response.headers), 'Content-Type': 'application/json', 'Cache-Control': 'no-store', Connection: 'close', }); res.end(await response.text()); } catch { + log.append({ stage: 'server', outcome: 'error', status: 500 }); res.writeHead(500, { Connection: 'close' }); res.end('{"error":"Relay failure"}'); } @@ -51,6 +75,9 @@ async function main() { }); console.log(`Dtryx relay ready on 127.0.0.1:${port}`); const close = () => { + clearInterval(heartbeat); + log.append({ stage: 'process', outcome: 'stopping' }); + void log.flush(); server.close(); server.closeAllConnections(); }; @@ -58,7 +85,9 @@ async function main() { process.once('SIGINT', close); } if (process.argv[1] && import.meta.url === pathToFileURL(process.argv[1]).href) { - main().catch(() => { + main().catch(async () => { + logger?.append({ stage: 'process', outcome: 'startup-failed' }); + await logger?.flush(); console.error('디트릭스 릴레이 시작 실패: 토큰, 포트 및 상태 경로를 확인하세요.'); process.exitCode = 1; }); diff --git a/scripts/relay/dtryx.ts b/scripts/relay/dtryx.ts index b8398222..319a84ff 100644 --- a/scripts/relay/dtryx.ts +++ b/scripts/relay/dtryx.ts @@ -1,5 +1,5 @@ /** 고정 공개 API만 허용하는 디트릭스 전용 중계입니다. */ -import { timingSafeEqual } from 'node:crypto'; +import { randomUUID, timingSafeEqual } from 'node:crypto'; import { DTRYX_API } from '../../src/services/dtryx/api.js'; type Route = 'timetable' | 'play-dates' | 'movies'; @@ -11,6 +11,14 @@ interface Params { interface Options { takeQuota: () => Promise; fetcher?: typeof fetch; + onEvent?: (event: { + stage: string; + operation: string; + requestId: string; + outcome: string; + status: number; + durationMs: number; + }) => void | Promise; } class RelayError extends Error { constructor(readonly status: number) { @@ -195,11 +203,17 @@ export function createDtryxRelay(token: string, options: Options) { abort(); }, 15000); let acquired = false; + let stage = 'body'; + let resultStatus = 200; + const suppliedId = request.headers.get('x-request-id'); + const requestId = + suppliedId && /^[A-Za-z0-9_-]{1,64}$/.test(suppliedId) ? suppliedId : randomUUID(); try { const p = validate( await readJson(request.body, 16384, controller.signal, 400), name as Route, ); + stage = 'queue'; await acquire(controller.signal); acquired = true; if (performance.now() >= deadline) { @@ -207,6 +221,7 @@ export function createDtryxRelay(token: string, options: Options) { abort(); } controller.signal.throwIfAborted(); + stage = 'quota'; if ( !(await abortable( options.takeQuota().catch(() => { @@ -217,6 +232,7 @@ export function createDtryxRelay(token: string, options: Options) { ) throw new RelayError(429); controller.signal.throwIfAborted(); + stage = 'upstream'; return reply(200, await upstream(name as Route, p, controller.signal, fetcher)); } catch (error) { const status = expired @@ -226,8 +242,23 @@ export function createDtryxRelay(token: string, options: Options) { : error instanceof RelayError ? error.status : 502; + resultStatus = status; return reply(status, { error: 'Relay request failed' }); } finally { + try { + void Promise.resolve( + options.onEvent?.({ + stage, + operation: name, + requestId, + outcome: resultStatus === 200 ? 'ok' : 'error', + status: resultStatus, + durationMs: performance.now() - deadline + 15000, + }), + ).catch(() => undefined); + } catch { + /* 관측 실패는 요청에 영향을 주지 않습니다. */ + } clearTimeout(timer); request.signal.removeEventListener('abort', abort); controller.abort(); diff --git a/scripts/relay/lifecycle.ts b/scripts/relay/lifecycle.ts index d3049849..c27c9a79 100644 --- a/scripts/relay/lifecycle.ts +++ b/scripts/relay/lifecycle.ts @@ -21,7 +21,17 @@ export async function bounded(work: Promise, ms: number): Promise { clearTimeout(timer!); } } -export function createBrowserLifecycle(launch: () => Promise) { +export function createBrowserLifecycle( + launch: () => Promise, + onEvent?: (reason: string) => void | Promise, +) { + const emit = (reason: string) => { + try { + void Promise.resolve(onEvent?.(reason)).catch(() => undefined); + } catch { + /* 관측 실패는 브라우저 회수에 영향을 주지 않습니다. */ + } + }; let owner: BrowserOwner | undefined; let page: Page | undefined; let context: BrowserContext | undefined; @@ -40,6 +50,7 @@ export function createBrowserLifecycle(launch: () => Promise) { let replacementPending = false; const retire = (why: string) => { reason = why; + emit(why); if (timer) clearInterval(timer); timer = undefined; const previous = owner; @@ -69,7 +80,12 @@ export function createBrowserLifecycle(launch: () => Promise) { rotations++; } if (owner) return; - owner = await launch(); + try { + owner = await launch(); + } catch (error) { + emit('launch-failed'); + throw error; + } born = Date.now(); calls = 0; if (closed) { @@ -97,6 +113,7 @@ export function createBrowserLifecycle(launch: () => Promise) { ); await bounded(page.waitForURL('**/store/**', { timeout: 30000 }), 32000); if (closed || owner !== sessionOwner) throw new Error('Browser lifecycle unavailable'); + emit('ready'); timer = setInterval(() => { if (!active && Date.now() - born >= 30 * 60 * 1000) { rotations++; @@ -166,7 +183,15 @@ export function createBrowserLifecycle(launch: () => Promise) { await cleanup; }, status: () => ({ - state: failed ? 'failed' : closed ? 'closed' : initializing ? 'starting' : owner ? 'ready' : 'idle', + state: failed + ? 'failed' + : closed + ? 'closed' + : initializing + ? 'starting' + : owner + ? 'ready' + : 'idle', active, calls, totalCalls, diff --git a/scripts/relay/logging.ts b/scripts/relay/logging.ts new file mode 100644 index 00000000..256c47b9 --- /dev/null +++ b/scripts/relay/logging.ts @@ -0,0 +1,132 @@ +/** 민감한 입력을 제외하고 디스크·메모리 상한을 지키는 로컬 JSONL 로그. */ +import { appendFile, chmod, mkdir, readdir, stat, statfs, unlink } from 'node:fs/promises'; +import { randomUUID } from 'node:crypto'; +import { join } from 'node:path'; + +interface LoggerOptions { + service: 'oliveyoung' | 'dtryx'; + now?: () => number; + statfs?: (path: string) => Promise<{ bavail: number; bsize: number }>; + appendFile?: typeof appendFile; + maxFileBytes?: number; + maxTotalBytes?: number; +} +export function createRelayLogger(directory: string, options: LoggerOptions) { + const now = options.now ?? Date.now; + const available = options.statfs ?? statfs; + const write = options.appendFile ?? appendFile; + const maxFileBytes = Math.min(options.maxFileBytes ?? 4 * 1024 ** 2, 4 * 1024 ** 2); + const maxTotalBytes = Math.min(options.maxTotalBytes ?? 64 * 1024 ** 2, 64 * 1024 ** 2); + const ownFile = new RegExp(`^${options.service}-[0-9]+-[A-Za-z0-9-]+\\.jsonl$`); + const queue: string[] = []; + let running: Promise | undefined; + let queued = 0; + let written = 0; + let dropped = 0; + let errors = 0; + let lowSpace = false; + let active: string | undefined; + let initialized = false; + + async function persist(line: string) { + if (!initialized) { + await mkdir(directory, { recursive: true, mode: 0o700 }); + await chmod(directory, 0o700); + initialized = true; + } + const files: { name: string; bytes: number; created: number }[] = []; + for (const item of await readdir(directory, { withFileTypes: true })) { + if (!item.isFile() || !ownFile.test(item.name)) continue; + const info = await stat(join(directory, item.name)); + const created = Number(item.name.split('-')[1]); + if (created <= now() - 7 * 86400000) { + await unlink(join(directory, item.name)); + } else { + files.push({ name: item.name, bytes: info.size, created }); + } + } + files.sort((a, b) => a.created - b.created || a.name.localeCompare(b.name)); + const bytes = Buffer.byteLength(line); + if (bytes > maxFileBytes || bytes > maxTotalBytes) { + dropped++; + return; + } + let total = files.reduce((sum, file) => sum + file.bytes, 0); + while (total + bytes > maxTotalBytes) { + const oldest = files.shift()!; + await unlink(join(directory, oldest.name)); + total -= oldest.bytes; + } + const disk = await available(directory); + lowSpace = disk.bavail * disk.bsize - bytes < 2 * 1024 ** 3; + if (lowSpace) { + dropped++; + return; + } + const current = files.find((file) => file.name === active); + if (!current || current.bytes + bytes > maxFileBytes) { + active = `${options.service}-${now()}-${randomUUID()}.jsonl`; + } + await write(join(directory, active!), line, { mode: 0o600 }); + written++; + } + async function drain() { + while (queue.length) { + const line = queue.shift()!; + try { + await persist(line); + } catch { + errors++; + dropped++; + } finally { + queued--; + } + } + running = undefined; + } + return { + append(event: object): void { + try { + const safe: Record = { + time: new Date(now()).toISOString(), + service: options.service, + }; + for (const field of [ + 'requestId', + 'parentRequestId', + 'operation', + 'stage', + 'outcome', + 'cache', + 'quotaReason', + ]) { + const value = (event as Record)[field]; + if (typeof value === 'string' && /^[A-Za-z0-9_-]{1,64}$/.test(value)) safe[field] = value; + } + for (const field of ['status', 'durationMs', 'dailyRemaining', 'minuteRemaining']) { + const value = (event as Record)[field]; + if (typeof value === 'number' && Number.isFinite(value) && value >= 0) + safe[field] = value; + } + const line = `${JSON.stringify(safe)}\n`; + // 허용 필드 7개×64자와 숫자 4개로 각 이벤트는 2KiB 미만입니다. + if (queued >= 256) { + dropped++; + return; + } + queue.push(line); + queued++; + running ??= drain(); + } catch { + errors++; + dropped++; + } + }, + async flush(): Promise { + await running; + }, + status() { + return { queued, written, dropped, errors, lowSpace }; + }, + }; +} diff --git a/scripts/relay/observed.ts b/scripts/relay/observed.ts new file mode 100644 index 00000000..c3077102 --- /dev/null +++ b/scripts/relay/observed.ts @@ -0,0 +1,56 @@ +/** 로컬 요청의 상태만 기록하며 인증정보나 payload를 보존하지 않습니다. */ +import { randomUUID } from 'node:crypto'; +export interface RequestEvent { + requestId: string; + operation: string; + stage: string; + outcome: string; + status: number; + durationMs: number; + cache?: string; + quotaReason?: string; +} +export function observeRelay( + handler: (request: Request) => Promise, + emit: (event: RequestEvent) => void | Promise, +) { + return async (request: Request): Promise => { + const supplied = request.headers.get('x-request-id'); + const requestId = supplied && /^[A-Za-z0-9_-]{1,64}$/.test(supplied) ? supplied : randomUUID(); + const headers = new Headers(request.headers); + headers.set('x-request-id', requestId); + const forwarded = new Request(request, { headers }); + const path = new URL(request.url).pathname; + const match = + /^\/v1\/(?:oliveyoung|dtryx)\/(find-store|product-search-v3|stock-goods-info-v3|stock-stores|movies|play-dates|timetable)$/.exec( + path, + ); + const operation = match ? match[1] : 'other'; + const start = Date.now(); + let response: Response | undefined; + try { + response = await handler(forwarded); + response.headers.set('x-request-id', requestId); + return response; + } finally { + if (!response?.ok || !['/health', '/v1/dtryx/health'].includes(path)) { + try { + void Promise.resolve( + emit({ + requestId, + operation, + stage: 'request', + outcome: response?.ok ? 'ok' : 'error', + status: response?.status ?? 500, + durationMs: Date.now() - start, + cache: response?.headers.get('x-relay-cache') ?? undefined, + quotaReason: response?.headers.get('x-relay-quota-reason') ?? undefined, + }), + ).catch(() => undefined); + } catch { + /* 기록 실패는 서비스 응답에 영향을 주지 않습니다. */ + } + } + } + }; +} diff --git a/scripts/relay/oliveyoung.ts b/scripts/relay/oliveyoung.ts index bc972418..2eae3541 100644 --- a/scripts/relay/oliveyoung.ts +++ b/scripts/relay/oliveyoung.ts @@ -1,7 +1,9 @@ /** 고정된 올리브영 조회만 허용하는 인증 릴레이. */ -import { timingSafeEqual } from 'node:crypto'; +import { randomUUID, timingSafeEqual } from 'node:crypto'; import { OLIVEYOUNG_API } from '../../src/services/oliveyoung/api.js'; import type { OliveyoungApiResponse } from '../../src/services/oliveyoung/types.js'; +import { canonicalKey, createResponseCache } from './cache.js'; +import type { QuotaStatus } from './quota.js'; export type BrowserRunner = ( path: string, body: Record, @@ -43,8 +45,17 @@ const fields: Record> = }; const error = (status: number, message: string) => Response.json({ error: message }, { status }); -interface RelayOptions { - takeQuota?: () => Promise; +export interface RelayEvent { + stage: string; + operation: string; + outcome: string; + requestId?: string; + parentRequestId?: string; + durationMs?: number; +} +export interface RelayOptions { + takeQuota?: (() => Promise) & { status?: () => QuotaStatus }; + onEvent?: (event: RelayEvent) => void | Promise; status?: () => Record; } export function createOliveyoungRelay( @@ -54,6 +65,23 @@ export function createOliveyoungRelay( ) { if (!token.trim()) throw new Error('OY_RELAY_TOKEN이 필요합니다.'); const expected = Buffer.from(`Bearer ${token}`); + const cache = createResponseCache(); + const ttl: Record = { + 'find-store': 300000, + 'product-search-v3': 300000, + 'stock-goods-info-v3': 600000, + 'stock-stores': 60000, + }; + type Result = OliveyoungApiResponse | null | 'quota' | 'unavailable'; + const pending = new Map< + string, + { + task: Promise; + signals: Map; + startedAt: number; + requestId: string; + } + >(); let outstanding = 0; let tail: Promise = Promise.resolve(); return async (request: Request): Promise => { @@ -62,7 +90,12 @@ export function createOliveyoungRelay( return error(401, 'Unauthorized'); const url = new URL(request.url); if (request.method === 'GET' && url.pathname === '/health' && !url.search && options.status) { - return Response.json({ ...options.status(), outstanding }); + return Response.json({ + ...options.status(), + outstanding, + cache: cache.stats(), + quota: options.takeQuota?.status?.(), + }); } if (!url.pathname.startsWith('/v1/oliveyoung/')) return error(404, 'Not found'); const operation = url.pathname.slice('/v1/oliveyoung/'.length); @@ -105,28 +138,103 @@ export function createOliveyoungRelay( return error(400, 'Invalid JSON'); } - const queuedAt = Date.now(); - const task = tail.then(async () => { - if (request.signal.aborted || Date.now() - queuedAt >= 15000) return null; - if (options.takeQuota) { - try { - if (!(await options.takeQuota())) return 'quota' as const; - } catch { - return 'unavailable' as const; - } + const suppliedId = request.headers.get('x-request-id'); + const requestId = + suppliedId && /^[A-Za-z0-9_-]{1,64}$/.test(suppliedId) ? suppliedId : randomUUID(); + const started = Date.now(); + const emit = (stage: string, outcome: string, parentRequestId?: string) => { + try { + void Promise.resolve( + options.onEvent?.({ + stage, + operation, + outcome, + requestId, + parentRequestId, + durationMs: Date.now() - started, + }), + ).catch(() => undefined); + } catch { + /* 관측 실패는 요청 처리에 영향을 주지 않습니다. */ } - return run(paths[operation], body); - }); - tail = task.catch(() => undefined); + }; + const key = canonicalKey(operation, body); + const cached = cache.get(key); + if (cached !== undefined) { + emit('cache', 'hit'); + return new Response(cached, { + headers: { 'content-type': 'application/json', 'x-relay-cache': 'hit' }, + }); + } + let entry = pending.get(key); + const mode = entry ? 'coalesced' : 'miss'; + emit('cache', mode, entry?.requestId); + const queuedAt = Date.now(); + if (!entry) { + const signals = new Map([[request.signal, queuedAt]]); + const task = tail + .then(async (): Promise => { + entry!.startedAt = Date.now(); + if ( + [...signals].every( + ([signal, arrived]) => signal.aborted || entry!.startedAt - arrived >= 15000, + ) + ) + return null; + if (options.takeQuota) { + try { + if (!(await options.takeQuota())) { + emit('quota', 'denied'); + return 'quota'; + } + emit('quota', 'consumed'); + } catch { + emit('quota', 'unavailable'); + return 'unavailable'; + } + } + const result = await run(paths[operation], body); + if (result?.status === 'SUCCESS') + cache.set(key, JSON.stringify(result), ttl[operation]); + emit('upstream', result?.status === 'SUCCESS' ? 'success' : 'error'); + return result; + }) + .finally(() => { + pending.delete(key); + }); + entry = { task, signals, startedAt: 0, requestId }; + pending.set(key, entry); + tail = task.catch(() => undefined); + } else { + entry.signals.set(request.signal, queuedAt); + } try { - const result = await task; - if (result === null) return error(503, 'Request expired'); - if (result === 'quota') return error(429, 'Relay quota exceeded'); + const result = await entry.task; + if (request.signal.aborted || result === null || entry.startedAt - queuedAt >= 15000) { + emit('queue', 'expired'); + return error(503, 'Request expired'); + } + if (result === 'quota') { + const status = options.takeQuota?.status?.(); + return Response.json( + { error: 'Relay quota exceeded', reason: status?.blockedBy || 'unknown' }, + { + status: 429, + headers: { + 'x-relay-quota-reason': status?.blockedBy || 'unknown', + 'retry-after': String(status?.retryAfter || 60), + }, + }, + ); + } if (result === 'unavailable') return error(503, 'Relay quota unavailable'); if (result?.status !== 'SUCCESS') return error(502, 'Upstream unavailable'); - return Response.json(result); + return Response.json(result, { headers: { 'x-relay-cache': mode } }); } catch { + emit('upstream', 'error'); return error(502, 'Upstream unavailable'); + } finally { + entry.signals.delete(request.signal); } } finally { outstanding--; diff --git a/scripts/relay/quota.ts b/scripts/relay/quota.ts index 76df3d9f..c598caa0 100644 --- a/scripts/relay/quota.ts +++ b/scripts/relay/quota.ts @@ -6,10 +6,18 @@ interface Ledger { dayCount: number; minuteCount: number; } +export interface QuotaStatus { + dailyRemaining: number; + minuteRemaining: number; + resetAt: { daily: number; minute: number }; + blockedBy: 'daily' | 'minute' | null; + retryAfter: number; +} +export type FileQuota = (() => Promise) & { status: () => QuotaStatus }; export async function createFileQuota( path: string, now: () => number = Date.now, -): Promise<() => Promise> { +): Promise { let ledger: Ledger = { day: 0, minute: 0, dayCount: 0, minuteCount: 0 }; try { const value = JSON.parse(await readFile(path, 'utf8')) as Ledger; @@ -26,7 +34,7 @@ export async function createFileQuota( if ((error as NodeJS.ErrnoException).code !== 'ENOENT') throw error; } let tail: Promise = Promise.resolve(); - return () => { + const take = () => { const task = tail.then(async () => { const time = now(); const day = Math.max(ledger.day, Math.floor(time / 86400000)); @@ -44,4 +52,17 @@ export async function createFileQuota( tail = task.catch(() => undefined); return task; }; + return Object.assign(take, { + status(): QuotaStatus { + const time = now(); + const day = Math.max(ledger.day, Math.floor(time / 86400000)); + const minute = Math.max(ledger.minute, Math.floor(time / 60000)); + const dailyRemaining = Math.max(0, 3000 - (day === ledger.day ? ledger.dayCount : 0)); + const minuteRemaining = Math.max(0, 30 - (minute === ledger.minute ? ledger.minuteCount : 0)); + const resetAt = { daily: (day + 1) * 86400000, minute: (minute + 1) * 60000 }; + const blockedBy = dailyRemaining === 0 ? 'daily' : minuteRemaining === 0 ? 'minute' : null; + const retryAfter = blockedBy ? Math.ceil((resetAt[blockedBy] - time) / 1000) : 0; + return { dailyRemaining, minuteRemaining, resetAt, blockedBy, retryAfter }; + }, + }); } diff --git a/scripts/relay/start.ts b/scripts/relay/start.ts index b0ed9fb3..637a6d13 100644 --- a/scripts/relay/start.ts +++ b/scripts/relay/start.ts @@ -1,3 +1,5 @@ +import { createRelayLogger } from './logging.js'; +import { observeRelay } from './observed.js'; /** 실행 시에만 로컬 브라우저 릴레이를 시작합니다. */ import { createServer } from 'node:http'; import { Readable } from 'node:stream'; @@ -9,6 +11,7 @@ import { launchGuardedBrowser } from './supervisor.js'; import { createFileQuota } from './quota.js'; import { createOliveyoungRelay } from './oliveyoung.js'; +let logger: ReturnType | undefined; async function main() { const token = process.env.OY_RELAY_TOKEN; if (!token?.trim()) throw new Error('OY_RELAY_TOKEN이 필요합니다.'); @@ -18,16 +21,30 @@ async function main() { const stateDir = process.env.OY_RELAY_STATE_DIR; if (!stateDir) throw new Error('OY_RELAY_STATE_DIR이 필요합니다.'); await mkdir(stateDir, { recursive: true, mode: 0o700 }); + logger = createRelayLogger(join(stateDir, 'logs'), { service: 'oliveyoung' }); + const log = logger; + log.append({ stage: 'process', outcome: 'starting' }); const takeQuota = await createFileQuota(join(stateDir, 'quota.json')); - const lifecycle = createBrowserLifecycle(() => - launchGuardedBrowser(join(stateDir, 'browser-owner.json')), + log.append({ stage: 'quota', outcome: 'snapshot', ...takeQuota.status() }); + const heartbeat = setInterval( + () => log.append({ stage: 'process', outcome: 'heartbeat', ...takeQuota.status() }), + 60000, + ); + heartbeat.unref(); + const lifecycle = createBrowserLifecycle( + () => launchGuardedBrowser(join(stateDir, 'browser-owner.json')), + (outcome) => log.append({ stage: 'lifecycle', operation: 'browser', outcome }), ); try { await lifecycle.start(); - const handler = createOliveyoungRelay(token, lifecycle.run, { - takeQuota, - status: lifecycle.status, - }); + const handler = observeRelay( + createOliveyoungRelay(token, lifecycle.run, { + takeQuota, + status: () => ({ ...lifecycle.status(), logging: log.status() }), + onEvent: log.append, + }), + log.append, + ); const server = createServer(async (req, res) => { try { const controller = new AbortController(); @@ -41,11 +58,13 @@ async function main() { } as RequestInit & { duplex: 'half' }); const response = await handler(request); res.writeHead(response.status, { + ...Object.fromEntries(response.headers), 'Content-Type': 'application/json', 'Cache-Control': 'no-store', }); res.end(await response.text()); } catch { + log.append({ stage: 'server', outcome: 'error', status: 500 }); res.writeHead(500); res.end('{"error":"Relay failure"}'); } @@ -61,10 +80,13 @@ async function main() { const close = () => { if (stopping) return; stopping = true; + clearInterval(heartbeat); + log.append({ stage: 'process', outcome: 'stopping' }); server.close(); server.closeAllConnections(); void lifecycle .close() + .then(() => log.flush()) .then(() => process.exit(0)) .catch(() => process.exit(1)); }; @@ -76,7 +98,9 @@ async function main() { } } if (process.argv[1] && import.meta.url === pathToFileURL(process.argv[1]).href) { - main().catch(() => { + main().catch(async () => { + logger?.append({ stage: 'process', outcome: 'startup-failed' }); + await logger?.flush(); console.error('올리브영 릴레이 시작 실패: 토큰, 포트 및 GUI 브라우저 접속을 확인하세요.'); process.exitCode = 1; }); diff --git a/src/api/routes/oliveyoungRoutes.ts b/src/api/routes/oliveyoungRoutes.ts index 019a77f7..fa579858 100644 --- a/src/api/routes/oliveyoungRoutes.ts +++ b/src/api/routes/oliveyoungRoutes.ts @@ -2,6 +2,7 @@ * 올리브영 GET API 라우트 등록 */ +import { oliveyoungCacheKey } from '../../utils/oliveyoungCacheKey.js'; import type { Hono } from 'hono'; import { withEdgeCache } from '../../utils/cache.js'; import { @@ -14,11 +15,11 @@ import type { AppBindings } from '../response.js'; export function registerOliveyoungRoutes(app: Hono<{ Bindings: AppBindings }>): void { app.get('/api/oliveyoung/products', async (c) => withEdgeCache( - c.req.url, + oliveyoungCacheKey(c.req.url), { ttlSeconds: 60 * 5, staleWhileRevalidateSeconds: 60, - keyPrefix: 'oliveyoung-products-v1', + keyPrefix: 'oliveyoung-products-v2', }, () => handleOliveyoungSearchProducts(c), ), @@ -26,11 +27,11 @@ export function registerOliveyoungRoutes(app: Hono<{ Bindings: AppBindings }>): app.get('/api/oliveyoung/stores', async (c) => withEdgeCache( - c.req.url, + oliveyoungCacheKey(c.req.url), { ttlSeconds: 60 * 60 * 24, staleWhileRevalidateSeconds: 60 * 5, - keyPrefix: 'oliveyoung-stores-v1', + keyPrefix: 'oliveyoung-stores-v2', }, () => handleOliveyoungFindStores(c), ), @@ -38,11 +39,11 @@ export function registerOliveyoungRoutes(app: Hono<{ Bindings: AppBindings }>): app.get('/api/oliveyoung/inventory', async (c) => withEdgeCache( - c.req.url, + oliveyoungCacheKey(c.req.url), { ttlSeconds: 60 * 10, staleWhileRevalidateSeconds: 60, - keyPrefix: 'oliveyoung-inventory-v1', + keyPrefix: 'oliveyoung-inventory-v2', }, () => handleOliveyoungCheckInventory(c), ), diff --git a/src/core/registry.ts b/src/core/registry.ts index 920d47fd..100e6582 100644 --- a/src/core/registry.ts +++ b/src/core/registry.ts @@ -4,6 +4,7 @@ * 서비스 프로바이더를 등록하고 MCP 서버에 도구를 연결합니다. */ +import { diagnosticEvent } from '../utils/diagnostics.js'; import type { McpServer } from '@modelcontextprotocol/sdk/server/mcp.js'; import type { ServiceProvider, ServiceFactory } from './interfaces.js'; import type { ServiceInfo, ToolRegistration } from './types.js'; @@ -223,10 +224,12 @@ export class ServiceRegistry { }; server.registerTool(tool.name, metadata as never, async (args) => { + const started = Date.now(); let result: Awaited>; try { result = await tool.handler(args); } catch (error) { + diagnosticEvent({ stage: 'tool', operation: tool.name, outcome: 'error', durationMs: Date.now() - started }); const message = error instanceof ServiceError ? JSON.stringify({ error: { code: error.code, message: error.message }, @@ -239,6 +242,7 @@ export class ServiceRegistry { }; } + diagnosticEvent({ stage: 'tool', operation: tool.name, outcome: result.isError ? 'error' : 'ok', durationMs: Date.now() - started }); const content = result.content.map((item) => ({ type: item.type as 'text', text: item.text, diff --git a/src/index.ts b/src/index.ts index a13a0542..fb6bcca4 100644 --- a/src/index.ts +++ b/src/index.ts @@ -5,6 +5,7 @@ * 다이소, 편의점, 백화점 등 다양한 서비스를 확장할 수 있습니다. */ +import { diagnosticsMiddleware } from './middleware/diagnostics.js'; import { dtryxTransportFromBindings } from './services/dtryx/transport.js'; import { Hono, type Context } from 'hono'; @@ -315,6 +316,8 @@ const handleRootMcpRequest = async (c: Context<{ Bindings: AppBindings }>) => { // Hono 앱 생성 const app = new Hono<{ Bindings: AppBindings }>(); +app.use('*', diagnosticsMiddleware); + // CORS 설정 app.use( '*', @@ -329,7 +332,7 @@ app.use( 'Last-Event-ID', 'mcp-protocol-version', ], - exposeHeaders: ['mcp-session-id', 'mcp-protocol-version'], + exposeHeaders: ['mcp-session-id', 'mcp-protocol-version', 'x-request-id'], }), ); diff --git a/src/middleware/diagnostics.ts b/src/middleware/diagnostics.ts new file mode 100644 index 00000000..4ec80b70 --- /dev/null +++ b/src/middleware/diagnostics.ts @@ -0,0 +1,24 @@ +/** REST와 MCP의 공통 요청 경계를 기록합니다. */ +import type { MiddlewareHandler } from 'hono'; +import { + withDiagnostics, + diagnosticEvent, + diagnosticHeaders, + diagnosticOperation, +} from '../utils/diagnostics.js'; +export const diagnosticsMiddleware: MiddlewareHandler = async (c, next) => + withDiagnostics(async () => { + const start = performance.now(); + try { + await next(); + } finally { + c.header('x-request-id', diagnosticHeaders()['x-request-id']); + diagnosticEvent({ + stage: 'request', + operation: diagnosticOperation(c.req.url), + outcome: c.error || c.res.status >= 400 ? 'error' : 'ok', + status: c.res.status, + durationMs: performance.now() - start, + }); + } + }); diff --git a/src/services/dtryx/transport.ts b/src/services/dtryx/transport.ts index aa490842..43882937 100644 --- a/src/services/dtryx/transport.ts +++ b/src/services/dtryx/transport.ts @@ -1,3 +1,4 @@ +import { diagnosticHeaders } from '../../utils/diagnostics.js'; /** 디트릭스 전용 중계 설정과 인증 전송입니다. */ import { ServiceError } from '../../core/errors.js'; import { createTimeoutController } from '../../utils/http.js'; @@ -66,6 +67,7 @@ export async function requestDtryxRelay( ); } const headers: Record = { + ...diagnosticHeaders(), 'Content-Type': 'application/json', Accept: 'application/json', Authorization: `Bearer ${relayToken}`, diff --git a/src/services/oliveyoung/transport.ts b/src/services/oliveyoung/transport.ts index 25aed178..8157cab9 100644 --- a/src/services/oliveyoung/transport.ts +++ b/src/services/oliveyoung/transport.ts @@ -1,3 +1,4 @@ +import { diagnosticHeaders } from '../../utils/diagnostics.js'; /** 올리브영 무료 직접 요청 및 운영자가 설정한 브라우저 릴레이 전송. */ import { fetchJson } from '../../utils/http.js'; import { toOliveyoungRelayError } from './errors.js'; @@ -51,6 +52,7 @@ export async function requestOliveyoung( } if (!relayToken?.trim()) throw new Error('OY_RELAY_TOKEN이 필요합니다.'); url = `${relayUrl.replace(/\/$/, '')}/v1/oliveyoung/${path.split('/').pop()}`; + Object.assign(headers, diagnosticHeaders()); headers.Authorization = `Bearer ${relayToken}`; const { accessClientId, accessClientSecret } = options; if (accessClientId !== undefined || accessClientSecret !== undefined) { diff --git a/src/utils/diagnostics.ts b/src/utils/diagnostics.ts new file mode 100644 index 00000000..8dec3490 --- /dev/null +++ b/src/utils/diagnostics.ts @@ -0,0 +1,90 @@ +/** 비밀값과 원문 없이 요청 경계를 연결하는 진단 컨텍스트입니다. */ +import { AsyncLocalStorage } from 'node:async_hooks'; +interface DiagnosticContext { + requestId: string; + sampled: boolean; + events: number; +} +const context = new AsyncLocalStorage(); +export interface DiagnosticEvent { + stage: 'request' | 'tool' | 'http' | 'relay'; + outcome: 'ok' | 'error' | 'retry'; + operation?: string; + status?: number; + durationMs?: number; +} +export function withDiagnostics(work: () => T): T { + if (context.getStore()) return work(); + return context.run( + { requestId: crypto.randomUUID(), sampled: Math.random() < 0.01, events: 0 }, + work, + ); +} +export function diagnosticHeaders(): Record { + const current = context.getStore(); + return current ? { 'x-request-id': current.requestId } : {}; +} +export function diagnosticEvent(event: DiagnosticEvent): void { + const current = context.getStore(); + // 요청당 상한으로 재시도/팬아웃 로그가 무한히 늘어나지 않게 합니다. + if (!current || (event.outcome === 'ok' && !current.sampled) || current.events >= 32) return; + current.events++; + console.error( + JSON.stringify({ + event: 'diagnostic', + time: new Date().toISOString(), + requestId: current.requestId, + stage: event.stage, + outcome: event.outcome, + operation: event.operation, + status: event.status, + durationMs: event.durationMs, + }), + ); +} +const services = new Set([ + 'daiso', + 'oliveyoung', + 'dtryx', + 'gs25', + 'cu', + 'seveneleven', + 'emart24', + 'lottemart', + 'cgv', + 'megabox', + 'lottecinema', + 'opinet', + 'places', + 'compare', + 'feedback', + 'health', + 'rate-limit', + 'actions', +]); +const operations = new Set([ + 'products', + 'stores', + 'inventory', + 'movies', + 'theaters', + 'timetable', + 'play-dates', + 'seats', + 'remaining-seats', + 'average', + 'lowest', + 'requests', + 'checks', + 'stats', + 'query', + 'popwords', + 'price', +]); +export function diagnosticOperation(url: string): string { + const parts = new URL(url).pathname.split('/'); + if (parts[1] === 'mcp') return 'mcp'; + if (parts[1] === 'api' && services.has(parts[2]) && operations.has(parts[3])) + return `${parts[2]}.${parts[3]}`; + return 'other'; +} diff --git a/src/utils/http.ts b/src/utils/http.ts index b77f509f..6b8e9f4d 100644 --- a/src/utils/http.ts +++ b/src/utils/http.ts @@ -1,3 +1,4 @@ +import { diagnosticEvent } from './diagnostics.js'; /** * 공용 HTTP 유틸리티 */ @@ -132,6 +133,8 @@ async function requestWithTimeout( for (let attempt = 1; attempt <= maxAttempts; attempt += 1) { const { controller, timeoutId } = createTimeoutController(timeout); let readingResponse = false; + const started = Date.now(); + let responseStatus: number | undefined; try { const response = await fetch(url, { @@ -139,6 +142,8 @@ async function requestWithTimeout( signal: controller.signal, }); + responseStatus = response.status; + diagnosticEvent({ stage: 'http', outcome: response.ok ? 'ok' : 'error', status: response.status, durationMs: Date.now() - started }); if ( retryAllowed && attempt < maxAttempts && @@ -162,6 +167,7 @@ async function requestWithTimeout( readingResponse = true; return await readResponse(response); } catch (error) { + diagnosticEvent({ stage: 'http', outcome: 'error', status: responseStatus, durationMs: Date.now() - started }); if (readingResponse || !retryAllowed || attempt >= maxAttempts) { throw error; } diff --git a/src/utils/oliveyoungCacheKey.ts b/src/utils/oliveyoungCacheKey.ts new file mode 100644 index 00000000..dd0afa4a --- /dev/null +++ b/src/utils/oliveyoungCacheKey.ts @@ -0,0 +1,26 @@ +/** 핸들러가 읽는 query만 캐시 키에 포함하고 동일한 기본값을 합칩니다. */ +const product = { keyword: '', page: '1', size: '20', sort: '01', includeSoldOut: 'false' }; +const location = { lat: '37.5665', lng: '126.978' }; +const defaults: Record> = { + '/api/oliveyoung/products': product, + '/api/oliveyoung/stores': { keyword: '', ...location, pageIdx: '1', limit: '20' }, + '/api/oliveyoung/inventory': { + ...product, + ...location, + storeKeyword: '', + storeLimit: '10', + stockCheckLimit: '5', + }, +}; +export function oliveyoungCacheKey(input: string): string { + const url = new URL(input); + const values = defaults[url.pathname]; + if (!values) return input; + const key = new URL(url.origin + url.pathname); + for (const [name, fallback] of Object.entries({ ...values, timeoutMs: '15000' })) { + key.searchParams.set(name, url.searchParams.get(name) || fallback); + } + const fresh = url.searchParams.get('_healthCheck'); + if (fresh !== null) key.searchParams.set('_healthCheck', fresh); + return key.toString(); +} diff --git a/tests/app/app-daily-rate-limit.test.ts b/tests/app/app-daily-rate-limit.test.ts index 760b4a56..29f71803 100644 --- a/tests/app/app-daily-rate-limit.test.ts +++ b/tests/app/app-daily-rate-limit.test.ts @@ -202,7 +202,7 @@ describe('일일 호출 제한 통합', () => { ]); expect(fixture.idFromName).toHaveBeenLastCalledWith(RATE_LIMIT_METRICS_LEDGER_NAME); expect(fixture.calls[1]?.durableObjectId).toBe(LEDGER_ID); - expect(randomUuidSpy).toHaveBeenCalledTimes(1); + expect(randomUuidSpy).toHaveBeenCalledTimes(2); const ledgerRequest = fixture.calls[1]?.request; expect(ledgerRequest?.method).toBe('POST'); diff --git a/tests/app/app-mcp-client.test.ts b/tests/app/app-mcp-client.test.ts index c78a4697..dda57406 100644 --- a/tests/app/app-mcp-client.test.ts +++ b/tests/app/app-mcp-client.test.ts @@ -155,3 +155,21 @@ it('MCP 올리브영 요청은 운영 바인딩의 Access 자격증명만 사용 expect(mockFetch).toHaveBeenCalledWith('https://relay.example/v1/oliveyoung/product-search-v3',expect.objectContaining({redirect:'manual',headers:expect.objectContaining({'CF-Access-Client-Id':'access-test-id','CF-Access-Client-Secret':'access-test-secret'})})); }finally{await client.close();} }); +it('같은 MCP 세션의 동시 도구 호출도 각각 응답과 릴레이 ID가 연결된다', async()=>{ + const ids:string[]=[];const returned:string[]=[]; + mockFetch.mockImplementation(async (_url,init)=>{ids.push(init.headers['x-request-id']);await Promise.resolve();return Response.json({status:'SUCCESS',data:{}})}); + const client=new Client({name:'trace-test',version:'1'}); + const transport=new StreamableHTTPClientTransport(new URL('https://local.test/mcp'),{fetch:async(url,init)=>{ + const request=new Request(url,init); const body=request.method==='POST'?await request.clone().json():{}; + const response=await app.request(request,undefined,{OY_RELAY_URL:'https://relay.example',OY_RELAY_TOKEN:'test'}); + if(body.method==='tools/call')returned.push(response.headers.get('x-request-id')!);return response; + }}); + await client.connect(transport); + try{await Promise.all(['a','b'].map(keyword=>client.callTool({name:'oliveyoung_search_products',arguments:{keyword}})));expect(new Set(ids).size).toBe(2);expect(ids.sort()).toEqual(returned.sort())}finally{await client.close()} +}); +it('Actions 내부 재호출은 응답과 릴레이의 추적 ID가 같다',async()=>{ + mockFetch.mockImplementation(async()=>Response.json({status:'SUCCESS',data:{}})); + const response=await app.request('/api/actions/query?action=oliveyoungSearchProducts&keyword=lip',undefined,{OY_RELAY_URL:'https://relay.example',OY_RELAY_TOKEN:'test'}); + expect(response.status).toBe(200); + expect(response.headers.get('x-request-id')).toBe(mockFetch.mock.calls[0][1].headers['x-request-id']); +}); diff --git a/tests/app/app-rate-limit-stats-logging.test.ts b/tests/app/app-rate-limit-stats-logging.test.ts index c163e99a..4bff06ac 100644 --- a/tests/app/app-rate-limit-stats-logging.test.ts +++ b/tests/app/app-rate-limit-stats-logging.test.ts @@ -94,7 +94,7 @@ describe('GET /api/rate-limit/stats 안전 로그', () => { expectSafeLog(consoleSpy); }); - it('예상된 인증·query 4xx는 오류 로그를 남기지 않는다', async () => { + it('예상된 인증·query 4xx는 원문 없이 공통 진단만 남긴다', async () => { const fixture = createStatsFixture(); const consoleSpy = vi.spyOn(console, 'error').mockImplementation(() => undefined); @@ -111,6 +111,10 @@ describe('GET /api/rate-limit/stats 안전 로그', () => { expect(unauthorized.status).toBe(401); expect(invalid.status).toBe(400); - expect(consoleSpy).not.toHaveBeenCalled(); + expect(consoleSpy).toHaveBeenCalledTimes(2); + for (const [line] of consoleSpy.mock.calls) { + expect(JSON.parse(line as string)).toMatchObject({ event: 'diagnostic', stage: 'request', operation: 'rate-limit.stats' }); + } + expectSafeLog(consoleSpy); }); }); diff --git a/tests/relay/cache.test.ts b/tests/relay/cache.test.ts new file mode 100644 index 00000000..e98c8f8a --- /dev/null +++ b/tests/relay/cache.test.ts @@ -0,0 +1,28 @@ +import { expect, it } from 'vitest'; +import { createResponseCache, canonicalKey } from '../../scripts/relay/cache.js'; +it('키 순서를 정규화하고 TTL, LRU, 바이트 및 항목 상한을 유지한다', () => { + let now = 0; + const cache = createResponseCache(2, 12, () => now); + expect(canonicalKey('op', { b: 2, a: 1 })).toBe(canonicalKey('op', { a: 1, b: 2 })); + expect(cache.get('a')).toBeUndefined(); + cache.set('a', '123', 10); + cache.set('b', '123', 20); + expect(cache.get('a')).toBe('123'); + cache.set('c', '123', 20); + expect(cache.get('b')).toBeUndefined(); + cache.set('a', '1', 10); + cache.set('oversized', '123456789', 10); + expect(cache.stats()).toMatchObject({ entries: 2, bytes: 6 }); + now = 10; + expect(cache.get('a')).toBeUndefined(); + now = 20; + expect(cache.stats()).toMatchObject({ entries: 0, bytes: 0 }); + cache.set('a', '12345678', 10); + cache.set('b', '1234', 10); + expect(cache.get('a')).toBeUndefined(); +}); +it('기본 캐시도 성공 문자열을 보관한다', () => { + const cache = createResponseCache(); + cache.set('key', '{}', 1000); + expect(cache.get('key')).toBe('{}'); +}); diff --git a/tests/relay/dtryx-events.test.ts b/tests/relay/dtryx-events.test.ts new file mode 100644 index 00000000..f689107c --- /dev/null +++ b/tests/relay/dtryx-events.test.ts @@ -0,0 +1,49 @@ +import { describe, it, expect, vi } from 'vitest'; +import { createDtryxRelay } from '../../scripts/relay/dtryx.js'; +const req = () => + new Request('http://localhost/v1/dtryx/movies', { + method: 'POST', + headers: { authorization: 'Bearer test', 'x-request-id': 'req-1' }, + body: JSON.stringify({ brandCode: 'dtryx', cinemaCode: '000067' }), + }); +describe('디트릭스 실패 단계', () => { + it('한도 실패는 upstream을 실행하지 않고 제한 단계를 기록한다', async () => { + const events: unknown[] = []; + const fetcher = vi.fn(); + const handler = createDtryxRelay('test', { + takeQuota: async () => false, + fetcher, + onEvent: (e) => { + events.push(e); + }, + }); + expect((await handler(req())).status).toBe(429); + expect(events).toMatchObject([{ stage: 'quota', status: 429, requestId: 'req-1' }]); + expect(fetcher).not.toHaveBeenCalled(); + }); + it('원본 실패를 기록하고 기록 함수 예외가 서비스를 깨뜨리지 않는다', async () => { + const events: unknown[] = []; + const handler = createDtryxRelay('test', { + takeQuota: async () => true, + fetcher: vi.fn().mockResolvedValue(new Response('', { status: 403 })), + onEvent: (e) => { + events.push(e); + throw Error('log'); + }, + }); + expect((await handler(req())).status).toBe(502); + expect(events).toMatchObject([{ stage: 'upstream', status: 502 }]); + }); +}); +it('잘못된 ID를 교체하고 비동기 관측 실패를 격리한다', async () => { + const request = req(); + request.headers.set('x-request-id', 'invalid value'); + const handler = createDtryxRelay('test', { + takeQuota: async () => true, + fetcher: vi.fn().mockResolvedValue(Response.json({ RetCode: 'success', Recordset: [] })), + onEvent: async () => { + throw Error('log'); + }, + }); + expect((await handler(request)).status).toBe(200); +}); diff --git a/tests/relay/lifecycle.test.ts b/tests/relay/lifecycle.test.ts index c3926be3..c59ed03a 100644 --- a/tests/relay/lifecycle.test.ts +++ b/tests/relay/lifecycle.test.ts @@ -314,3 +314,14 @@ it('자동 준비 중 팝업 회수 실패는 준비 완료로 보고하지 않 expect(f.launch).toHaveBeenCalledTimes(2); await life.close(); }); +it('브라우저 시작/회수 사유를 기록하고 관측기 실패를 격리한다', async () => { + const f = fixture(); const events: string[] = []; + const life = createBrowserLifecycle(f.launch, event => { events.push(event); if(event==='shutdown') throw Error('log'); }); + await life.start(); await life.close(); expect(events).toEqual(['ready','shutdown']); + const second = createBrowserLifecycle(f.launch, async()=>{throw Error('async log')}); + await second.start(); await second.close(); +}); +it('브라우저 프로세스 실행 실패도 별도 사건으로 기록한다',async()=>{ + const events:string[]=[];const life=createBrowserLifecycle(async()=>{throw Error('launch')},e=>{events.push(e)}); + await expect(life.start()).rejects.toThrow('launch');expect(events).toContain('launch-failed');await life.close(); +}); diff --git a/tests/relay/logging.test.ts b/tests/relay/logging.test.ts new file mode 100644 index 00000000..b11cf3fb --- /dev/null +++ b/tests/relay/logging.test.ts @@ -0,0 +1,238 @@ +import { mkdtemp, readdir, readFile, rm, stat, writeFile, utimes } from 'node:fs/promises'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { afterEach, expect, it, vi } from 'vitest'; +import { createRelayLogger } from '../../scripts/relay/logging.js'; +const dirs: string[] = []; +async function directory() { + const dir = await mkdtemp(join(tmpdir(), 'relay-log-')); + dirs.push(dir); + return dir; +} +afterEach(async () => { + await Promise.all(dirs.splice(0).map((dir) => rm(dir, { recursive: true, force: true }))); +}); +const event = { + stage: 'cache', + operation: 'product-search-v3', + outcome: 'hit', + requestId: 'safe_1', + parentRequestId: 'parent_1', + status: 200, + durationMs: 4, + cache: 'hit', + quotaReason: 'minute', +}; +const space = async () => ({ bavail: 3 * 1024 ** 3, bsize: 1 }); +it('허용 필드만 안전한 권한의 JSONL로 기록한다', async () => { + const dir = await directory(); + const logger = createRelayLogger(dir, { service: 'oliveyoung', statfs: space }); + logger.append({ ...event, token: 'secret', body: { query: 'secret' }, url: 'secret' }); + logger.append({ + stage: 'https://secret', + durationMs: -1, + status: NaN, + requestId: 'bad.id', + time: 'spoof', + }); + await logger.flush(); + const [name] = await readdir(dir); + const lines = (await readFile(join(dir, name), 'utf8')) + .trim() + .split('\n') + .map((line) => JSON.parse(line)); + expect(lines[0]).toMatchObject(event); + expect(Object.keys(lines[1])).toEqual(['time', 'service']); + expect(await readFile(join(dir, name), 'utf8')).not.toContain('secret'); + expect((await stat(dir)).mode & 0o777).toBe(0o700); + expect((await stat(join(dir, name))).mode & 0o777).toBe(0o600); + expect(logger.status()).toMatchObject({ + written: 2, + queued: 0, + errors: 0, + dropped: 0, + lowSpace: false, + }); +}); +it('공간 부족과 쓰기 오류는 요청을 막지 않고 다음 기록에서 복구한다', async () => { + const dir = await directory(); + const statfs = vi + .fn() + .mockResolvedValueOnce({ bavail: 0, bsize: 1 }) + .mockRejectedValueOnce(new Error('ENOSPC')) + .mockImplementation(space); + const logger = createRelayLogger(dir, { service: 'dtryx', statfs }); + logger.append(event); + await logger.flush(); + expect(logger.status()).toMatchObject({ lowSpace: true, dropped: 1 }); + logger.append(event); + await logger.flush(); + expect(logger.status().errors).toBe(1); + logger.append(event); + await logger.flush(); + expect(logger.status()).toMatchObject({ lowSpace: false, written: 1 }); +}); +it('자체 파일만 회전 및 만료 정리하고 재시작 후 총 용량을 지킨다', async () => { + const dir = await directory(); + const now = Date.now(); + const old = join(dir, 'oliveyoung-1000-old.jsonl'); + await writeFile(old, 'old'); + await utimes(old, 0, 0); + await writeFile(join(dir, 'dtryx-1000-other.jsonl'), 'keep'); + await writeFile(join(dir, 'unrelated'), 'keep'); + const options = { + service: 'oliveyoung' as const, + now: () => now, + statfs: space, + maxFileBytes: 300, + maxTotalBytes: 600, + }; + const logger = createRelayLogger(dir, options); + for (let i = 0; i < 8; i++) logger.append(event); + await logger.flush(); + const next = createRelayLogger(dir, options); + next.append(event); + await next.flush(); + const names = await readdir(dir); + expect(names).not.toContain('oliveyoung-1000-old.jsonl'); + expect(names).toContain('unrelated'); + expect(names).toContain('dtryx-1000-other.jsonl'); + const sizes = await Promise.all( + names + .filter((name) => name.startsWith('oliveyoung-')) + .map(async (name) => (await stat(join(dir, name))).size), + ); + expect(sizes.every((size) => size <= 300)).toBe(true); + expect(sizes.reduce((sum, size) => sum + size, 0)).toBeLessThanOrEqual(600); +}); +it('대기열과 이벤트 크기를 제한한다', async () => { + const dir = await directory(); + let release!: () => void; + const gate = new Promise((resolve) => { + release = resolve; + }); + const logger = createRelayLogger(dir, { + service: 'oliveyoung', + statfs: async () => { + await gate; + return space(); + }, + }); + for (let i = 0; i < 260; i++) logger.append(event); + expect(logger.status()).toMatchObject({ queued: 256, dropped: 4 }); + release(); + await logger.flush(); + expect(logger.status()).toMatchObject({ queued: 0, written: 256 }); +}); +it('직렬화·쓰기 실패 및 작은 파일 상한을 안전하게 처리한다', async () => { + const dir = await directory(); + const write = vi.fn().mockRejectedValueOnce(new Error('ENOSPC')).mockResolvedValue(undefined); + const logger = createRelayLogger(dir, { + service: 'oliveyoung', + statfs: space, + appendFile: write, + }); + logger.append( + Object.defineProperty({}, 'stage', { + get() { + throw new Error('secret'); + }, + }), + ); + logger.append(event); + await logger.flush(); + logger.append(event); + await logger.flush(); + expect(logger.status()).toMatchObject({ errors: 2, dropped: 2, written: 1 }); + const tiny = createRelayLogger(dir, { service: 'oliveyoung', statfs: space, maxFileBytes: 1 }); + tiny.append(event); + await tiny.flush(); + expect(tiny.status().dropped).toBe(1); + const total = createRelayLogger(dir, { service: 'oliveyoung', statfs: space, maxTotalBytes: 1 }); + total.append(event); + await total.flush(); + expect(total.status().dropped).toBe(1); +}); +it('기본 파일시스템 공간 검사를 지원한다', async () => { + const logger = createRelayLogger(await directory(), { service: 'dtryx' }); + logger.append(event); + await logger.flush(); + expect(logger.status().written + logger.status().dropped).toBe(1); +}); +it('생성 시간이 같은 파일은 이름 순서로 정리한다', async () => { + const dir = await directory(); + const now = Date.now(); + for (const name of [`oliveyoung-${now}-b.jsonl`, `oliveyoung-${now}-a.jsonl`]) { + await writeFile(join(dir, name), 'x'.repeat(250)); + await utimes(join(dir, name), now / 1000, now / 1000); + } + const logger = createRelayLogger(dir, { + service: 'oliveyoung', + now: () => now, + statfs: space, + maxTotalBytes: 500, + }); + logger.append(event); + await logger.flush(); + expect(await readdir(dir)).not.toContain(`oliveyoung-${now}-a.jsonl`); +}); +it('공간이 부족해도 자체 만료 파일을 먼저 정리한다', async () => { + const dir = await directory(); + const name = 'oliveyoung-1000-expired.jsonl'; + await writeFile(join(dir, name), 'x'); + await utimes(join(dir, name), 0, 0); + const logger = createRelayLogger(dir, { + service: 'oliveyoung', + statfs: async () => ({ bavail: 0, bsize: 1 }), + }); + logger.append(event); + await logger.flush(); + expect(await readdir(dir)).not.toContain(name); + expect(logger.status().lowSpace).toBe(true); +}); +it('자주 갱신된 파일도 생성 후 7일이 되면 삭제한다', async () => { + const dir = await directory(); + let now = Date.now(); + const logger = createRelayLogger(dir, { service: 'oliveyoung', statfs: space, now: () => now }); + logger.append(event); + await logger.flush(); + const [original] = await readdir(dir); + now += 6 * 86400000; + logger.append(event); + await logger.flush(); + expect(await readdir(dir)).toEqual([original]); + await utimes(join(dir, original), now / 1000, now / 1000); + now += 86400000; + logger.append(event); + await logger.flush(); + const names = await readdir(dir); + expect(names).not.toContain(original); + expect(names).toHaveLength(1); +}); +it('예산 잔여량은 유한한 비음수 숫자만 기록한다', async () => { + const dir = await directory(); + const logger = createRelayLogger(dir, { service: 'oliveyoung', statfs: space }); + logger.append({ dailyRemaining: 3000, minuteRemaining: 0, token: 'secret' }); + logger.append({ dailyRemaining: -1, minuteRemaining: Infinity }); + logger.append({ dailyRemaining: 'secret', minuteRemaining: NaN }); + await logger.flush(); + const [name] = await readdir(dir); + const lines = (await readFile(join(dir, name), 'utf8')) + .trim() + .split('\n') + .map((line) => JSON.parse(line)); + expect(lines[0]).toMatchObject({ dailyRemaining: 3000, minuteRemaining: 0 }); + for (const line of lines.slice(1)) expect(Object.keys(line)).toEqual(['time', 'service']); + expect(JSON.stringify(lines)).not.toContain('secret'); +}); +it('기록 이후에도 최소 2GiB의 여유 공간을 보존한다', async () => { + const dir = await directory(); + const logger = createRelayLogger(dir, { + service: 'oliveyoung', + statfs: async () => ({ bavail: 2 * 1024 ** 3, bsize: 1 }), + }); + logger.append(event); + await logger.flush(); + expect(logger.status()).toMatchObject({ lowSpace: true, written: 0, dropped: 1 }); + expect(await readdir(dir)).toEqual([]); +}); diff --git a/tests/relay/observed.test.ts b/tests/relay/observed.test.ts new file mode 100644 index 00000000..182b71a3 --- /dev/null +++ b/tests/relay/observed.test.ts @@ -0,0 +1,52 @@ +import { describe, it, expect, vi } from 'vitest'; +import { observeRelay } from '../../scripts/relay/observed.js'; +describe('릴레이 요청 경계 기록', () => { + it('ID와 상태를 연결하고 허용되지 않은 경로 및 query를 기록하지 않는다', async () => { + const events: unknown[] = []; + const handle = observeRelay( + async () => new Response('private', { status: 429 }), + (e) => events.push(e), + ); + const r = await handle( + new Request('http://localhost/v1/oliveyoung/product-search-v3?secret=private', { + headers: { 'x-request-id': 'req-1' }, + }), + ); + expect(r.headers.get('x-request-id')).toBe('req-1'); + expect(events).toMatchObject([ + { requestId: 'req-1', status: 429, operation: 'product-search-v3', outcome: 'error' }, + ]); + expect(JSON.stringify(events)).not.toContain('private'); + await handle(new Request('http://localhost/private')); + expect(events[1]).toMatchObject({ operation: 'other' }); + }); + it('health 성공은 제외하고 내부 예외와 기록 실패를 안전하게 처리한다', async () => { + const emit = vi.fn(); + await observeRelay( + async () => Response.json({ ok: true }), + emit, + )(new Request('http://localhost/health')); + expect(emit).not.toHaveBeenCalled(); + const fail = observeRelay(async () => { + throw new Error('private'); + }, emit); + await expect(fail(new Request('http://localhost/health'))).rejects.toThrow('private'); + expect(emit).toHaveBeenCalledWith(expect.objectContaining({ status: 500, outcome: 'error' })); + const safe = observeRelay( + async () => new Response(), + () => { + throw new Error(); + }, + ); + expect((await safe(new Request('http://localhost/test'))).status).toBe(200); + }); +}); +it('비동기 기록 실패도 응답을 바꾸지 않는다', async () => { + const handler = observeRelay( + async () => new Response(), + async () => { + throw Error('log'); + }, + ); + expect((await handler(new Request('http://localhost/test'))).status).toBe(200); +}); diff --git a/tests/relay/oliveyoung.test.ts b/tests/relay/oliveyoung.test.ts index 69901245..d8c5254e 100644 --- a/tests/relay/oliveyoung.test.ts +++ b/tests/relay/oliveyoung.test.ts @@ -36,7 +36,9 @@ it('브라우저 오류를 숨기고 동시 요청을 제한한다', async () => const relay = createOliveyoungRelay('test', runner); const first = relay(request()); await vi.waitFor(() => expect(runner).toHaveBeenCalledTimes(1)); - const queued = Array.from({ length: 7 }, () => relay(request())); + const queued = Array.from({ length: 7 }, (_, i) => + relay(request(undefined, JSON.stringify({ goodsNo: String(i) }))), + ); await new Promise((resolve) => setTimeout(resolve, 0)); expect((await relay(request())).status).toBe(503); runner.mockResolvedValue({ status: 'SUCCESS' }); @@ -181,3 +183,223 @@ it('예산 허용 후 요청을 실행하고 잘못된 상태 경로는 거절 ).status, ).toBe(404); }); +it('성공 응답을 캐시하고 캐시 조회는 예산을 사용하지 않는다', async () => { + const runner = vi.fn().mockResolvedValue({ status: 'SUCCESS' }); + const takeQuota = vi.fn().mockResolvedValue(true); + const relay = createOliveyoungRelay('test', runner, { takeQuota }); + expect((await relay(request())).headers.get('x-relay-cache')).toBe('miss'); + expect((await relay(request())).headers.get('x-relay-cache')).toBe('hit'); + expect(takeQuota).toHaveBeenCalledTimes(1); +}); +it('동일 요청을 병합하고 첫 요청 취소가 다른 대기자를 중단하지 않는다', async () => { + let release!: (value: { status: string }) => void; + const runner = vi + .fn() + .mockImplementationOnce( + () => + new Promise((resolve) => { + release = resolve; + }), + ) + .mockResolvedValue({ status: 'SUCCESS' }); + const events: unknown[] = []; + const relay = createOliveyoungRelay('test', runner, { + onEvent: (event) => { + events.push(event); + }, + }); + const first = relay(request(undefined, JSON.stringify({ goodsNo: 'other' }))); + await vi.waitFor(() => expect(runner).toHaveBeenCalledTimes(1)); + const controller = new AbortController(); + const original = relay( + new Request(request(), { + signal: controller.signal, + headers: { authorization: 'Bearer test', 'x-request-id': 'safe-id' }, + }), + ); + await vi.waitFor(() => + expect(events).toContainEqual( + expect.objectContaining({ requestId: 'safe-id', stage: 'cache' }), + ), + ); + const duplicate = relay(request()); + await new Promise((resolve) => setTimeout(resolve, 0)); + controller.abort(); + release({ status: 'SUCCESS' }); + await first; + expect((await original).status).toBe(503); + expect((await duplicate).headers.get('x-relay-cache')).toBe('coalesced'); + expect(runner).toHaveBeenCalledTimes(2); + expect(events).toContainEqual( + expect.objectContaining({ requestId: 'safe-id', stage: 'cache', outcome: 'miss' }), + ); +}); +it('만료된 대기는 실행하지 않고 실패한 응답을 캐시하지 않는다', async () => { + const clock = vi.spyOn(Date, 'now').mockReturnValue(1000); + let release!: (value: { status: string }) => void; + const runner = vi + .fn() + .mockImplementationOnce( + () => + new Promise((resolve) => { + release = resolve; + }), + ) + .mockResolvedValue({ status: 'FAIL' }); + const relay = createOliveyoungRelay('test', runner, { + onEvent: () => { + throw new Error('logging'); + }, + }); + const first = relay(request()); + await vi.waitFor(() => expect(runner).toHaveBeenCalledTimes(1)); + const queued = relay(request(undefined, JSON.stringify({ goodsNo: 'other' }))); + await new Promise((resolve) => setTimeout(resolve, 0)); + clock.mockReturnValue(16000); + release({ status: 'SUCCESS' }); + await first; + expect((await queued).status).toBe(503); + expect(runner).toHaveBeenCalledTimes(1); + clock.mockReturnValue(616000); + expect((await relay(request())).status).toBe(502); + expect((await relay(request())).status).toBe(502); + expect(runner).toHaveBeenCalledTimes(3); + clock.mockRestore(); +}); +it('할당량 사유와 재시도 시간 및 상태를 반환한다', async () => { + const status = { + dailyRemaining: 0, + minuteRemaining: 30, + resetAt: { daily: 86400000, minute: 60000 }, + blockedBy: 'daily' as const, + retryAfter: 99, + }; + const takeQuota = Object.assign(async () => false, { status: () => status }); + const relay = createOliveyoungRelay('test', vi.fn(), { takeQuota, status: () => ({ pages: 0 }) }); + const response = await relay( + new Request(request(), { headers: { authorization: 'Bearer test', 'x-request-id': 'bad.id' } }), + ); + expect(response.headers.get('retry-after')).toBe('99'); + expect(response.headers.get('x-relay-quota-reason')).toBe('daily'); + const health = await relay( + new Request('http://localhost/health', { headers: { authorization: 'Bearer test' } }), + ); + expect(await health.json()).toMatchObject({ quota: status, cache: { entries: 0 } }); +}); +it('비동기 관측 실패도 요청 처리에 영향을 주지 않는다', async () => { + const relay = createOliveyoungRelay('test', vi.fn().mockResolvedValue({ status: 'SUCCESS' }), { + onEvent: async () => { + throw new Error('observer'); + }, + }); + expect((await relay(request())).status).toBe(200); +}); +it('취소된 오래된 요청에 합류한 새 요청은 자기 대기 시간으로 실행한다', async () => { + const clock = vi.spyOn(Date, 'now').mockReturnValue(1000); + let release!: (value: { status: string }) => void; + const runner = vi + .fn() + .mockImplementationOnce( + () => + new Promise((resolve) => { + release = resolve; + }), + ) + .mockResolvedValue({ status: 'SUCCESS' }); + const takeQuota = vi.fn().mockResolvedValue(true); + const relay = createOliveyoungRelay('test', runner, { takeQuota }); + const first = relay(request(undefined, JSON.stringify({ goodsNo: 'block' }))); + await vi.waitFor(() => expect(runner).toHaveBeenCalledTimes(1)); + const old = relay(request()); + await new Promise((resolve) => setTimeout(resolve, 0)); + clock.mockReturnValue(16000); + const fresh = relay(request()); + await new Promise((resolve) => setTimeout(resolve, 0)); + release({ status: 'SUCCESS' }); + expect((await first).status).toBe(200); + expect((await old).status).toBe(503); + expect((await fresh).status).toBe(200); + expect(takeQuota).toHaveBeenCalledTimes(2); + clock.mockRestore(); +}); +it.each([ + [ + 'product-search-v3', + { includeSoldOut: true, keyword: 'x', page: 1, sort: 'x', size: 1 }, + 300000, + ], + ['stock-goods-info-v3', { goodsNo: 'x' }, 600000], + [ + 'find-store', + { + lat: 1, + lon: 1, + pageIdx: 1, + searchWords: '', + pogKeys: '', + serviceKeys: '', + mapLat: 1, + mapLon: 1, + }, + 300000, + ], + [ + 'stock-stores', + { productId: 'x', lat: 1, lon: 1, pageIdx: 1, searchWords: '', mapLat: 1, mapLon: 1 }, + 60000, + ], +])('%s TTL 경계까지 정규화된 입력을 재사용한다', async (operation, body, ttl) => { + const clock = vi.spyOn(Date, 'now').mockReturnValue(1000); + const runner = vi.fn().mockResolvedValue({ status: 'SUCCESS' }); + const relay = createOliveyoungRelay('test', runner); + await relay(request(operation, JSON.stringify(body))); + clock.mockReturnValue(1000 + ttl - 1); + const reversed = Object.fromEntries(Object.entries(body).reverse()); + expect( + (await relay(request(operation, JSON.stringify(reversed)))).headers.get('x-relay-cache'), + ).toBe('hit'); + clock.mockReturnValue(1000 + ttl); + expect((await relay(request(operation, JSON.stringify(body)))).headers.get('x-relay-cache')).toBe( + 'miss', + ); + expect(runner).toHaveBeenCalledTimes(2); + clock.mockRestore(); +}); +it('공유 요청의 부모 ID와 실제 예산 소비를 기록한다', async () => { + const events: unknown[] = []; + let reject!: (reason: Error) => void; + const runner = vi.fn().mockImplementation( + () => + new Promise((_, fail) => { + reject = fail; + }), + ); + const relay = createOliveyoungRelay('test', runner, { + takeQuota: async () => true, + onEvent: (event) => { + events.push(event); + }, + }); + const first = relay( + new Request(request(), { + headers: { authorization: 'Bearer test', 'x-request-id': 'parent-id' }, + }), + ); + await vi.waitFor(() => expect(runner).toHaveBeenCalledTimes(1)); + const child = relay(request()); + await vi.waitFor(() => + expect(events).toContainEqual( + expect.objectContaining({ + stage: 'cache', + outcome: 'coalesced', + parentRequestId: 'parent-id', + }), + ), + ); + expect( + events.filter((event) => (event as { outcome: string }).outcome === 'consumed'), + ).toHaveLength(1); + reject(new Error('upstream')); + expect((await first).status).toBe(502); + expect((await child).status).toBe(502); +}); diff --git a/tests/relay/quota.test.ts b/tests/relay/quota.test.ts index 4de492c9..77a0d115 100644 --- a/tests/relay/quota.test.ts +++ b/tests/relay/quota.test.ts @@ -63,3 +63,46 @@ it('시간이 뒤로 가도 예산을 복원하지 않는다', async () => { expect(await take()).toBe(true); expect(JSON.parse(await readFile(path, 'utf8')).dayCount).toBe(2); }); +it('상태 조회는 원장을 쓰지 않고 현재 창과 재시도 시간을 계산한다', async () => { + const path = await file(); + let now = Date.UTC(2026, 8, 15) + 1000; + const take = await createFileQuota(path, () => now); + expect(take.status()).toMatchObject({ + dailyRemaining: 3000, + minuteRemaining: 30, + blockedBy: null, + retryAfter: 0, + }); + await expect(readFile(path)).rejects.toThrow(); + await Promise.all(Array.from({ length: 30 }, () => take())); + expect(take.status()).toMatchObject({ + dailyRemaining: 2970, + minuteRemaining: 0, + blockedBy: 'minute', + retryAfter: 59, + }); + now += 60000; + expect(take.status().minuteRemaining).toBe(30); + now += 86400000; + expect(take.status().dailyRemaining).toBe(3000); +}); +it('일일 상한과 시계 역행에도 정확한 상태를 제공한다', async () => { + const path = await file(); + const now = Date.UTC(2026, 8, 15); + await writeFile( + path, + JSON.stringify({ + day: Math.floor(now / 86400000), + minute: Math.floor(now / 60000), + dayCount: 3000, + minuteCount: 30, + }), + ); + const take = await createFileQuota(path, () => now - 1000); + expect(take.status()).toMatchObject({ + dailyRemaining: 0, + minuteRemaining: 0, + blockedBy: 'daily', + retryAfter: 86401, + }); +}); diff --git a/tests/utils/diagnostics-integration.test.ts b/tests/utils/diagnostics-integration.test.ts new file mode 100644 index 00000000..08399dd1 --- /dev/null +++ b/tests/utils/diagnostics-integration.test.ts @@ -0,0 +1,57 @@ +import { Hono } from 'hono'; +import { describe, it, expect, vi, afterEach } from 'vitest'; +import { diagnosticsMiddleware } from '../../src/middleware/diagnostics.js'; +import { withDiagnostics } from '../../src/utils/diagnostics.js'; +import { fetchJson } from '../../src/utils/http.js'; +import { requestOliveyoung } from '../../src/services/oliveyoung/transport.js'; +describe('진단 경계 통합', () => { + afterEach(() => { + vi.restoreAllMocks(); + vi.unstubAllGlobals(); + }); + it('REST 실패 응답 ID와 로그를 연결하고 입력 헤더와 query를 기록하지 않는다', async () => { + const log = vi.spyOn(console, 'error').mockImplementation(() => {}); + const app = new Hono(); + app.use('*', diagnosticsMiddleware); + app.get('/api/oliveyoung/products', (c) => c.json({ error: true }, 503)); + const r = await app.request('/api/oliveyoung/products?keyword=private', { + headers: { 'x-request-id': 'private' }, + }); + const event = JSON.parse(log.mock.calls[0][0] as string); + expect(event.requestId).toBe(r.headers.get('x-request-id')); + expect(event.operation).toBe('oliveyoung.products'); + expect(JSON.stringify(log.mock.calls)).not.toContain('private'); + }); + it('HTTP 실패의 상태와 네트워크 실패를 본문 없이 기록한다', async () => { + const log = vi.spyOn(console, 'error').mockImplementation(() => {}); + vi.stubGlobal( + 'fetch', + vi + .fn() + .mockResolvedValueOnce(new Response('private', { status: 429 })) + .mockRejectedValueOnce(new Error('private')), + ); + await withDiagnostics(async () => { + await expect(fetchJson('https://x/?secret=private')).rejects.toThrow(); + await expect(fetchJson('https://x')).rejects.toThrow(); + }); + const rows = log.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(rows.some((r) => r.stage === 'http' && r.status === 429)).toBe(true); + expect( + rows.some((r) => r.stage === 'http' && r.outcome === 'error' && r.status === undefined), + ).toBe(true); + expect(JSON.stringify(rows)).not.toContain('private'); + }); + it('릴레이에 요청 ID를 전달한다', async () => { + const fetch = vi.fn().mockResolvedValue(Response.json({ status: 'SUCCESS' })); + vi.stubGlobal('fetch', fetch); + await withDiagnostics(() => + requestOliveyoung( + '/stock/product-search-v3', + {}, + { relayUrl: 'https://relay.test', relayToken: 'test' }, + ), + ); + expect(fetch.mock.calls[0][1].headers['x-request-id']).toMatch(/^[a-f0-9-]{36}$/); + }); +}); diff --git a/tests/utils/diagnostics.test.ts b/tests/utils/diagnostics.test.ts new file mode 100644 index 00000000..385a2228 --- /dev/null +++ b/tests/utils/diagnostics.test.ts @@ -0,0 +1,61 @@ +import { describe, it, expect, vi, afterEach } from 'vitest'; +import { + withDiagnostics, + diagnosticEvent, + diagnosticHeaders, + diagnosticOperation, +} from '../../src/utils/diagnostics.js'; +describe('요청 진단 컨텍스트', () => { + afterEach(() => vi.restoreAllMocks()); + it('동시 요청 ID를 격리하고 민감값과 임의 필드를 제외한다', async () => { + const log = vi.spyOn(console, 'error').mockImplementation(() => {}); + const ids = await Promise.all( + [1, 2].map(async (n) => + withDiagnostics(async () => { + const first = diagnosticHeaders()['x-request-id']; + await Promise.resolve(); + diagnosticEvent({ + stage: 'http', + outcome: 'error', + operation: 'products', + status: 503, + secret: 'password', + } as never); + expect(diagnosticHeaders()['x-request-id']).toBe(first); + return first + n; + }), + ), + ); + expect(ids[0]).not.toBe(ids[1]); + expect(log).toHaveBeenCalledTimes(2); + expect(JSON.stringify(log.mock.calls)).not.toContain('password'); + expect(diagnosticHeaders()).toEqual({}); + }); + it('컨텍스트 밖에서는 기록하지 않고 성공은 샘플링한다', async () => { + const log = vi.spyOn(console, 'error').mockImplementation(() => {}); + diagnosticEvent({ stage: 'http', outcome: 'error' }); + vi.spyOn(Math, 'random').mockReturnValue(0.5); + await withDiagnostics(async () => diagnosticEvent({ stage: 'http', outcome: 'ok' })); + expect(log).not.toHaveBeenCalled(); + vi.spyOn(Math, 'random').mockReturnValue(0); + await withDiagnostics(async () => + diagnosticEvent({ stage: 'http', outcome: 'ok', durationMs: 12 }), + ); + expect(log).toHaveBeenCalledTimes(1); + }); + it('정해진 API 경로만 식별하고 query와 임의 경로를 기록하지 않는다', () => { + expect(diagnosticOperation('https://x/api/oliveyoung/products?keyword=secret')).toBe( + 'oliveyoung.products', + ); + expect(diagnosticOperation('https://x/mcp')).toBe('mcp'); + expect(diagnosticOperation('https://x/secret')).toBe('other'); + }); +}); +it('내부 API 재호출은 바깥 요청 ID를 유지한다', async () => { + await withDiagnostics(async () => { + const parent = diagnosticHeaders()['x-request-id']; + await withDiagnostics(async () => { + expect(diagnosticHeaders()['x-request-id']).toBe(parent); + }); + }); +}); diff --git a/tests/utils/oliveyoungCacheKey.test.ts b/tests/utils/oliveyoungCacheKey.test.ts new file mode 100644 index 00000000..4988ae56 --- /dev/null +++ b/tests/utils/oliveyoungCacheKey.test.ts @@ -0,0 +1,24 @@ +import { describe, it, expect } from 'vitest'; +import { oliveyoungCacheKey } from '../../src/utils/oliveyoungCacheKey.js'; +describe('올리브영 캐시 키', () => { + it('무관 query를 제거하고 명시 기본값을 합친다', () => { + const base = 'https://x/api/oliveyoung/products?keyword=lip'; + expect(oliveyoungCacheKey(base)).toBe( + oliveyoungCacheKey(base + '&page=1&size=20&includeSoldOut=false&unused=nonce'), + ); + }); + it('실제 검색조건과 강제 점검은 분리한다', () => { + const base = 'https://x/api/oliveyoung/products?keyword=lip'; + expect(oliveyoungCacheKey(base)).not.toBe(oliveyoungCacheKey(base + '&_healthCheck=123')); + expect(oliveyoungCacheKey(base)).not.toBe(oliveyoungCacheKey(base + '&size=1')); + }); + it('매장과 재고 기본값, 첫 query값 및 알 수 없는 경로를 보존한다', () => { + for (const route of ['stores', 'inventory']) { + const base = `https://x/api/oliveyoung/${route}?keyword=lip`; + expect(oliveyoungCacheKey(base)).toBe( + oliveyoungCacheKey(base + '&lat=37.5665&lng=126.978&keyword=ignored'), + ); + } + expect(oliveyoungCacheKey('https://x/other?a=1')).toBe('https://x/other?a=1'); + }); +}); diff --git a/vitest.config.ts b/vitest.config.ts index a7a62992..8727f413 100644 --- a/vitest.config.ts +++ b/vitest.config.ts @@ -30,7 +30,7 @@ export default defineConfig({ reporter: ['text', 'text-summary', 'html', 'json'], // 커버리지 대상 파일 - include: ['src/**/*.ts', 'scripts/relay/oliveyoung.ts', 'scripts/relay/dtryx.ts', 'scripts/relay/browser.ts', 'scripts/relay/lifecycle.ts', 'scripts/relay/ownership.ts', 'scripts/relay/guard-controller.ts', 'scripts/relay/guard-runtime.ts', 'scripts/relay/supervisor.ts', 'scripts/relay/quota.ts', 'scripts/relay/browser-environment.ts'], + include: ['src/**/*.ts', 'scripts/relay/cache.ts', 'scripts/relay/logging.ts', 'scripts/relay/observed.ts', 'scripts/relay/oliveyoung.ts', 'scripts/relay/dtryx.ts', 'scripts/relay/browser.ts', 'scripts/relay/lifecycle.ts', 'scripts/relay/ownership.ts', 'scripts/relay/guard-controller.ts', 'scripts/relay/guard-runtime.ts', 'scripts/relay/supervisor.ts', 'scripts/relay/quota.ts', 'scripts/relay/browser-environment.ts'], // 커버리지 제외 파일 exclude: [ diff --git a/wrangler.toml b/wrangler.toml index 9c7ae226..b0fd8174 100644 --- a/wrangler.toml +++ b/wrangler.toml @@ -1,12 +1,18 @@ name = "daiso-mcp" main = "src/index.ts" compatibility_date = "2025-01-23" +compatibility_flags = ["nodejs_als"] [vars] HEALTH_CHECK_BASE_URL = "https://daiso-mcp.hmmhmmhm.workers.dev" [observability] -enabled = false +enabled = true + +[observability.logs] +enabled = true +head_sampling_rate = 1 +invocation_logs = false [[durable_objects.bindings]] name = "DAILY_RATE_LIMITER"