diff --git a/app/game-engine/src/lifecycle/databaseTurnDaemonLease.ts b/app/game-engine/src/lifecycle/databaseTurnDaemonLease.ts index 069936c1..81e58276 100644 --- a/app/game-engine/src/lifecycle/databaseTurnDaemonLease.ts +++ b/app/game-engine/src/lifecycle/databaseTurnDaemonLease.ts @@ -184,6 +184,7 @@ export class DatabaseTurnDaemonLease { if (!token || this.lost) { throw this.getLossError(); } + // CURRENT_TIMESTAMP는 transaction 시작에 고정되어 VM 정지 중 만료를 놓친다. const db = transaction ?? this.db; const rows = await db.$queryRaw(GamePrisma.sql` SELECT "profile", "owner_id", "fencing_epoch" @@ -192,7 +193,7 @@ export class DatabaseTurnDaemonLease { "profile" = ${token.profile} AND "owner_id" = ${token.ownerId} AND "fencing_epoch" = ${token.fencingEpoch} - AND "lease_until" > CURRENT_TIMESTAMP AT TIME ZONE 'UTC' + AND "lease_until" > clock_timestamp() AT TIME ZONE 'UTC' FOR UPDATE `); if (rows.length === 0) { diff --git a/app/game-engine/src/lifecycle/turnDaemonLifecycle.ts b/app/game-engine/src/lifecycle/turnDaemonLifecycle.ts index 4c817c54..cddf1914 100644 --- a/app/game-engine/src/lifecycle/turnDaemonLifecycle.ts +++ b/app/game-engine/src/lifecycle/turnDaemonLifecycle.ts @@ -240,7 +240,8 @@ export class TurnDaemonLifecycle { const wallDeadline = await this.stateStore.projectGameDeadline?.(nextRunTime); const command = await this.controlQueue.waitFor( - Math.max(0, wallDeadline ? wallDeadline.getTime() - nowMs : nextTurnMs - gameNowMs) + // 벽시계가 뒤로 이동해도 다음 턴까지 장시간 잠들지 않고 lease/gate를 다시 확인한다. + Math.min(1000, Math.max(0, wallDeadline ? wallDeadline.getTime() - nowMs : nextTurnMs - gameNowMs)) ); if (command) { await this.handleCommand(command); diff --git a/app/game-engine/src/turn/cli.ts b/app/game-engine/src/turn/cli.ts index c5f04c56..7f2f400c 100644 --- a/app/game-engine/src/turn/cli.ts +++ b/app/game-engine/src/turn/cli.ts @@ -6,6 +6,7 @@ import { resolveDatabaseUrl } from '../scenario/databaseUrl.js'; import { createTurnDaemonRuntime } from './turnDaemon.js'; import { createTurnDaemonMemoryReporter } from './turnDaemonMemoryReporter.js'; import { createGatewayProfileGate } from './gatewayProfileGate.js'; +import { retryTurnDaemonLeaseStartup } from './leaseStartupRetry.js'; import { TurnDaemonLeaseUnavailableError } from '../lifecycle/databaseTurnDaemonLease.js'; export interface TurnDaemonCliOptions { @@ -79,19 +80,21 @@ export const runTurnDaemonCli = async (options: TurnDaemonCliOptions = {}): Prom } const gameClockMode = rawGameClockMode as GameClockMode | undefined; - const runtime = await createTurnDaemonRuntime({ - profile, - profileName, - databaseUrl, - gatewayDatabaseUrl, - defaultBudget: budget, - tickMinutes, - schedule: options.schedule, - enableDatabaseFlush, - pauseGateIntervalMs, - adminActionIntervalMs, - gameClockMode, - }).catch(async (error: unknown) => { + const runtime = await retryTurnDaemonLeaseStartup(() => + createTurnDaemonRuntime({ + profile, + profileName, + databaseUrl, + gatewayDatabaseUrl, + defaultBudget: budget, + tickMinutes, + schedule: options.schedule, + enableDatabaseFlush, + pauseGateIntervalMs, + adminActionIntervalMs, + gameClockMode, + }) + ).catch(async (error: unknown) => { // 중복 starter가 정상 owner를 멈추면 안 된다. 그 밖의 초기화 실패는 // lifecycle hook이 아직 없으므로 여기서 별도로 관리자에게 기록한다. if (!(error instanceof TurnDaemonLeaseUnavailableError)) { @@ -103,7 +106,7 @@ export const runTurnDaemonCli = async (options: TurnDaemonCliOptions = {}): Prom incidentContext: () => ({ stage: 'startup' }), }); try { - await gate.markPaused(error); + await gate.reportFailure(error); } finally { await gate.close(); } diff --git a/app/game-engine/src/turn/gatewayProfileGate.ts b/app/game-engine/src/turn/gatewayProfileGate.ts index f249b092..fc8567e1 100644 --- a/app/game-engine/src/turn/gatewayProfileGate.ts +++ b/app/game-engine/src/turn/gatewayProfileGate.ts @@ -4,6 +4,8 @@ import { randomUUID } from 'node:crypto'; import { describeRuntimeError, gatewayProfileCapabilities, type GatewayProfileStatus } from '@sammo-ts/common'; import { createGatewayPostgresConnector } from '@sammo-ts/infra'; +import { TurnDaemonLeaseLostError } from '../lifecycle/databaseTurnDaemonLease.js'; + export interface GatewayProfileGateOptions { databaseUrl: string; gatewayDatabaseUrl?: string; @@ -15,7 +17,7 @@ export interface GatewayProfileGateOptions { export interface GatewayProfileGate { shouldPause(): Promise; isExplicitlyPaused(): boolean; - markPaused(error?: unknown): Promise; + reportFailure(error?: unknown): Promise; close(): Promise; } @@ -29,6 +31,7 @@ export const createGatewayProfileGate = async (options: GatewayProfileGateOption }); await connector.connect(); const prisma = connector.prisma; + const reportedLeaseErrors = new WeakSet(); let lastCheckedAt = 0; let cachedPause = false; let cachedStatus: GatewayProfileStatus | null = null; @@ -60,26 +63,38 @@ export const createGatewayProfileGate = async (options: GatewayProfileGateOption lastCheckedAt = now; return cachedPause; }, - async markPaused(error?: unknown): Promise { - cachedPause = true; - cachedStatus = 'PAUSED'; - lastCheckedAt = performance.now(); + async reportFailure(error?: unknown): Promise { + // VM 정지/시계 보정으로 lease를 잃은 실행자는 종료하고 새 owner가 + // DB를 다시 읽는다. 운영자의 RUNNING/PAUSED/STOPPED 의도는 덮어쓰지 않는다. + const recoverable = error instanceof TurnDaemonLeaseLostError; + if (recoverable && reportedLeaseErrors.has(error)) return; + if (!recoverable) { + cachedPause = true; + cachedStatus = 'PAUSED'; + lastCheckedAt = performance.now(); + } const failure = error ? describeRuntimeError(error) : null; const message = failure?.message ?? null; try { await prisma.$transaction(async (tx) => { - const updated = await tx.gatewayProfile.updateMany({ - where: { - profileName: options.profileName, - status: { in: [...PROFILE_STATUSES_MARKABLE_AS_PAUSED] }, - OR: [{ status: { not: 'PAUSED' } }, { lastError: { not: message } }, { lastError: null }], - }, - data: { - status: 'PAUSED', - lastError: message, - }, - }); - if (updated.count && failure) { + const updated = recoverable + ? null + : await tx.gatewayProfile.updateMany({ + where: { + profileName: options.profileName, + status: { in: [...PROFILE_STATUSES_MARKABLE_AS_PAUSED] }, + OR: [ + { status: { not: 'PAUSED' } }, + { lastError: { not: message } }, + { lastError: null }, + ], + }, + data: { + status: 'PAUSED', + lastError: message, + }, + }); + if ((recoverable || updated?.count) && failure) { // 상태와 이력을 함께 commit한다. 재개가 lastError를 지워도 // 당시 원인과 실행 좌표는 관리자 감사 저장소에 남는다. await tx.adminAuditEvent.create({ @@ -95,11 +110,16 @@ export const createGatewayProfileGate = async (options: GatewayProfileGateOption outcome: 'FAILED', errorCode: failure.code, errorMessage: failure.message, - summary: { frames: failure.frames, ...options.incidentContext?.() }, + summary: { + frames: failure.frames, + ...options.incidentContext?.(), + recovery: recoverable ? 'RESTART' : 'OPERATOR', + }, }, }); } }); + if (recoverable) reportedLeaseErrors.add(error); } catch { if (failure) console.error('[turn-daemon] failed to persist runtime incident', failure); return; diff --git a/app/game-engine/src/turn/leaseStartupRetry.ts b/app/game-engine/src/turn/leaseStartupRetry.ts new file mode 100644 index 00000000..084306d7 --- /dev/null +++ b/app/game-engine/src/turn/leaseStartupRetry.ts @@ -0,0 +1,23 @@ +import { setTimeout } from 'node:timers/promises'; + +import { TurnDaemonLeaseUnavailableError } from '../lifecycle/databaseTurnDaemonLease.js'; + +// 역방향 시계 보정 또는 기존 owner의 정상 종료를 기다리는 동안 PM2의 +// 짧은 시작 실패 횟수를 소진하지 않는다. 매번 새 runtime/DB snapshot을 만든다. +export const retryTurnDaemonLeaseStartup = async ( + create: () => Promise, + wait: () => Promise = () => setTimeout(2000) +): Promise => { + let attempts = 0; + for (;;) { + try { + return await create(); + } catch (error) { + if (!(error instanceof TurnDaemonLeaseUnavailableError)) throw error; + if (attempts++ % 15 === 0) { + console.info('[turn-daemon] waiting for the active lease owner; startup will retry.'); + } + await wait(); + } + } +}; diff --git a/app/game-engine/src/turn/turnDaemon.ts b/app/game-engine/src/turn/turnDaemon.ts index b291cff2..7017bb33 100644 --- a/app/game-engine/src/turn/turnDaemon.ts +++ b/app/game-engine/src/turn/turnDaemon.ts @@ -942,7 +942,7 @@ const createTurnDaemonRuntimeWithLease = async ( ...dbHooks.hooks, onRunError: async (error) => { await dbHooks.hooks.onRunError?.(error); - await gatewayGate?.markPaused(error); + await gatewayGate?.reportFailure(error); if (!turnDaemonLease?.isLost() && world.getGameClockState().phase === 'RUNNING') { // 같은 command batch의 다음 가입도 정지된 시각을 보게 한다. await dbHooks.prepareRealtimeRecovery({ paused: true }); @@ -974,7 +974,7 @@ const createTurnDaemonRuntimeWithLease = async ( } else if (reservedTurnStoreHandle) { hooks = { onRunError: async (error) => { - await gatewayGate?.markPaused(error); + await gatewayGate?.reportFailure(error); }, }; close = async () => { @@ -985,7 +985,7 @@ const createTurnDaemonRuntimeWithLease = async ( } else if (gatewayGate) { hooks = { onRunError: async (error) => { - await gatewayGate?.markPaused(error); + await gatewayGate?.reportFailure(error); }, }; close = async () => { diff --git a/app/game-engine/test/gatewayRuntimeAction.integration.test.ts b/app/game-engine/test/gatewayRuntimeAction.integration.test.ts index 97fde950..63f4ebea 100644 --- a/app/game-engine/test/gatewayRuntimeAction.integration.test.ts +++ b/app/game-engine/test/gatewayRuntimeAction.integration.test.ts @@ -3,6 +3,7 @@ import { afterAll, beforeAll, describe, expect, it, vi } from 'vitest'; import { createGatewayPostgresConnector, type GatewayPrismaClient } from '@sammo-ts/infra'; import { createGatewayAdminActionConsumer } from '../src/turn/gatewayAdminActions.js'; +import { TurnDaemonLeaseLostError } from '../src/lifecycle/databaseTurnDaemonLease.js'; import { createGatewayProfileGate } from '../src/turn/gatewayProfileGate.js'; const databaseUrl = process.env.GATEWAY_RUNTIME_ACTION_DATABASE_URL; @@ -111,6 +112,36 @@ integration('gateway runtime action consumer', () => { expect(onActionApplied).toHaveBeenCalledTimes(1); }); + it.each(['RUNNING', 'PREOPEN', 'PAUSED', 'STOPPED', 'COMPLETED'] as const)( + 'preserves %s and its operator error when a lease-lost owner reports failure', + async (status) => { + await db.gatewayProfile.update({ where: { profileName }, data: { status, lastError: 'operator context' } }); + const before = await db.adminAuditEvent.count({ where: { profileName, action: 'runtime.failure' } }); + const gate = await createGatewayProfileGate({ databaseUrl: databaseUrl!, profileName, cacheMs: 0 }); + try { + const paused = await gate.shouldPause(); + const error = new TurnDaemonLeaseLostError(profileName, 'simulated VM resume'); + await gate.reportFailure(error); + await gate.reportFailure(error); + expect(await db.gatewayProfile.findUniqueOrThrow({ where: { profileName } })).toMatchObject({ + status, + lastError: 'operator context', + }); + expect(await gate.shouldPause()).toBe(paused); + expect(await db.adminAuditEvent.count({ where: { profileName, action: 'runtime.failure' } })).toBe( + before + 1 + ); + const incident = await db.adminAuditEvent.findFirstOrThrow({ + where: { profileName, errorCode: 'TurnDaemonLeaseLostError' }, + orderBy: { createdAt: 'desc' }, + }); + expect(incident.summary).toMatchObject({ recovery: 'RESTART' }); + } finally { + await gate.close(); + } + } + ); + it('does not overwrite a terminal operator status while reporting a daemon error', async () => { const existingIncidents = await db.adminAuditEvent.count({ where: { profileName, action: 'runtime.failure' } }); const gate = await createGatewayProfileGate({ @@ -123,15 +154,15 @@ integration('gateway runtime action consumer', () => { where: { profileName }, data: { status: 'RUNNING', lastError: null }, }); - await gate.markPaused(new Error('running failure')); + await gate.reportFailure(new Error('running failure')); expect(await db.gatewayProfile.findUniqueOrThrow({ where: { profileName } })).toMatchObject({ status: 'PAUSED', lastError: 'running failure', }); - await gate.markPaused(new Error('running failure')); + await gate.reportFailure(new Error('running failure')); const incidents = await db.adminAuditEvent.findMany({ where: { profileName, action: 'runtime.failure' } }); expect(incidents).toHaveLength(existingIncidents + 1); - expect(incidents[0]).toMatchObject({ + expect(incidents.find((incident) => incident.errorMessage === 'running failure')).toMatchObject({ credentialKind: 'DAEMON', errorCode: 'Error', errorMessage: 'running failure', @@ -146,7 +177,7 @@ integration('gateway runtime action consumer', () => { where: { profileName }, data: { status: 'STOPPED', lastError: null }, }); - await gate.markPaused(new Error('late shutdown failure')); + await gate.reportFailure(new Error('late shutdown failure')); expect(await db.gatewayProfile.findUniqueOrThrow({ where: { profileName } })).toMatchObject({ status: 'STOPPED', lastError: null, diff --git a/app/game-engine/test/leaseStartupRetry.test.ts b/app/game-engine/test/leaseStartupRetry.test.ts new file mode 100644 index 00000000..2310ee75 --- /dev/null +++ b/app/game-engine/test/leaseStartupRetry.test.ts @@ -0,0 +1,28 @@ +import { describe, expect, it, vi } from 'vitest'; +import { TurnDaemonLeaseUnavailableError } from '../src/lifecycle/databaseTurnDaemonLease.js'; +import { retryTurnDaemonLeaseStartup } from '../src/turn/leaseStartupRetry.js'; + +describe('lease startup retry', () => { + it('survives more than the PM2 startup failure budget and returns only a fresh runtime', async () => { + const freshRuntime = { owner: 'new-owner' }; + let attempts = 0; + const create = vi.fn(async () => { + if (++attempts <= 20) throw new TurnDaemonLeaseUnavailableError('test'); + return freshRuntime; + }); + const wait = vi.fn(async () => {}); + expect(await retryTurnDaemonLeaseStartup(create, wait)).toBe(freshRuntime); + expect(create).toHaveBeenCalledTimes(21); + expect(wait).toHaveBeenCalledTimes(20); + }); + it('propagates gameplay or startup faults instead of hiding them in a retry loop', async () => { + const error = new Error('invalid world'); + const create = vi.fn(async () => { + throw error; + }); + const wait = vi.fn(async () => {}); + await expect(retryTurnDaemonLeaseStartup(create, wait)).rejects.toBe(error); + expect(create).toHaveBeenCalledTimes(1); + expect(wait).not.toHaveBeenCalled(); + }); +}); diff --git a/app/game-engine/test/turnDaemonLease.integration.test.ts b/app/game-engine/test/turnDaemonLease.integration.test.ts index e6232d1e..2bc81666 100644 --- a/app/game-engine/test/turnDaemonLease.integration.test.ts +++ b/app/game-engine/test/turnDaemonLease.integration.test.ts @@ -308,6 +308,30 @@ integration('database turn daemon lease and fencing', () => { expect(await db.inputEvent.findUnique({ where: { requestId } })).toBeNull(); }); + it('fences expiry during a transaction using current DB time rather than transaction start time', async () => { + const profile = `${profilePrefix}transaction-expiry`; + const requestId = `${profilePrefix}transaction-expiry-write`; + const lease = await createLease(profile, 'stalled-owner'); + await lease.acquire(); + await expect( + db.$transaction(async (tx) => { + // transaction 시작 뒤에 만료되는 짧은 DB lease를 만든다. local watchdog은 + // 60초이므로 이 검증은 DB의 실제 시간 fence만으로 통과해야 한다. + await tx.$executeRaw` + UPDATE turn_daemon_lease + SET lease_until = (clock_timestamp() AT TIME ZONE 'UTC') + INTERVAL '100 milliseconds' + WHERE profile = ${profile} + `; + await tx.inputEvent.create({ + data: { requestId, target: 'ENGINE', eventType: 'fenced-test', payload: {} }, + }); + await tx.$executeRaw`SELECT pg_sleep(0.2)`; + await lease.assertActive(tx); + }) + ).rejects.toBeInstanceOf(TurnDaemonLeaseLostError); + expect(await db.inputEvent.findUnique({ where: { requestId } })).toBeNull(); + }); + it('permits a clean successor after release while fencing a resumed old token', async () => { const profile = `${profilePrefix}release`; const first = await createLease(profile, 'owner-a'); diff --git a/app/game-engine/test/turnDaemonLifecycle.test.ts b/app/game-engine/test/turnDaemonLifecycle.test.ts index 43febd38..68058da1 100644 --- a/app/game-engine/test/turnDaemonLifecycle.test.ts +++ b/app/game-engine/test/turnDaemonLifecycle.test.ts @@ -51,6 +51,39 @@ describe('TurnDaemonLifecycle', () => { expect(lifecycle.getStatus()).toMatchObject({ state: 'stopping', paused: true, lastError: error.message }); }); + it('rechecks the lease within one second while a wall deadline remains far in the future', async () => { + const now = new Date('2026-09-15T00:00:00Z'); + const error = new TurnDaemonLeaseLostError('che:default'); + const queue = new InMemoryControlQueue(); + const wait = vi.spyOn(queue, 'waitFor').mockResolvedValue(null); + let checks = 0; + const processor = { run: vi.fn() }; + const lifecycle = new TurnDaemonLifecycle( + { + clock: new ManualClock(now.getTime()), + controlQueue: queue, + processor, + getNextTickTime: (value) => addMinutes(value, 60), + stateStore: { + loadLastTurnTime: async () => now, + loadNextGeneralTurnTime: async () => addMinutes(now, 60), + projectGameDeadline: async () => addMinutes(now, 180), + saveLastTurnTime: async () => {}, + loadCheckpoint: async () => undefined, + saveCheckpoint: async () => {}, + }, + pauseGate: async () => { + if (++checks === 2) throw error; + return false; + }, + }, + { profile: 'che', defaultBudget: { budgetMs: 100, maxGenerals: 10, catchUpCap: 1 } } + ); + await expect(lifecycle.start()).rejects.toBe(error); + expect(wait).toHaveBeenCalledExactlyOnceWith(1000); + expect(processor.run).not.toHaveBeenCalled(); + }); + it.each(['PREOPEN', 'SUSPENDED', 'RECONCILING', 'COMPLETED'] as const)( 'does not dispatch an explicit run while the clock phase is %s', async (phase) => { diff --git a/docs/release-operations.md b/docs/release-operations.md index 01bd4c6f..7253f71e 100644 --- a/docs/release-operations.md +++ b/docs/release-operations.md @@ -319,6 +319,7 @@ process 복구를 시도합니다. 관리자 화면의 오류와 PM2 process 상 - 실행·명령·lifecycle 및 초기화 실패는 `admin_audit_event`의 `action=runtime.failure`, `credentialKind=DAEMON`으로 저장합니다. profile PAUSED 전환과 같은 transaction이며 현재 오류와 같은 반복 보고는 중복 저장하지 않습니다. + lease 만료는 상태를 바꾸지 않고 `summary.recovery=RESTART` 이력으로 기록합니다. 재개·배포로 `lastError`가 사라져도 append-only 이력은 남습니다. - 오류 종류·정화한 메시지·최대 8개 stack frame과 게임 연월/시계/lease 좌표를 저장합니다. 연결 URL과 인증값은 제거합니다. Gateway DB 자체에 기록할 수 없는 @@ -328,10 +329,24 @@ process 복구를 시도합니다. 관리자 화면의 오류와 PM2 process 상 lease와 시계를 다시 확인합니다. 복구 시작 시각 전의 대기를 장애로 오인하지 않습니다. VM 중단이나 DB 연결 장애로 turn-daemon lease가 만료되면 기존 owner는 턴과 -관리자 mutation을 처리할 수 없습니다. Lifecycle은 이를 즉시 `lastError`와 -`PAUSED`로 기록하고 종료합니다. PM2가 새 runtime과 DB snapshot으로 시작한 뒤 -관리자가 `재개`를 요청합니다. 이전 owner의 lease를 연장하거나 fencing 검증을 -우회하지 않습니다. 초기화·pause gate 실패도 같은 오류 기록 경로를 사용합니다. +관리자 mutation을 처리할 수 없습니다. Lifecycle은 오류 이력을 남기고 종료하며, +PM2가 새 owner/epoch와 DB snapshot으로 재시작합니다. lease 오류만으로 profile을 +영구 `PAUSED`로 바꾸지 않아 원래 실행 중인 서버는 기존 clock recovery 절차로 +자동 복구합니다. 운영자의 `PAUSED`/`STOPPED`와 실제 게임 처리 오류는 자동 재개하지 +않습니다. 이전 버전에서 이미 lease 오류로 PAUSED가 된 서버는 원인을 확인한 뒤 +한 번 `START`/재개해야 합니다. + +30초 lease와 이전 owner의 fencing은 유지합니다. transaction의 만료 검사는 시작에 +고정된 `CURRENT_TIMESTAMP`가 아닌 검사 순간의 `clock_timestamp()`를 사용합니다. +역방향 시계 보정으로 기존 lease가 아직 유효하면 startup은 2초 간격으로 기다리며 +PM2의 연속 시작 실패 한도를 소진하지 않습니다. 다음 턴을 기다리는 루프도 최대 +1초마다 gate를 다시 확인합니다. lease 이외 초기화·게임 처리 오류는 계속 PAUSED로 +기록하며 자동 재시도로 숨기지 않습니다. + +Hyper-V의 VM 정지/재개, 체크포인트 또는 host 시간 보정은 게스트의 heartbeat와 +벽시계에 영향을 줄 수 있습니다. 장애 시각의 게스트 `hv_utils`, `Clock change detected`, +NTP 로그와 Windows Hyper-V/백업 작업 이력을 대조합니다. lease 기간을 늘리거나 +시간 동기화를 임의로 끄는 것으로 해결하지 않습니다. Turn daemon의 DB persistence interactive transaction은 기본 30초입니다. 정상 turn budget과 같은 Prisma 기본 5초를 그대로 쓰면 populated season의 flush가 경계에서