From 3be6fa408d895ffe909431e5edbc3ab9666d45da Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EC=98=A4=EC=98=81=ED=9B=88?= <102127984+oyeonghun@users.noreply.github.com> Date: Sat, 10 Oct 2026 15:24:08 +0900 Subject: [PATCH] =?UTF-8?q?Fix:=20=EC=9D=B4=EB=B2=A4=ED=8A=B8=C2=B7?= =?UTF-8?q?=ED=99=9C=EB=8F=99=20=EC=8B=9C=EA=B0=81=EC=9D=84=20=EB=84=A3?= =?UTF-8?q?=EC=9D=80=20=EC=88=9C=EA=B0=84(clock=5Ftimestamp)=EC=9C=BC?= =?UTF-8?q?=EB=A1=9C=20=E2=80=94=20=EB=A8=BC=EC=A0=80=20BEGIN=ED=95=9C=20?= =?UTF-8?q?=ED=8A=B8=EB=9E=9C=EC=9E=AD=EC=85=98=EC=9D=98=20=EC=A7=80?= =?UTF-8?q?=EC=8B=9C=EA=B0=80=20=ED=94=84=EB=A1=9C=EC=A0=9D=ED=8A=B8=20?= =?UTF-8?q?=EC=8B=9C=EC=9E=91=EB=B3=B4=EB=8B=A4=20=EC=95=9E=EC=97=90=20?= =?UTF-8?q?=EC=A0=95=EB=A0=AC=EB=90=98=EB=8D=98=20=EA=B2=83=20(019)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - now()는 BEGIN 시각이라 READ COMMITTED에서 뒤에 커밋된 변화를 읽고 남긴 이벤트가 원인보다 과거 시각을 받았다. 룸 피드 테스트가 CI에서 가끔 '실행해 주세요'를 '프로젝트를 시작합니다'보다 앞에 냈다. - 같은 모양(먼저 연 트랜잭션 A, 그 사이 커밋된 B)을 고정하는 테스트 — now()면 실패, clock_timestamp()면 통과를 확인. - 룸 테스트 준비 단계는 태스크 생성 신호를 기다린 뒤 시작한다. Co-Authored-By: Claude Opus 5.5 --- CLAUDE.md | 3 ++ docs/erd.dbml | 4 +-- migrations/019_event_clock_timestamp.sql | 18 ++++++++++ tests/rooms.test.ts | 42 ++++++++++++++++++++++-- 4 files changed, 62 insertions(+), 5 deletions(-) create mode 100644 migrations/019_event_clock_timestamp.sql diff --git a/CLAUDE.md b/CLAUDE.md index 41c0b2d..84ef13a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -132,6 +132,9 @@ await withTransaction(async (tx) => { }) ``` +`events.ts`(와 `agent_activity.ts`)는 `clock_timestamp()` — **넣은 순간**이다(019). `now()`(BEGIN 시각)로 되돌리지 말 것: 먼저 BEGIN한 트랜잭션이 뒤에 커밋된 변화를 읽고 남긴 이벤트가 +원인보다 과거 시각을 받아, 룸 피드에서 "실행해 주세요"가 "프로젝트를 시작합니다"보다 앞에 나왔다(CI에서 가끔). 시각으로 순서를 매기는 곳(피드·리플레이)이 이 성질에 기댄다. + `on_behalf_of`는 NOT NULL이고 절대 비울 수 없다(모든 행동은 사람에게 귀속된다는 원칙의 구현체). 시스템이 주체면 `'system:planner'`처럼 명시적 문자열을 쓴다 — 빈 문자열이나 `'system'` 같은 모호한 값 금지. events는 append-only로, UPDATE/DELETE하지 않는다. 조직에 들기 전의 행동(가입, 연결 키 교체, CLI 연결)은 `orgId: null`로 기록한다(003에서 `events.org_id` nullable). `orgId`는 생략할 수 없는 필수 인자라 호출부가 의식적으로 `null`을 고르게 되어 있다. **비밀값(연결 키·토큰·비밀번호)은 payload에 절대 넣지 않는다** — events는 지워지지 않는다. diff --git a/docs/erd.dbml b/docs/erd.dbml index 8c9f55c..0e9875e 100644 --- a/docs/erd.dbml +++ b/docs/erd.dbml @@ -625,7 +625,7 @@ Table agent_activity { agent_id uuid [not null] kind text [not null, note: 'read | edit | write | run | search | other'] target text [not null, note: '작업공간 기준 경로 또는 명령 첫 줄, 1~300자'] - ts timestamptz [not null, default: `now()`] + ts timestamptz [not null, default: `clock_timestamp()`, note: '★ 019'] indexes { (project_id, id) @@ -692,7 +692,7 @@ Table events { latency_ms integer path_violation boolean [note: 'M5′'] owner_role text - ts timestamptz [not null, default: `now()`] + ts timestamptz [not null, default: `clock_timestamp()`, note: '★ 019: 넣은 순간. now()(BEGIN 시각)면 뒤에 커밋된 변화를 보고 남긴 이벤트가 원인보다 앞선다'] indexes { (org_id, id) diff --git a/migrations/019_event_clock_timestamp.sql b/migrations/019_event_clock_timestamp.sql new file mode 100644 index 0000000..fa64b71 --- /dev/null +++ b/migrations/019_event_clock_timestamp.sql @@ -0,0 +1,18 @@ +-- Up Migration + +-- 이벤트·활동 시각을 트랜잭션 시작 시각(now())이 아니라 **행을 넣은 순간**(clock_timestamp())으로 찍는다. +-- +-- now()는 BEGIN 시각이다. READ COMMITTED에서는 문장마다 그때까지 커밋된 상태를 보므로, 먼저 BEGIN한 트랜잭션이 +-- 뒤에 커밋된 변화를 읽고 그 결과로 이벤트를 남기면 원인보다 **과거 시각**을 받는다. 실제로 "실행해 주세요"(TASK_DISPATCHED — +-- 시작된 프로젝트를 보고 계산한다)가 "프로젝트를 시작합니다"(PROJECT_STARTED)보다 앞에 정렬되어 룸 피드 테스트가 가끔 깨졌다. +-- clock_timestamp()면 다른 트랜잭션의 커밋을 보고 넣은 행은 항상 그 커밋보다 뒤 시각이다. 같은 트랜잭션 안의 행도 넣은 순서대로 시각이 갈린다. +-- +-- 이미 쌓인 행은 고치지 않는다(events는 append-only). + +ALTER TABLE events ALTER COLUMN ts SET DEFAULT clock_timestamp(); +ALTER TABLE agent_activity ALTER COLUMN ts SET DEFAULT clock_timestamp(); + +-- Down Migration + +ALTER TABLE agent_activity ALTER COLUMN ts SET DEFAULT now(); +ALTER TABLE events ALTER COLUMN ts SET DEFAULT now(); diff --git a/tests/rooms.test.ts b/tests/rooms.test.ts index e76831e..fe62913 100644 --- a/tests/rooms.test.ts +++ b/tests/rooms.test.ts @@ -2,7 +2,8 @@ import type { Server } from 'node:http'; import type { AddressInfo } from 'node:net'; import { afterAll, beforeAll, beforeEach, describe, expect, it } from 'vitest'; import { createApp } from '../src/app.js'; -import { pool } from '../src/config/db.js'; +import { appendEvent } from '../src/domain/events/append.js'; +import { pool, withTransaction } from '../src/config/db.js'; import { connectAgent } from '../src/domain/agent/service.js'; import { login, signup } from '../src/domain/auth/service.js'; import { createTask } from '../src/domain/authoring/service.js'; @@ -11,6 +12,7 @@ import { acceptInvite, createInvite } from '../src/domain/invite/service.js'; import { createOrganization } from '../src/domain/org/service.js'; import { assignMember, createProject, startProject } from '../src/domain/project/service.js'; import { connectRepos } from '../src/domain/repo/service.js'; +import { DISPATCHER } from '../src/domain/room/dispatch.js'; import { gitMirrorInspector, setCommitInspector } from '../src/domain/verification/commit-inspector.js'; import { sweepUnresponsiveClaims } from '../src/domain/task/stall.js'; import { assignRootOwner } from './fixtures.js'; @@ -61,7 +63,7 @@ async function account(loginId: string) { } // 대표, BE·FE 팀원(각자 에이전트), BE·FE 태스크 하나씩. 시작까지 해 둔다. -async function world() { +async function world(options: { started?: boolean } = {}) { const rep = await account('rep'); const { orgId } = await createOrganization(rep.userId, 'Acme'); const be = await account('be-dev'); @@ -81,7 +83,9 @@ async function world() { await assignMember(actor, projectId, feAgent.agentId, 'FRONTEND'); const beTask = await createTask(rep.userId, projectId, { title: 'T-1 가입 API', teamRole: 'BACKEND', kind: 'INTEGRATION', repoId: repo!.id, specId: null, dependsOn: [] }); const feTask = await createTask(rep.userId, projectId, { title: 'T-2 가입 화면', teamRole: 'FRONTEND', kind: 'INTEGRATION', repoId: repo!.id, specId: null, dependsOn: [] }); - await startProject(actor, projectId); + // 태스크 생성의 신호(tasksChanged → 지시 기록)가 끝난 뒤에 시작한다 — 겹치는 경우는 아래 '이벤트 시각' 테스트가 따로 고정한다. + await drainTasksChanged(); + if (options.started !== false) await startProject(actor, projectId); await drainTasksChanged(); // 배정 뒤 재발급해야 토큰에 project_id가 담긴다. const refresh = async (refreshToken: string) => @@ -102,6 +106,38 @@ async function feed(token: string, projectId: string, role: string, query = ''): return { status: res.status, messages: (res.data.messages ?? []) as Msg[], nextBefore: (res.data.nextBefore ?? null) as string | null }; } +describe('이벤트 시각 (019)', () => { + // 지시 기록(recordDispatches)은 신호를 받아 별도 트랜잭션에서 "지금 가져갈 수 있는 태스크"를 계산한다. 그 트랜잭션이 시작보다 먼저 + // BEGIN했어도 READ COMMITTED라 계산 문장은 커밋된 시작을 본다 — now()(BEGIN 시각)였을 때 지시가 시작보다 앞에 정렬되어 CI에서 가끔 깨졌다. + // 실제 지시 기록과 경합하지 않도록 같은 모양을 직접 만든다: 먼저 연 트랜잭션 A, 그 사이 커밋된 B, A가 B 뒤에 넣은 이벤트. + it('먼저 BEGIN한 트랜잭션이 뒤에 커밋된 이벤트를 보고 넣은 이벤트는 그보다 뒤 시각이다', async () => { + const w = await world({ started: false }); + const event = (type: 'PROJECT_STARTED' | 'TASK_DISPATCHED') => ({ + orgId: w.orgId, + projectId: w.projectId, + type, + onBehalfOf: DISPATCHER, + payload: { taskId: w.beTaskId, marker: 'clock' }, + }); + const a = await pool.connect(); + try { + await a.query('BEGIN'); + await a.query('SELECT 1'); // 트랜잭션 시작 시각이 여기서 정해진다 + await withTransaction(async (b) => appendEvent(b, event('PROJECT_STARTED'))); + await new Promise((r) => setTimeout(r, 5)); + await appendEvent(a, event('TASK_DISPATCHED')); + await a.query('COMMIT'); + } catch (err) { + await a.query('ROLLBACK'); + throw err; + } finally { + a.release(); + } + const { rows } = await testPool.query(`SELECT type FROM events WHERE payload->>'marker' = 'clock' ORDER BY ts`); + expect(rows.map((r) => r.type)).toEqual(['PROJECT_STARTED', 'TASK_DISPATCHED']); + }); +}); + describe('룸 피드 — 실행해 주세요부터 검증 결과까지', () => { it('BE 룸에 서버 지시·수령·실행·도구 사용·제출·검증이 순서대로 쌓인다(최신부터)', async () => { const w = await world();