fix: VM 시간 변경 후 턴 lease를 안전하게 자동 복구

This commit is contained in:
2026-09-15 23:05:33 +00:00
parent 7dc1670935
commit 4fb1343943
11 changed files with 224 additions and 45 deletions
@@ -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<LeaseRow[]>(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) {
@@ -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);
+17 -14
View File
@@ -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();
}
+38 -18
View File
@@ -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<boolean>;
isExplicitlyPaused(): boolean;
markPaused(error?: unknown): Promise<void>;
reportFailure(error?: unknown): Promise<void>;
close(): Promise<void>;
}
@@ -29,6 +31,7 @@ export const createGatewayProfileGate = async (options: GatewayProfileGateOption
});
await connector.connect();
const prisma = connector.prisma;
const reportedLeaseErrors = new WeakSet<TurnDaemonLeaseLostError>();
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<void> {
cachedPause = true;
cachedStatus = 'PAUSED';
lastCheckedAt = performance.now();
async reportFailure(error?: unknown): Promise<void> {
// 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;
@@ -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 <T>(
create: () => Promise<T>,
wait: () => Promise<void> = () => setTimeout(2000)
): Promise<T> => {
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();
}
}
};
+3 -3
View File
@@ -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 () => {
@@ -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,
@@ -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();
});
});
@@ -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');
@@ -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) => {
+19 -4
View File
@@ -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가 경계에서