Release: 이벤트 시각 clock_timestamp (019)

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는 지워지지 않는다.

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)

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();

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();