From 928e71731c054a8029c82f7c885c4b3d8cb17678 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Fri, 9 Oct 2026 15:10:40 -0300 Subject: [PATCH 01/14] Tolerate a session listener start that lost a race (#89) Two callers that both find NetLDI missing both run startnetldi, and the loser exits 1 with "already running" although everything it wanted is up. startNetldi now re-lists after a failure and, when gemdbldi is there and answering, logs that another process started it and reports false (not started by this call) instead of throwing. Needed whatever else lands: 1.5.x and 1.6.0 keep starting NetLDI without any lock. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 8 +++ src/__tests__/databaseStarted.test.ts | 16 ++++- src/__tests__/startProcesses.test.ts | 96 +++++++++++++++++++++++++++ src/lifecycle.ts | 5 +- src/processes.ts | 52 ++++++++++----- 5 files changed, 156 insertions(+), 21 deletions(-) create mode 100644 src/__tests__/startProcesses.test.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index 8eefaed..c7d3c99 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -86,6 +86,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 database while a cell started it could install the MCP server's classes twice and start two servers on one port. Now the second waits for the first. +### Fixed + +- **Starting GemDB while something else is starting it no longer reports a failure.** Pressing + Start, running a notebook cell or opening the GemDB Shell while another window or terminal was + bringing the database up could end in "Start session listener failed (exit code 1)", although the + database and its session listener were both running. A listener another process started first now + counts as started. + ## [1.6.0] - 2026-10-07 The engine is unchanged at GemStone 4.0.0.a4, but start with a fresh database: delete diff --git a/src/__tests__/databaseStarted.test.ts b/src/__tests__/databaseStarted.test.ts index 73612d8..21cc268 100644 --- a/src/__tests__/databaseStarted.test.ts +++ b/src/__tests__/databaseStarted.test.ts @@ -53,7 +53,7 @@ vi.mock('../osConfig', async (importOriginal) => { const findStone = vi.fn(() => true); const findNetldi = vi.fn(() => true); const startStone = vi.fn(async () => {}); -const startNetldi = vi.fn(async () => {}); +const startNetldi = vi.fn(async (): Promise => true); vi.mock('../processes', () => ({ listProcesses: () => [], findStone: () => findStone(), @@ -133,6 +133,20 @@ describe('databaseStarted', () => { expect(eventsNamed('databaseStarted')).toHaveLength(1); }); + it('counts a listener another process started in the meantime as a start, not a failure', async () => { + // Pressing Start while another window, or the GemDB Shell, is starting the + // database: both see no listener and the other one wins (#89). + findNetldi.mockReturnValue(false); + startNetldi.mockResolvedValueOnce(false); + + const ok = await ensureRunning('/ext', TRIGGER.startCommand); + + expect(ok).toBe(true); + expect(eventsNamed('databaseStarted').map((e) => e.properties?.outcome)).not.toContain( + 'startFailed', + ); + }); + it('reports a script that did not take as osConfigFailed, not a decline', async () => { // The user said yes and the sudo script ran, but shared memory is still // short — a mistyped password, a cancelled script. Counting that as a diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts new file mode 100644 index 0000000..91a458e --- /dev/null +++ b/src/__tests__/startProcesses.test.ts @@ -0,0 +1,96 @@ +import { EventEmitter } from 'events'; +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { promisify } from 'util'; +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; +import { __log, __resetSettings, __setSetting } from '../__mocks__/vscode'; + +/** + * Starting the stone and the listener when another process may be doing the + * same, with the engine's commands faked: `gslist` answers from `listed`, and + * every other command exits with the code `exitCodes` gives it. + */ + +let listed = ''; +const exitCodes: Record = {}; +const spawned: string[] = []; + +function fakeChild(command: string): EventEmitter { + const name = path.basename(command); + spawned.push(name); + const child = Object.assign(new EventEmitter(), { + stdout: new EventEmitter(), + stderr: new EventEmitter(), + }); + setImmediate(() => child.emit('close', exitCodes[name] ?? 0)); + return child; +} + +vi.mock('child_process', async (importOriginal) => { + const actual = await importOriginal(); + const execFile = Object.assign(() => {}, { + [promisify.custom]: async () => ({ stdout: listed, stderr: '' }), + }); + return { + ...actual, + execFile, + execFileSync: () => listed, + spawn: (command: string) => fakeChild(command), + }; +}); + +const { expectedEnginePath } = await import('../paths'); +const { startNetldi } = await import('../processes'); + +function row(status: string, type: 'Stone' | 'Netldi', name: string): string { + return `${status.padEnd(12)} 4.0.0.a4 me 79386 51475 Sep 28 19:31 ${type.padEnd(7)} ${name}`; +} + +let root: string; + +beforeEach(() => { + __resetSettings(); + root = fs.mkdtempSync(path.join(os.tmpdir(), 'gemdb-start-')); + __setSetting('gemdb.rootPath', root); + fs.mkdirSync(path.join(expectedEnginePath(), 'bin'), { recursive: true }); + fs.writeFileSync(path.join(expectedEnginePath(), 'bin', 'gslist'), ''); + listed = ''; + spawned.length = 0; + for (const key of Object.keys(exitCodes)) delete exitCodes[key]; +}); + +afterEach(() => { + fs.rmSync(root, { recursive: true, force: true }); +}); + +describe('startNetldi', () => { + it('counts a listener another process started first as up, not as a failure (#89)', async () => { + // Both saw no listener; the other one won, so startnetldi refuses with + // "already running" and the re-list shows the listener answering. + exitCodes.startnetldi = 1; + listed = [row('OK', 'Stone', 'gemdb'), row('OK', 'Netldi', 'gemdbldi')].join('\n'); + + await expect(startNetldi()).resolves.toBe(false); + expect(__log).toContain('Another process started the session listener.'); + }); + + it('still fails when the listener is not up afterwards', async () => { + exitCodes.startnetldi = 1; + listed = row('OK', 'Stone', 'gemdb'); + + await expect(startNetldi()).rejects.toThrow(/Start session listener failed \(exit code 1\)/); + }); + + it('still fails when the listener is listed but not answering', async () => { + exitCodes.startnetldi = 1; + listed = [row('OK', 'Stone', 'gemdb'), row('exe deleted', 'Netldi', 'gemdbldi')].join('\n'); + + await expect(startNetldi()).rejects.toThrow(/Start session listener failed/); + }); + + it('reports a listener it started itself as started', async () => { + await expect(startNetldi()).resolves.toBe(true); + expect(spawned).toEqual(['startnetldi']); + }); +}); diff --git a/src/lifecycle.ts b/src/lifecycle.ts index 7d90eba..bf25ddf 100644 --- a/src/lifecycle.ts +++ b/src/lifecycle.ts @@ -852,8 +852,7 @@ async function startProcesses( } if (!findNetldi(running)) { progress?.report({ message: 'Starting the session listener…' }); - await startNetldi(); - startedNetldi = true; + startedNetldi = await startNetldi(); } else { log('The session listener is already running.'); } @@ -884,7 +883,7 @@ export interface StopWorld { listenerUp: () => boolean; stopStone: (force: boolean) => Promise; stopNetldi: () => Promise; - startNetldi: () => Promise; + startNetldi: () => Promise; /** Ask whether to disconnect the sessions that are in the way. */ confirmForce: (reason: string) => Promise; log: (message: string) => void; diff --git a/src/processes.ts b/src/processes.ts index f69d705..be6ba5d 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -277,26 +277,44 @@ function fileSize(file: string): number { } } -export async function startNetldi(): Promise { +/** + * Start the session listener. True when this call started it; false when + * `startnetldi` refused because another process had started it first. + * + * That race is not rare (#89): the window's start, the GemDB Shell's, and + * releases before this one, which start the listener without any lock, can + * all find it missing and start it together. The loser's `startnetldi` exits + * 1 with "Server 'gemdbldi' is already running", and everything the caller + * wanted is true, so a listener that is up and answering afterwards is not a + * failure. One that is not still fails with startnetldi's own words. + */ +export async function startNetldi(): Promise { requireOwnDatabase('start'); logStep('Starting the session listener'); const env = engineEnvironment(); - await runEngineCommand( - path.join(env.GEMSTONE, 'bin', 'startnetldi'), - // -a restricts logins to this user, -g runs sessions as that user without - // needing a host password. Together they are what lets GemDB log in with - // no operating-system credentials at all. - [ - '-a', - os.userInfo().username, - '-g', - '-l', - path.join(databaseLogPath(), `${NETLDI_NAME}.log`), - NETLDI_NAME, - ], - env, - 'Start session listener', - ); + try { + await runEngineCommand( + path.join(env.GEMSTONE, 'bin', 'startnetldi'), + // -a restricts logins to this user, -g runs sessions as that user without + // needing a host password. Together they are what lets GemDB log in with + // no operating-system credentials at all. + [ + '-a', + os.userInfo().username, + '-g', + '-l', + path.join(databaseLogPath(), `${NETLDI_NAME}.log`), + NETLDI_NAME, + ], + env, + 'Start session listener', + ); + return true; + } catch (e) { + if (findNetldi(await listProcessesAsync())?.status !== 'OK') throw e; + log('Another process started the session listener.'); + return false; + } } /** From 9d1c90bb9d7154b5c4d12fa6de02fce07d797149 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Fri, 9 Oct 2026 16:00:44 -0300 Subject: [PATCH 02/14] Start the stone and session listener once, under the stone lock ensureProcesses() looks for both processes and starts what is missing inside withStoneLock, so the window, the GemDB Shell and the listener a declined force-stop puts back no longer race each other. The flags it returns say what this call started, so a window that queued behind another start sends no databaseStarted of its own. Waiting for the lock ends early only when both are up and answering. The pre-start guards move to assertSafeToStart() in database.ts and run through beforeStoneStart, so the Shell now gets the NFS, engine-version, space-limit and disk-room checks (not statmonitor, which needs editor settings). An external database is still only checked, by both callers. startNetldi is no longer exported; integration tests that started both processes use ensureProcesses() instead. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 11 +- src/__integration__/breakpoint.test.ts | 5 +- src/__integration__/database.test.ts | 5 +- src/__integration__/debugConsole.test.ts | 5 +- src/__integration__/grail.test.ts | 5 +- src/__integration__/mcp.test.ts | 5 +- src/__integration__/redDots.test.ts | 5 +- src/__integration__/sessions.test.ts | 5 +- src/__integration__/space.test.ts | 5 +- src/__integration__/spaceFull.test.ts | 5 +- src/__tests__/databaseStarted.test.ts | 41 +++---- src/__tests__/externalDatabase.test.ts | 4 +- src/__tests__/externalLifecycle.test.ts | 21 ++-- src/__tests__/oneBringUp.test.ts | 9 +- src/__tests__/startProcesses.test.ts | 139 +++++++++++++++++++---- src/cliMain.ts | 37 ++++-- src/database.ts | 25 +++- src/lifecycle.ts | 63 +++------- src/processes.ts | 133 ++++++++++++++++++---- 19 files changed, 356 insertions(+), 172 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c7d3c99..1c02367 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -91,8 +91,15 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **Starting GemDB while something else is starting it no longer reports a failure.** Pressing Start, running a notebook cell or opening the GemDB Shell while another window or terminal was bringing the database up could end in "Start session listener failed (exit code 1)", although the - database and its session listener were both running. A listener another process started first now - counts as started. + database and its session listener were both running. GemDB now checks for and starts the session + listener under the same lock as the database, so one start waits for the other, and a listener + started by an older GemDB in another editor counts as started. +- **The GemDB Shell checks the database before starting it, as the window does.** Opening the + Shell with the database stopped started it without the checks the window makes first, so a + database the installed engine cannot read started and then refused every login, and one on a + network drive or a disk without room for it failed with the engine's own error. The Shell now + refuses with the same explanation the window gives, and applies the space limits a database + from an earlier GemDB is missing. ## [1.6.0] - 2026-10-07 diff --git a/src/__integration__/breakpoint.test.ts b/src/__integration__/breakpoint.test.ts index 1ff767e..90c038c 100644 --- a/src/__integration__/breakpoint.test.ts +++ b/src/__integration__/breakpoint.test.ts @@ -25,7 +25,7 @@ import { setVariableQuery, unquote, } from '../pauseVariables'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { fileOwner } from '../fileOwner'; import { runPython, runPythonFile } from '../pythonQueries'; import { @@ -94,8 +94,7 @@ beforeAll(async () => { if (!fixture) return; createDatabaseWithPython(fixture); stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterEach(() => setHaltHandler(undefined)); diff --git a/src/__integration__/database.test.ts b/src/__integration__/database.test.ts index f2bd905..1d94819 100644 --- a/src/__integration__/database.test.ts +++ b/src/__integration__/database.test.ts @@ -5,12 +5,12 @@ import { createDatabase } from '../database'; import { isSharedMemoryConfigured } from '../osConfig'; import { databaseExists, databaseStatPath, extentPath } from '../paths'; import { + ensureProcesses, findNetldi, findStone, isListening, isRunning, listProcesses, - startNetldi, startStone, stopNetldi, stopStone, @@ -81,8 +81,7 @@ describe.skipIf(!makeFixtureIsPossible())('a real database', () => { it('starts, and reports itself through gslist', async () => { // As startProcesses does before every start. ensureStatmonitor(); - await startStone(); - await startNetldi(); + await ensureProcesses(); ensureDatabaseAccount(); const processes = listProcesses(); diff --git a/src/__integration__/debugConsole.test.ts b/src/__integration__/debugConsole.test.ts index d859909..1694cef 100644 --- a/src/__integration__/debugConsole.test.ts +++ b/src/__integration__/debugConsole.test.ts @@ -22,7 +22,7 @@ import { parsePausedStack, pausedStackQuery, } from '../pauseVariables'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { PyResult, runPython, runPythonFile } from '../pythonQueries'; import { SessionOwner, @@ -92,8 +92,7 @@ beforeAll(async () => { fs.writeFileSync(path.join(fixture.root, 'dcmod.py'), DCMOD); createDatabaseWithPython(fixture); stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterAll(async () => { diff --git a/src/__integration__/grail.test.ts b/src/__integration__/grail.test.ts index 5e37231..b96a173 100644 --- a/src/__integration__/grail.test.ts +++ b/src/__integration__/grail.test.ts @@ -5,7 +5,7 @@ import { createDatabase } from '../database'; import { bundledGrailStamp, installGrail, recordGrailInstalled, stageGrail } from '../grail'; import { isSharedMemoryConfigured } from '../osConfig'; import { grailInstalled, grailStagedOnDisk } from '../paths'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { isErrorResult, isGrailInstalled, @@ -61,8 +61,7 @@ beforeAll(async () => { createDatabase(fixture.engine); limitTestDatabase(); - await startStone(); - await startNetldi(); + await ensureProcesses(); // Grail installs into the gemdb account, as `ensureRunning` creates it. ensureDatabaseAccount(); }); diff --git a/src/__integration__/mcp.test.ts b/src/__integration__/mcp.test.ts index dbc0045..36c6c10 100644 --- a/src/__integration__/mcp.test.ts +++ b/src/__integration__/mcp.test.ts @@ -17,7 +17,7 @@ import { stopMcpServer, } from '../mcp'; import { mcpInstalled, mcpRouterStatePath, mcpStagedOnDisk } from '../paths'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { GciSession, execute, logoutAll } from '../session'; import { createDatabaseWithPython, Fixture, haveTestExtent, makeFixture } from './fixture'; @@ -73,8 +73,7 @@ beforeAll(async () => { // Grail's files on disk, because the router's worker gems inherit the // NetLDI's environment and resolve Python modules through GRAIL_DIR. stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterAll(async () => { diff --git a/src/__integration__/redDots.test.ts b/src/__integration__/redDots.test.ts index 48c9869..63274c3 100644 --- a/src/__integration__/redDots.test.ts +++ b/src/__integration__/redDots.test.ts @@ -11,7 +11,7 @@ import { parsePausedStack, pausedStackQuery, } from '../pauseVariables'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { runPython, runPythonFile } from '../pythonQueries'; import { DotsByFile } from '../redDots'; import { @@ -122,8 +122,7 @@ beforeAll(async () => { if (!fixture) return; createDatabaseWithPython(fixture); stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterEach(() => { diff --git a/src/__integration__/sessions.test.ts b/src/__integration__/sessions.test.ts index 6fa675d..ef31108 100644 --- a/src/__integration__/sessions.test.ts +++ b/src/__integration__/sessions.test.ts @@ -1,7 +1,7 @@ import { afterAll, beforeAll, describe, expect, it } from 'vitest'; import { __log } from '../__mocks__/vscode'; import { stageGrail } from '../grail'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { isErrorResult, renameOwner, runPython } from '../pythonQueries'; import { SessionOwner, cacheNameFor, execute, logoutAll, sessionRegistry } from '../session'; import { createDatabaseWithPython, Fixture, haveTestExtent, makeFixture } from './fixture'; @@ -38,8 +38,7 @@ beforeAll(async () => { if (!fixture) return; createDatabaseWithPython(fixture); stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterAll(async () => { diff --git a/src/__integration__/space.test.ts b/src/__integration__/space.test.ts index c7f5b03..3c5032c 100644 --- a/src/__integration__/space.test.ts +++ b/src/__integration__/space.test.ts @@ -12,7 +12,7 @@ import { stopDatabaseSession, } from '../maintenance'; import { databaseLogPath, extentPath } from '../paths'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { isErrorResult, runPython } from '../pythonQueries'; import { GciSession, @@ -69,8 +69,7 @@ beforeAll(async () => { if (!fixture) return; createDatabaseWithPython(fixture); stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterAll(async () => { diff --git a/src/__integration__/spaceFull.test.ts b/src/__integration__/spaceFull.test.ts index ab9f2b1..5de2e5a 100644 --- a/src/__integration__/spaceFull.test.ts +++ b/src/__integration__/spaceFull.test.ts @@ -4,7 +4,7 @@ import { stageGrail } from '../grail'; import { adminAccount } from '../config'; import { collectGarbage, parseSpaceReading } from '../maintenance'; import { extentPath } from '../paths'; -import { isRunning, startNetldi, startStone, stopNetldi, stopStone } from '../processes'; +import { ensureProcesses, isRunning, stopNetldi, stopStone } from '../processes'; import { runPython } from '../pythonQueries'; import { GciSession, SessionOwner, execute, logoutAll } from '../session'; import { @@ -74,8 +74,7 @@ beforeAll(async () => { const extentMb = fs.statSync(extentPath()).size / 1048576; limitTestDatabase(Math.ceil((extentMb + 192) / 16) * 16, THRESHOLD_MB); stageGrail(ext); - await startStone(); - await startNetldi(); + await ensureProcesses(); }); afterAll(async () => { diff --git a/src/__tests__/databaseStarted.test.ts b/src/__tests__/databaseStarted.test.ts index 21cc268..e020d00 100644 --- a/src/__tests__/databaseStarted.test.ts +++ b/src/__tests__/databaseStarted.test.ts @@ -50,16 +50,13 @@ vi.mock('../osConfig', async (importOriginal) => { }; }); -const findStone = vi.fn(() => true); -const findNetldi = vi.fn(() => true); -const startStone = vi.fn(async () => {}); -const startNetldi = vi.fn(async (): Promise => true); +const nothingStarted = { startedStone: false, startedNetldi: false }; +const ensureProcesses = vi.fn(async () => nothingStarted); vi.mock('../processes', () => ({ listProcesses: () => [], - findStone: () => findStone(), - findNetldi: () => findNetldi(), - startStone: () => startStone(), - startNetldi: () => startNetldi(), + findStone: () => true, + findNetldi: () => true, + ensureProcesses: () => ensureProcesses(), isListening: () => true, isRunning: () => true, stopNetldi: async () => {}, @@ -91,8 +88,7 @@ describe('databaseStarted', () => { ensureOsConfigured.mockReset().mockResolvedValue('alreadyConfigured'); isSharedMemoryConfigured.mockReset().mockResolvedValue(true); fileInGrail.mockClear(); - findStone.mockReturnValue(true); - findNetldi.mockReturnValue(true); + ensureProcesses.mockReset().mockResolvedValue(nothingStarted); const context = fakeExtensionContext(); initTelemetry(context, false); @@ -101,6 +97,9 @@ describe('databaseStarted', () => { initUnattendedSetupMarker(context.globalStorageUri.fsPath); }); + // Also a window that pressed Start while another window, or the GemDB Shell, + // was starting the database: once it has the lock it finds both up and has + // started nothing, so the start is the other process's to report. it('sends nothing on a no-op call — everything already up, nothing prompted', async () => { const ok = await ensureRunning('/ext', TRIGGER.notebook); @@ -124,27 +123,20 @@ describe('databaseStarted', () => { }); it('sends started when the stone had to be started', async () => { - findStone.mockReturnValue(false); + ensureProcesses.mockResolvedValue({ startedStone: true, startedNetldi: false }); const ok = await ensureRunning('/ext', TRIGGER.notebook); expect(ok).toBe(true); - expect(startStone).toHaveBeenCalledTimes(1); expect(eventsNamed('databaseStarted')).toHaveLength(1); }); - it('counts a listener another process started in the meantime as a start, not a failure', async () => { - // Pressing Start while another window, or the GemDB Shell, is starting the - // database: both see no listener and the other one wins (#89). - findNetldi.mockReturnValue(false); - startNetldi.mockResolvedValueOnce(false); + it('sends started when only the listener had to be started', async () => { + ensureProcesses.mockResolvedValue({ startedStone: false, startedNetldi: true }); - const ok = await ensureRunning('/ext', TRIGGER.startCommand); + await ensureRunning('/ext', TRIGGER.notebook); - expect(ok).toBe(true); - expect(eventsNamed('databaseStarted').map((e) => e.properties?.outcome)).not.toContain( - 'startFailed', - ); + expect(eventsNamed('databaseStarted')).toHaveLength(1); }); it('reports a script that did not take as osConfigFailed, not a decline', async () => { @@ -212,12 +204,10 @@ describe('resumeRunning', () => { grailNeedsUpdate.mockReturnValue(false); grailInstalled.mockReturnValue(true); isInstalled.mockReturnValue(true); - findStone.mockReturnValue(true); - findNetldi.mockReturnValue(true); ensureOsConfigured.mockReset().mockResolvedValue('alreadyConfigured'); isSharedMemoryConfigured.mockReset().mockResolvedValue(true); fileInGrail.mockClear(); - startStone.mockClear(); + ensureProcesses.mockReset().mockResolvedValue(nothingStarted); initTelemetry(fakeExtensionContext(), false); }); @@ -228,7 +218,6 @@ describe('resumeRunning', () => { expect(await resumeRunning('/ext')).toBe(true); expect(fileInGrail).toHaveBeenCalledTimes(1); - expect(startStone).not.toHaveBeenCalled(); expect(eventsNamed('databaseStarted').map((e) => e.properties)).toEqual([ expect.objectContaining({ trigger: 'autoStart', diff --git a/src/__tests__/externalDatabase.test.ts b/src/__tests__/externalDatabase.test.ts index 54d6092..4e14a0b 100644 --- a/src/__tests__/externalDatabase.test.ts +++ b/src/__tests__/externalDatabase.test.ts @@ -22,9 +22,9 @@ import { EngineProcess, ExternalDatabaseError, engineEnvironment, + ensureProcesses, findNetldi, findStone, - startNetldi, startStone, stopNetldi, stopStone, @@ -228,7 +228,7 @@ describe('processes', () => { it('are never started or stopped by GemDB', async () => { useExternal(); await expect(startStone()).rejects.toBeInstanceOf(ExternalDatabaseError); - await expect(startNetldi()).rejects.toBeInstanceOf(ExternalDatabaseError); + await expect(ensureProcesses()).rejects.toBeInstanceOf(ExternalDatabaseError); await expect(stopStone()).rejects.toBeInstanceOf(ExternalDatabaseError); await expect(stopNetldi()).rejects.toBeInstanceOf(ExternalDatabaseError); }); diff --git a/src/__tests__/externalLifecycle.test.ts b/src/__tests__/externalLifecycle.test.ts index 9c76dfa..e2a1c3c 100644 --- a/src/__tests__/externalLifecycle.test.ts +++ b/src/__tests__/externalLifecycle.test.ts @@ -38,19 +38,18 @@ vi.mock('../osConfig', async (importOriginal) => { const findStone = vi.fn(() => true); const findNetldi = vi.fn(() => true); -const startStone = vi.fn(async () => {}); -const startNetldi = vi.fn(async () => {}); +const ensureProcesses = vi.fn(async () => ({ startedStone: false, startedNetldi: false })); const stopStone = vi.fn(async () => {}); const stopNetldi = vi.fn(async () => {}); vi.mock('../processes', async (importOriginal) => { const actual = await importOriginal(); return { ExternalDatabaseError: actual.ExternalDatabaseError, + externalDatabaseDownError: actual.externalDatabaseDownError, listProcesses: () => [], findStone: () => findStone(), findNetldi: () => findNetldi(), - startStone: () => startStone(), - startNetldi: () => startNetldi(), + ensureProcesses: () => ensureProcesses(), isListening: () => findNetldi(), isRunning: () => findStone(), stopNetldi: () => stopNetldi(), @@ -89,8 +88,7 @@ describe('an external database', () => { __setSetting('gemdb.externalDatabase.gemstone', '/opt/gemstone/product'); for (const mock of [ ensureOsConfigured, - startStone, - startNetldi, + ensureProcesses, stopStone, stopNetldi, startMcpServer, @@ -110,16 +108,14 @@ describe('an external database', () => { it('is used as it is when running: no shared-memory check, nothing started', async () => { expect(await ensureRunning('/ext', TRIGGER.notebook)).toBe(true); expect(ensureOsConfigured).not.toHaveBeenCalled(); - expect(startStone).not.toHaveBeenCalled(); - expect(startNetldi).not.toHaveBeenCalled(); + expect(ensureProcesses).not.toHaveBeenCalled(); }); it('is reported, not started, when it is down', async () => { findStone.mockReturnValue(false); expect(await ensureRunning('/ext', TRIGGER.notebook)).toBe(false); - expect(startStone).not.toHaveBeenCalled(); - expect(startNetldi).not.toHaveBeenCalled(); + expect(ensureProcesses).not.toHaveBeenCalled(); expect(__log.join('\n')).toMatch(/administrator runs\. Ask them to start it/); }); @@ -127,7 +123,7 @@ describe('an external database', () => { findNetldi.mockReturnValue(false); expect(await ensureRunning('/ext', TRIGGER.notebook)).toBe(false); - expect(startNetldi).not.toHaveBeenCalled(); + expect(ensureProcesses).not.toHaveBeenCalled(); }); it('is never stopped', async () => { @@ -148,8 +144,7 @@ describe('an external database', () => { it('starts the router for the running database, and nothing else', async () => { expect(await resumeMcpServing('/ext')).toBe(true); expect(startMcpServer).toHaveBeenCalledOnce(); - expect(startStone).not.toHaveBeenCalled(); - expect(startNetldi).not.toHaveBeenCalled(); + expect(ensureProcesses).not.toHaveBeenCalled(); }); it('leaves a router that is already listening alone', async () => { diff --git a/src/__tests__/oneBringUp.test.ts b/src/__tests__/oneBringUp.test.ts index a8ddf55..f2a516a 100644 --- a/src/__tests__/oneBringUp.test.ts +++ b/src/__tests__/oneBringUp.test.ts @@ -52,8 +52,8 @@ vi.mock('../osConfig', async (importOriginal) => { const findStone = vi.fn(() => true); const findNetldi = vi.fn(() => true); +// The stone start inside `ensureProcesses`, which starts only what is down. const startStone = vi.fn(async () => {}); -const startNetldi = vi.fn(async () => {}); const stopStone = vi.fn(async (_force: boolean) => { findStone.mockReturnValue(false); }); @@ -61,8 +61,11 @@ vi.mock('../processes', () => ({ listProcesses: () => [], findStone: () => findStone(), findNetldi: () => findNetldi(), - startStone: () => startStone(), - startNetldi: () => startNetldi(), + ensureProcesses: async () => { + const startedStone = !findStone(); + if (startedStone) await startStone(); + return { startedStone, startedNetldi: false }; + }, isListening: () => true, isRunning: () => findStone(), stopNetldi: async () => {}, diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts index 91a458e..aee20f6 100644 --- a/src/__tests__/startProcesses.test.ts +++ b/src/__tests__/startProcesses.test.ts @@ -8,14 +8,19 @@ import { __log, __resetSettings, __setSetting } from '../__mocks__/vscode'; /** * Starting the stone and the listener when another process may be doing the - * same, with the engine's commands faked: `gslist` answers from `listed`, and - * every other command exits with the code `exitCodes` gives it. + * same, with the engine's commands faked: `gslist` answers with the next of + * `listings` (the last one for good once they run out), and every other + * command exits with the code `exitCodes` gives it. */ -let listed = ''; +let listings: string[] = []; const exitCodes: Record = {}; const spawned: string[] = []; +function gslist(): string { + return listings.length > 1 ? (listings.shift() ?? '') : (listings[0] ?? ''); +} + function fakeChild(command: string): EventEmitter { const name = path.basename(command); spawned.push(name); @@ -30,23 +35,43 @@ function fakeChild(command: string): EventEmitter { vi.mock('child_process', async (importOriginal) => { const actual = await importOriginal(); const execFile = Object.assign(() => {}, { - [promisify.custom]: async () => ({ stdout: listed, stderr: '' }), + [promisify.custom]: async () => ({ stdout: gslist(), stderr: '' }), }); return { ...actual, execFile, - execFileSync: () => listed, + execFileSync: () => gslist(), spawn: (command: string) => fakeChild(command), }; }); +// The real lock, with what it is asked to wait for kept where a test can ask it. +let satisfied: (() => boolean | Promise) | undefined; +vi.mock('../lock', async (importOriginal) => { + const actual = await importOriginal(); + return { + ...actual, + withStoneLock: ( + work: () => Promise, + wait: { satisfied?: () => boolean | Promise } = {}, + ) => { + satisfied = wait.satisfied; + return actual.withStoneLock(work, wait); + }, + }; +}); + const { expectedEnginePath } = await import('../paths'); -const { startNetldi } = await import('../processes'); +const { ensureProcesses } = await import('../processes'); function row(status: string, type: 'Stone' | 'Netldi', name: string): string { return `${status.padEnd(12)} 4.0.0.a4 me 79386 51475 Sep 28 19:31 ${type.padEnd(7)} ${name}`; } +const STONE_UP = row('OK', 'Stone', 'gemdb'); +const LISTENER_UP = row('OK', 'Netldi', 'gemdbldi'); +const BOTH_UP = [STONE_UP, LISTENER_UP].join('\n'); + let root: string; beforeEach(() => { @@ -55,8 +80,9 @@ beforeEach(() => { __setSetting('gemdb.rootPath', root); fs.mkdirSync(path.join(expectedEnginePath(), 'bin'), { recursive: true }); fs.writeFileSync(path.join(expectedEnginePath(), 'bin', 'gslist'), ''); - listed = ''; + listings = []; spawned.length = 0; + satisfied = undefined; for (const key of Object.keys(exitCodes)) delete exitCodes[key]; }); @@ -64,33 +90,108 @@ afterEach(() => { fs.rmSync(root, { recursive: true, force: true }); }); -describe('startNetldi', () => { +describe('ensureProcesses', () => { + it('starts nothing, and says so, when both are already up', async () => { + listings = [BOTH_UP]; + const beforeStoneStart = vi.fn(); + + const started = await ensureProcesses({ beforeStoneStart }); + + expect(started).toEqual({ startedStone: false, startedNetldi: false }); + expect(spawned).toEqual([]); + expect(beforeStoneStart).not.toHaveBeenCalled(); + }); + + it('starts both, guards first, when neither is up', async () => { + listings = ['', '', BOTH_UP]; + const beforeStoneStart = vi.fn(() => { + expect(spawned).toEqual([]); + }); + + const started = await ensureProcesses({ beforeStoneStart }); + + expect(started).toEqual({ startedStone: true, startedNetldi: true }); + expect(spawned).toEqual(['startstone', 'startnetldi']); + expect(beforeStoneStart).toHaveBeenCalledOnce(); + }); + + it('starts only the listener when the stone is up, without the stone’s guards', async () => { + listings = [STONE_UP]; + const beforeStoneStart = vi.fn(); + + const started = await ensureProcesses({ beforeStoneStart }); + + expect(started).toEqual({ startedStone: false, startedNetldi: true }); + expect(spawned).toEqual(['startnetldi']); + expect(beforeStoneStart).not.toHaveBeenCalled(); + }); + + it('starts no stone when a guard refuses it', async () => { + listings = ['']; + + const start = ensureProcesses({ + beforeStoneStart: () => { + throw new Error('the database is on NFS'); + }, + }); + + await expect(start).rejects.toThrow('the database is on NFS'); + expect(spawned).toEqual([]); + }); + + it('looks for the listener again after starting the stone, not at a list from before', async () => { + // Another process started the listener while this one started the stone. + listings = ['', BOTH_UP]; + + const started = await ensureProcesses(); + + expect(started).toEqual({ startedStone: true, startedNetldi: false }); + expect(spawned).toEqual(['startstone']); + }); + it('counts a listener another process started first as up, not as a failure (#89)', async () => { // Both saw no listener; the other one won, so startnetldi refuses with // "already running" and the re-list shows the listener answering. exitCodes.startnetldi = 1; - listed = [row('OK', 'Stone', 'gemdb'), row('OK', 'Netldi', 'gemdbldi')].join('\n'); + listings = [STONE_UP, STONE_UP, BOTH_UP]; + + const started = await ensureProcesses(); - await expect(startNetldi()).resolves.toBe(false); + expect(started).toEqual({ startedStone: false, startedNetldi: false }); expect(__log).toContain('Another process started the session listener.'); }); - it('still fails when the listener is not up afterwards', async () => { + it('still fails a listener start that leaves no listener up', async () => { exitCodes.startnetldi = 1; - listed = row('OK', 'Stone', 'gemdb'); + listings = [STONE_UP]; - await expect(startNetldi()).rejects.toThrow(/Start session listener failed \(exit code 1\)/); + await expect(ensureProcesses()).rejects.toThrow( + /Start session listener failed \(exit code 1\)/, + ); }); - it('still fails when the listener is listed but not answering', async () => { + it('still fails a listener start that leaves a listener that is not answering', async () => { exitCodes.startnetldi = 1; - listed = [row('OK', 'Stone', 'gemdb'), row('exe deleted', 'Netldi', 'gemdbldi')].join('\n'); + listings = [ + STONE_UP, + STONE_UP, + [STONE_UP, row('exe deleted', 'Netldi', 'gemdbldi')].join('\n'), + ]; - await expect(startNetldi()).rejects.toThrow(/Start session listener failed/); + await expect(ensureProcesses()).rejects.toThrow(/Start session listener failed/); }); - it('reports a listener it started itself as started', async () => { - await expect(startNetldi()).resolves.toBe(true); - expect(spawned).toEqual(['startnetldi']); + it('stops waiting for the lock only once both are up and answering', async () => { + listings = [BOTH_UP]; + await ensureProcesses(); + const check = async (listing: string): Promise => { + listings = [listing]; + return satisfied?.(); + }; + + expect(await check(BOTH_UP)).toBe(true); + expect(await check(STONE_UP)).toBe(false); + expect(await check(LISTENER_UP)).toBe(false); + expect(await check([row('Startup', 'Stone', 'gemdb'), LISTENER_UP].join('\n'))).toBe(false); }); }); diff --git a/src/cliMain.ts b/src/cliMain.ts index 8607045..2ac6783 100644 --- a/src/cliMain.ts +++ b/src/cliMain.ts @@ -1,6 +1,13 @@ -import { abortIdleSessionsAfterMinutes } from './config'; +import { abortIdleSessionsAfterMinutes, externalDatabase } from './config'; +import { assertSafeToStart } from './database'; import { errorMessage } from './log'; -import { findNetldi, findStone, startNetldi, startStone } from './processes'; +import { + ensureProcesses, + externalDatabaseDownError, + findNetldi, + findStone, + listProcesses, +} from './processes'; import { PyRepl, ReplSession } from './pyRepl'; import { runPythonInSession } from './pythonQueries'; import { GciSession, setInputHandler } from './session'; @@ -25,16 +32,30 @@ import { GciSession, setInputHandler } from './session'; * Bring the database up, the same judgement the wrapper makes for a file run: * asking for the shell is asking for a running database. Unlike the wrapper's * file mode — a linked gem, needing only the stone — a shell session arrives - * through the listener, so both are ensured. Errors are reported rather than - * thrown: the shell prompt (or the exit code) is the caller's answer. + * through the listener, so both are ensured. Both go through + * `ensureProcesses`, the same locked path the window takes, so a Shell opened while a window is + * starting the database waits for it rather than racing it. The stone gets the + * window's pre-start guards too, all but statmonitor, whose configuration + * comes from editor settings the Shell does not have: `system.conf` keeps + * whatever the window's last start wrote. + * + * An external database is only checked, as the window checks it: GemDB starts + * none of it. Errors are reported rather than thrown: the shell prompt (or the + * exit code) is the caller's answer. */ async function ensureDatabase(): Promise { try { - if (!findStone()) { - process.stderr.write('gemdb: starting the database…\r\n'); - await startStone(); + const external = externalDatabase(); + if (external) { + const running = listProcesses(); + if (!findStone(running) || !findNetldi(running)) throw externalDatabaseDownError(external); + } else { + await ensureProcesses({ + beforeStoneStart: assertSafeToStart, + report: (message) => + process.stderr.write(`gemdb: ${message.charAt(0).toLowerCase()}${message.slice(1)}\r\n`), + }); } - if (!findNetldi()) await startNetldi(); return true; } catch (e) { // Raw mode may be on by now, so bare `\n` would stairstep the message. diff --git a/src/database.ts b/src/database.ts index df7b390..e70b194 100644 --- a/src/database.ts +++ b/src/database.ts @@ -2,10 +2,10 @@ import * as crypto from 'crypto'; import * as fs from 'fs'; import * as path from 'path'; import { execFileSync } from 'child_process'; -import { STONE_NAME, databasePasswordPath, rootPath } from './config'; +import { STONE_NAME, databasePasswordPath, engineVersion, rootPath } from './config'; import { log, logStep } from './log'; import { isOnNfs } from './networkFileSystem'; -import { databaseExists, databasePath, ensureRootPath, extentPath } from './paths'; +import { databaseExists, databasePath, enginePath, ensureRootPath, extentPath } from './paths'; /** * Create the one database GemDB manages. @@ -567,3 +567,24 @@ export function databaseOnNfsError(): DatabaseOnNfsError { 'for GemDB instead.', ); } + +/** + * Everything checked, or put right, just before GemDB's own stone starts — + * from the window or from the GemDB Shell, so neither door starts a stone the + * other would have refused. + * + * The engine check is here as well as in `prepareFiles` because an extension + * update reaches a start without going through preparation at all: the engine + * is downloaded, the database exists, Grail is staged, so the first thing that + * happens is a stone starting on a repository the new engine cannot read. NFS + * likewise: a database set up there before setup checked for it. And a + * database an earlier GemDB created has no space limits yet, while the stone + * reserves the extent's full size as it starts. + */ +export function assertSafeToStart(): void { + assertDatabaseIsLocal(); + const engine = enginePath(); + if (engine) assertDatabaseMatchesEngine(engine, engineVersion()); + ensureSpaceLimits(); + assertRoomForExtent(); +} diff --git a/src/lifecycle.ts b/src/lifecycle.ts index bf25ddf..801412b 100644 --- a/src/lifecycle.ts +++ b/src/lifecycle.ts @@ -18,9 +18,8 @@ import { DatabaseOnNfsError, DatabaseVersionError, DiskSpaceError, - assertRoomForExtent, assertRoomForSetup, - ensureSpaceLimits, + assertSafeToStart, removeDatabase, } from './database'; import { Progress, installEngine, removeEngine } from './engine'; @@ -53,14 +52,13 @@ import { mcpPath, } from './paths'; import { - ExternalDatabaseError, + ensureProcesses, + externalDatabaseDownError, findNetldi, findStone, isListening, isRunning, listProcesses, - startNetldi, - startStone, stopNetldi, stopStone, } from './processes'; @@ -810,53 +808,24 @@ export async function resumeRunning(extensionPath: string): Promise { async function startProcesses( progress?: vscode.Progress<{ message?: string }>, ): Promise<{ startedStone: boolean; startedNetldi: boolean }> { - const running = listProcesses(); - let startedStone = false; - let startedNetldi = false; - // Nothing to start for an external database — only whether it is up, said // in terms of what to do about it. const external = externalDatabase(); if (external) { - if (!findStone(running) || !findNetldi(running)) { - throw new ExternalDatabaseError( - `The database is not running: GemDB expects stone ${external.stone} and NetLDI ` + - `${external.netldi}, which this machine's administrator runs. Ask them to start it.`, - ); - } + const running = listProcesses(); + if (!findStone(running) || !findNetldi(running)) throw externalDatabaseDownError(external); log('The database is running.'); - return { startedStone, startedNetldi }; + return { startedStone: false, startedNetldi: false }; } - if (!findStone(running)) { - // Checked here as well as in `prepareFiles`, because an extension update - // reaches this line without going through preparation at all: the engine - // is downloaded, the database exists, Grail is staged, so `isInstalled()` - // is true and the first thing that happens is a stone starting on a - // repository the new engine cannot read. - // NFS likewise: a database set up there before setup checked for it. - assertDatabaseIsLocal(); - const engine = enginePath(); - if (engine) assertDatabaseMatchesEngine(engine, engineVersion()); - // A database an earlier GemDB created has no space limits yet, and the - // stone reserves the extent's full size as it starts. - ensureSpaceLimits(); - // Every start, not once: the settings it is written from may have changed. - ensureStatmonitor(); - assertRoomForExtent(); - progress?.report({ message: 'Starting the database…' }); - await startStone(); - startedStone = true; - } else { - log('The database is already running.'); - } - if (!findNetldi(running)) { - progress?.report({ message: 'Starting the session listener…' }); - startedNetldi = await startNetldi(); - } else { - log('The session listener is already running.'); - } - return { startedStone, startedNetldi }; + return ensureProcesses({ + beforeStoneStart: () => { + assertSafeToStart(); + // Every start, not once: the settings it is written from may have changed. + ensureStatmonitor(); + }, + report: (message) => progress?.report({ message }), + }); } /** @@ -975,7 +944,9 @@ async function stopOnce(): Promise { listenerUp: () => isListening(), stopStone, stopNetldi, - startNetldi, + // Through the lock, like every other start: the window that declined + // is not the only one that may be putting the listener back. + startNetldi: () => ensureProcesses(), confirmForce, log, }); diff --git a/src/processes.ts b/src/processes.ts index be6ba5d..1161a69 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -191,6 +191,80 @@ function requireOwnDatabase(action: string): void { ); } +/** + * What to say when an external database is not up: GemDB does not start it, + * so the sentence says who does. + */ +export function externalDatabaseDownError(external: { + stone: string; + netldi: string; +}): ExternalDatabaseError { + return new ExternalDatabaseError( + `The database is not running: GemDB expects stone ${external.stone} and NetLDI ` + + `${external.netldi}, which this machine's administrator runs. Ask them to start it.`, + ); +} + +/** + * Bring up whichever of the stone and the session listener is not already + * up, and say which of them this call started. + * + * Every start of GemDB's own database goes through here — the window's, the + * GemDB Shell's, and the listener a declined force-stop puts back — and all + * of it happens under the stone lock the `gemdb` wrapper also takes. Checking + * and starting have to be one step: checked outside the lock, two callers + * that both found the listener missing both ran `startnetldi`, and the loser + * reported a failure over a database that was up. So the look happens inside + * the lock, and a caller that queued behind whoever was starting it finds + * everything up and starts nothing. For the same reason, both coming up while + * we wait for the lock ends the wait, with nothing started. + * + * `beforeStoneStart` runs only when this call is about to start the stone: + * the guards that refuse a stone that should not start belong there, not on + * every call. `report` hears each step as it begins, for a progress + * notification or a terminal. + */ +export async function ensureProcesses( + opts: { beforeStoneStart?: () => void; report?: (message: string) => void } = {}, +): Promise<{ startedStone: boolean; startedNetldi: boolean }> { + requireOwnDatabase('start'); + const started = await withStoneLock( + async () => { + let startedStone = false; + if (!findStone(await listProcessesAsync())) { + opts.beforeStoneStart?.(); + opts.report?.('Starting the database…'); + logStep('Starting the database'); + await runStartstone(); + startedStone = true; + } else { + log('The database is already running.'); + } + + let startedNetldi = false; + if (!findNetldi(await listProcessesAsync())) { + opts.report?.('Starting the session listener…'); + startedNetldi = await startNetldi(); + } else { + log('The session listener is already running.'); + } + return { startedStone, startedNetldi }; + }, + { + satisfied: async () => { + const running = await listProcessesAsync(); + return findStone(running)?.status === 'OK' && findNetldi(running)?.status === 'OK'; + }, + }, + ); + return started ?? { startedStone: false, startedNetldi: false }; +} + +/** + * Start the stone alone, for what needs no session listener: the `gemdb` + * wrapper's file runs are linked sessions, and so are the tests that use this. + * Under the same lock as {@link ensureProcesses}. + */ export async function startStone(): Promise { requireOwnDatabase('start'); // Under the lock the generated `gemdb` wrapper also takes, because both @@ -205,32 +279,40 @@ export async function startStone(): Promise { return; } logStep(`Starting the database`); - const env = engineEnvironment(); - const stoneLog = path.join(databaseLogPath(), `${STONE_NAME}.log`); - const logSizeBefore = fileSize(stoneLog); - try { - await runEngineCommand( - path.join(env.GEMSTONE, 'bin', 'startstone'), - ['-l', stoneLog, STONE_NAME], - env, - 'Start database', - ); - } catch (e) { - if (refusedNfs(e, stoneLog, logSizeBefore)) throw databaseOnNfsError(); - if (stoneLogSays(/No space left on device/, e, stoneLog, logSizeBefore)) { - throw new DiskSpaceError( - 'The GemDB database could not start: the disk ran out of space while it reserved ' + - 'its extent. Free some disk space, or set gemdb.rootPath to a folder on a disk ' + - 'with more room, then start GemDB again.', - ); - } - throw e; - } + await runStartstone(); }, { satisfied: isRunningAsync }, ); } +/** + * Run `startstone`, turning the two refusals the stone explains only in its + * log into errors that say what to do. The caller holds the stone lock. + */ +async function runStartstone(): Promise { + const env = engineEnvironment(); + const stoneLog = path.join(databaseLogPath(), `${STONE_NAME}.log`); + const logSizeBefore = fileSize(stoneLog); + try { + await runEngineCommand( + path.join(env.GEMSTONE, 'bin', 'startstone'), + ['-l', stoneLog, STONE_NAME], + env, + 'Start database', + ); + } catch (e) { + if (refusedNfs(e, stoneLog, logSizeBefore)) throw databaseOnNfsError(); + if (stoneLogSays(/No space left on device/, e, stoneLog, logSizeBefore)) { + throw new DiskSpaceError( + 'The GemDB database could not start: the disk ran out of space while it reserved ' + + 'its extent. Free some disk space, or set gemdb.rootPath to a folder on a disk ' + + 'with more room, then start GemDB again.', + ); + } + throw e; + } +} + /** * Whether the stone refused to start because its files are on NFS. * @@ -281,15 +363,18 @@ function fileSize(file: string): number { * Start the session listener. True when this call started it; false when * `startnetldi` refused because another process had started it first. * + * Not exported: the listener starts only through {@link ensureProcesses}, + * under the stone lock. + * * That race is not rare (#89): the window's start, the GemDB Shell's, and * releases before this one, which start the listener without any lock, can * all find it missing and start it together. The loser's `startnetldi` exits * 1 with "Server 'gemdbldi' is already running", and everything the caller * wanted is true, so a listener that is up and answering afterwards is not a - * failure. One that is not still fails with startnetldi's own words. + * failure. One that is not still fails with startnetldi's own words. The lock + * closes the race between GemDB's own callers; this covers what takes no lock. */ -export async function startNetldi(): Promise { - requireOwnDatabase('start'); +async function startNetldi(): Promise { logStep('Starting the session listener'); const env = engineEnvironment(); try { From 5aacb22061b599825a6911007eedd941b6fbc3fa Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Fri, 9 Oct 2026 16:02:09 -0300 Subject: [PATCH 03/14] Count the stone as up at OK, not as soon as gslist lists it gslist lists a stone from the moment it exists, including the Startup it sits in while recovering from a crash, so the lock's early exit and the start path took a stone that would refuse logins as ready. stoneReady/listenerReady ask for status OK; findStone and isRunning keep meaning "a process exists" for the status bar and maintenance. ensureProcesses and startStone wait for a listed stone to reach OK before going on (polled on the stone lock's cadence, for up to a minute), and end the lock wait only on OK. A stone that vanishes or is still starting after the timeout is an error naming the stone log. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 5 +++ src/__tests__/gslist.test.ts | 12 +++++ src/__tests__/startProcesses.test.ts | 59 +++++++++++++++++++++++-- src/lock.ts | 9 ++-- src/processes.ts | 65 +++++++++++++++++++++++++--- 5 files changed, 136 insertions(+), 14 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 1c02367..a463646 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -94,6 +94,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 database and its session listener were both running. GemDB now checks for and starts the session listener under the same lock as the database, so one start waits for the other, and a listener started by an older GemDB in another editor counts as started. +- **GemDB waits for a database that is still starting before logging in to it.** After a crash + the database takes a while to recover before it accepts logins, and GemDB treated it as running + as soon as it appeared, so the first notebook cell or the GemDB Shell could fail to log in. Starting + GemDB now waits for the database to finish starting, for up to a minute, and then names the + database's log if it has not. - **The GemDB Shell checks the database before starting it, as the window does.** Opening the Shell with the database stopped started it without the checks the window makes first, so a database the installed engine cannot read started and then refused every login, and one on a diff --git a/src/__tests__/gslist.test.ts b/src/__tests__/gslist.test.ts index af3dbbe..2c27948 100644 --- a/src/__tests__/gslist.test.ts +++ b/src/__tests__/gslist.test.ts @@ -77,6 +77,18 @@ describe('parseGslist', () => { expect(netldi.responding).toBe(false); }); + it('reads a stone that is still starting, listed but not yet responding', () => { + // A stone is listed from the moment it exists, and sits at `Startup` while + // it recovers from a crash; a login in that time fails. + const output = 'Startup 4.0.0.a4 jfoster 79386 51475 Sep 28 19:31 Stone gemdb'; + + const [stone] = parseGslist(output); + + expect(stone.name).toBe('gemdb'); + expect(stone.status).toBe('Startup'); + expect(stone.responding).toBe(false); + }); + it('treats anything other than OK as not responding', () => { const output = 'frozen 4.0.0.Alpha jfoster 56970 65107 Sep 11 16:46 Stone gemdb'; diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts index aee20f6..666f99e 100644 --- a/src/__tests__/startProcesses.test.ts +++ b/src/__tests__/startProcesses.test.ts @@ -62,7 +62,8 @@ vi.mock('../lock', async (importOriginal) => { }); const { expectedEnginePath } = await import('../paths'); -const { ensureProcesses } = await import('../processes'); +const { ensureProcesses, stoneReady, waitForStoneReady } = await import('../processes'); +const { parseGslist } = await import('../gslist'); function row(status: string, type: 'Stone' | 'Netldi', name: string): string { return `${status.padEnd(12)} 4.0.0.a4 me 79386 51475 Sep 28 19:31 ${type.padEnd(7)} ${name}`; @@ -70,6 +71,7 @@ function row(status: string, type: 'Stone' | 'Netldi', name: string): string { const STONE_UP = row('OK', 'Stone', 'gemdb'); const LISTENER_UP = row('OK', 'Netldi', 'gemdbldi'); +const STONE_STARTING = row('Startup', 'Stone', 'gemdb'); const BOTH_UP = [STONE_UP, LISTENER_UP].join('\n'); let root: string; @@ -103,7 +105,7 @@ describe('ensureProcesses', () => { }); it('starts both, guards first, when neither is up', async () => { - listings = ['', '', BOTH_UP]; + listings = ['', STONE_UP]; const beforeStoneStart = vi.fn(() => { expect(spawned).toEqual([]); }); @@ -153,7 +155,7 @@ describe('ensureProcesses', () => { // Both saw no listener; the other one won, so startnetldi refuses with // "already running" and the re-list shows the listener answering. exitCodes.startnetldi = 1; - listings = [STONE_UP, STONE_UP, BOTH_UP]; + listings = [STONE_UP, STONE_UP, STONE_UP, BOTH_UP]; const started = await ensureProcesses(); @@ -173,6 +175,7 @@ describe('ensureProcesses', () => { it('still fails a listener start that leaves a listener that is not answering', async () => { exitCodes.startnetldi = 1; listings = [ + STONE_UP, STONE_UP, STONE_UP, [STONE_UP, row('exe deleted', 'Netldi', 'gemdbldi')].join('\n'), @@ -192,6 +195,54 @@ describe('ensureProcesses', () => { expect(await check(BOTH_UP)).toBe(true); expect(await check(STONE_UP)).toBe(false); expect(await check(LISTENER_UP)).toBe(false); - expect(await check([row('Startup', 'Stone', 'gemdb'), LISTENER_UP].join('\n'))).toBe(false); + expect(await check([STONE_STARTING, LISTENER_UP].join('\n'))).toBe(false); + }); +}); + +describe('a stone that is still starting', () => { + it('is listed, but not ready for a login', () => { + const processes = parseGslist(STONE_STARTING); + + expect(processes).toHaveLength(1); + expect(stoneReady(processes)).toBe(false); + }); + + it('is waited for until it reports OK', async () => { + listings = [STONE_STARTING, STONE_STARTING, STONE_UP]; + const report = vi.fn(); + + await waitForStoneReady(report, { pollMs: 1 }); + + expect(report).toHaveBeenCalledWith('Waiting for the database to finish starting…'); + expect(listings).toEqual([STONE_UP]); + }); + + it('is given up on after the timeout, naming the stone’s log', async () => { + listings = [STONE_STARTING]; + + const wait = waitForStoneReady(undefined, { pollMs: 1, timeoutMs: 20 }); + + await expect(wait).rejects.toThrow(/starting for over a minute\. See .*gemdb\.log/); + }); + + it('is an error when it disappears instead of finishing', async () => { + listings = [STONE_STARTING, '']; + + const wait = waitForStoneReady(undefined, { pollMs: 1 }); + + await expect(wait).rejects.toThrow(/stopped while it was starting/); + }); + + it('holds back the listener until it is ready', async () => { + listings = [STONE_STARTING, STONE_STARTING, STONE_UP]; + const report = vi.fn(); + + const started = await ensureProcesses({ report }); + + expect(started).toEqual({ startedStone: false, startedNetldi: true }); + expect(report.mock.calls.map(([message]) => message)).toEqual([ + 'Waiting for the database to finish starting…', + 'Starting the session listener…', + ]); }); }); diff --git a/src/lock.ts b/src/lock.ts index df669b5..5c8398a 100644 --- a/src/lock.ts +++ b/src/lock.ts @@ -496,9 +496,12 @@ function stoneLockPath(): string { return path.join(rootPath(), STONE_LOCK_NAME); } -/** How often, and for how long, {@link withStoneLock} waits for the lock. */ -const STONE_LOCK_POLL_MS = 200; -const STONE_LOCK_TIMEOUT_MS = 60_000; +/** + * How often, and for how long, {@link withStoneLock} waits for the lock — + * and `waitForStoneReady` for a stone to finish starting. + */ +export const STONE_LOCK_POLL_MS = 200; +export const STONE_LOCK_TIMEOUT_MS = 60_000; /** * Run `work` while holding the stone lock, waiting for another process to diff --git a/src/processes.ts b/src/processes.ts index 1161a69..dc0f748 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -16,7 +16,7 @@ import { } from './config'; import { libraryPathVariable, sharedLibraryExtension } from './platform'; import { log, logStep } from './log'; -import { withStoneLock } from './lock'; +import { STONE_LOCK_POLL_MS, STONE_LOCK_TIMEOUT_MS, withStoneLock } from './lock'; import { DiskSpaceError, databaseOnNfsError } from './database'; import { EngineProcess, parseGslist } from './gslist'; import { databaseConfPath, databaseLogPath, databasePath, enginePath, grailPath } from './paths'; @@ -170,6 +170,55 @@ export function isListening(processes = listProcesses()): boolean { return findNetldi(processes) !== undefined; } +/** + * True when the stone has finished starting and will take a login. + * + * Not the same question as {@link isRunning}. `gslist` lists a stone from the + * moment it exists, and one recovering from a crash sits at `Startup` for as + * long as recovery takes; a login in that time fails. So whatever is about to + * log in waits for `OK`, while the status bar and maintenance, which ask + * whether there is a stone at all, keep asking that. + */ +export function stoneReady(processes: EngineProcess[]): boolean { + return findStone(processes)?.status === 'OK'; +} + +/** True when the listener is up and answering, the listener's half of {@link stoneReady}. */ +export function listenerReady(processes: EngineProcess[]): boolean { + return findNetldi(processes)?.status === 'OK'; +} + +/** + * Wait for a listed stone to finish starting. + * + * Returns at once for a stone that is ready. One this process did not start — + * a crash being recovered, or one an older GemDB started without waiting — is + * polled until it reports `OK`. A stone that disappears while we wait failed + * to start, and one still starting after a minute is not going to soon; both + * end in an error naming the stone's log, which says why. + */ +export async function waitForStoneReady( + report?: (message: string) => void, + wait: { pollMs?: number; timeoutMs?: number } = {}, +): Promise { + if (stoneReady(await listProcessesAsync())) return; + report?.('Waiting for the database to finish starting…'); + log('The database is still starting; waiting for it.'); + const stoneLog = path.join(databaseLogPath(), `${STONE_NAME}.log`); + const deadline = Date.now() + (wait.timeoutMs ?? STONE_LOCK_TIMEOUT_MS); + for (;;) { + await new Promise((resolve) => setTimeout(resolve, wait.pollMs ?? STONE_LOCK_POLL_MS)); + const running = await listProcessesAsync(); + if (stoneReady(running)) return; + if (!findStone(running)) { + throw new Error(`The database stopped while it was starting. See ${stoneLog}.`); + } + if (Date.now() > deadline) { + throw new Error(`The database has been starting for over a minute. See ${stoneLog}.`); + } + } +} + /** * Raised when something asks GemDB to start or stop a database it does not * run. See {@link externalDatabase} for why that is refused, not attempted. @@ -240,6 +289,7 @@ export async function ensureProcesses( } else { log('The database is already running.'); } + await waitForStoneReady(opts.report); let startedNetldi = false; if (!findNetldi(await listProcessesAsync())) { @@ -253,7 +303,7 @@ export async function ensureProcesses( { satisfied: async () => { const running = await listProcessesAsync(); - return findStone(running)?.status === 'OK' && findNetldi(running)?.status === 'OK'; + return stoneReady(running) && listenerReady(running); }, }, ); @@ -276,12 +326,13 @@ export async function startStone(): Promise { async () => { if (isRunning()) { log('The database is already running; nothing to start.'); - return; + } else { + logStep(`Starting the database`); + await runStartstone(); } - logStep(`Starting the database`); - await runStartstone(); + await waitForStoneReady(); }, - { satisfied: isRunningAsync }, + { satisfied: async () => stoneReady(await listProcessesAsync()) }, ); } @@ -396,7 +447,7 @@ async function startNetldi(): Promise { ); return true; } catch (e) { - if (findNetldi(await listProcessesAsync())?.status !== 'OK') throw e; + if (!listenerReady(await listProcessesAsync())) throw e; log('Another process started the session listener.'); return false; } From d917434966a08bee71b4891b66f772d381ed4c93 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Fri, 9 Oct 2026 16:58:34 -0300 Subject: [PATCH 04/14] Have the gemdb wrapper wait for the stone to reach OK stone_is_up split in two. stone_is_listed (plain gslist, as before) decides whether to run startstone, so a stone still at Startup is never started a second time beside itself. stone_is_ready (gslist -cvl, status OK) is what lets a command go on to log in: the top-level check, the lock loop's early exit, and a new wait of up to a minute for a listed stone to finish starting, which ends in an error naming the stone log if the stone disappears or never gets there. The wrapper's fingerprint changes, so existing bin/gemdb files are rewritten once. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 6 ++-- src/__tests__/cli.test.ts | 73 ++++++++++++++++++++++++++++++++++----- src/cli.ts | 42 ++++++++++++++++++---- 3 files changed, 102 insertions(+), 19 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a463646..efe37df 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -96,9 +96,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 started by an older GemDB in another editor counts as started. - **GemDB waits for a database that is still starting before logging in to it.** After a crash the database takes a while to recover before it accepts logins, and GemDB treated it as running - as soon as it appeared, so the first notebook cell or the GemDB Shell could fail to log in. Starting - GemDB now waits for the database to finish starting, for up to a minute, and then names the - database's log if it has not. + as soon as it appeared, so the first notebook cell, the GemDB Shell or a `gemdb` command could + fail to log in. GemDB and the `gemdb` command now wait for the database to finish starting, for up + to a minute, and then name the database's log if it has not. - **The GemDB Shell checks the database before starting it, as the window does.** Opening the Shell with the database stopped started it without the checks the window makes first, so a database the installed engine cannot read started and then refused every login, and one on a diff --git a/src/__tests__/cli.test.ts b/src/__tests__/cli.test.ts index 6439938..18bdfe0 100644 --- a/src/__tests__/cli.test.ts +++ b/src/__tests__/cli.test.ts @@ -310,9 +310,10 @@ describe('putCliOnPath', () => { * `gslist` showed one row for them because it keys Stone rows by name. * * The stubs stand in for the engine binaries the wrapper calls by absolute - * path. `startstone` records that it ran and leaves a marker; `gslist` reports - * a stone only once that marker exists, so a wrapper that re-checks after - * taking the lock sees what a real one would. + * path. `startstone` records that it ran and leaves a marker holding the + * stone's status; `gslist` reports a stone, with that status, only once the + * marker exists, so a wrapper that re-checks after taking the lock sees what + * a real one would. */ describe('starting the database', () => { function installEngineStubs(): { starts: string } { @@ -320,25 +321,53 @@ describe('starting the database', () => { fs.mkdirSync(bin, { recursive: true }); const marker = path.join(root, 'stone.up'); const starts = path.join(root, 'starts.log'); + const countdown = path.join(root, 'stone.countdown'); + const next = path.join(root, 'stone.next'); fs.writeFileSync( path.join(bin, 'gslist'), - `#!/bin/sh\n[ -f '${marker}' ] && echo 'exists 4.0.0 me 1 1 x Stone gemdb'\nexit 0\n`, + [ + '#!/bin/sh', + // A stone that changes state on its own: see stoneBecomes. + `if [ -f '${countdown}' ]; then`, + ` n=$(cat '${countdown}')`, + ` if [ "$n" -le 0 ]; then`, + ` rm -f '${countdown}'`, + ` if [ -f '${next}' ]; then mv '${next}' '${marker}'; else rm -f '${marker}'; fi`, + ` else echo $((n - 1)) > '${countdown}'; fi`, + 'fi', + `[ -f '${marker}' ] && echo "$(cat '${marker}') 4.0.0 me 1 1 x Stone gemdb"`, + 'exit 0', + '', + ].join('\n'), ); fs.writeFileSync( path.join(bin, 'startstone'), - `#!/bin/sh\nsleep 0.2\necho started >> '${starts}'\ntouch '${marker}'\nexit 0\n`, + `#!/bin/sh\nsleep 0.2\necho started >> '${starts}'\necho OK > '${marker}'\nexit 0\n`, ); fs.chmodSync(path.join(bin, 'gslist'), 0o755); fs.chmodSync(path.join(bin, 'startstone'), 0o755); return { starts }; } + /** + * Leave a stone at `status` that becomes `then` (or disappears, when + * undefined) after `calls` gslist calls — the wrapper's own pace rather than + * the clock's, since how long it takes to reach its stone checks varies. + */ + function stoneBecomes(status: string, then: string | undefined, calls: number): void { + fs.writeFileSync(path.join(root, 'stone.up'), status); + if (then !== undefined) fs.writeFileSync(path.join(root, 'stone.next'), then); + fs.writeFileSync(path.join(root, 'stone.countdown'), String(calls)); + } + /** Run the wrapper on a path that does not exist: it exits after the * stone-start block and before topaz, which is the part under test. */ - function runWrapper(): Promise { + function runWrapper(): Promise { return new Promise((resolve) => { - execFile(cliPath(), [path.join(root, 'nothing-here.py')], () => resolve()); + execFile(cliPath(), [path.join(root, 'nothing-here.py')], (_error, _stdout, stderr) => + resolve(stderr), + ); }); } @@ -378,7 +407,7 @@ describe('starting the database', () => { const lock = path.join(root, '.gemdb-stone.lock'); fs.mkdirSync(lock); // The "other process" finishes: the stone comes up while the wrapper waits. - setTimeout(() => fs.writeFileSync(path.join(root, 'stone.up'), ''), 300); + setTimeout(() => fs.writeFileSync(path.join(root, 'stone.up'), 'OK'), 300); await runWrapper(); @@ -407,7 +436,7 @@ describe('starting the database', () => { const lock = path.join(root, '.gemdb-stone.lock'); fs.writeFileSync( path.join(bin, 'startstone'), - `#!/bin/sh\necho ${process.pid} > '${lock}/pid'\ntouch '${path.join(root, 'stone.up')}'\nexit 0\n`, + `#!/bin/sh\necho ${process.pid} > '${lock}/pid'\necho OK > '${path.join(root, 'stone.up')}'\nexit 0\n`, ); await runWrapper(); @@ -465,4 +494,30 @@ describe('starting the database', () => { : 0; expect(started).toBe(1); }); + it('waits for a stone that is still starting instead of starting a second one', async () => { + // Listed at Startup with nobody holding the lock: a crash being recovered, + // or a start by a GemDB that does not wait for OK. + writeCliScripts(ext); + const { starts } = installEngineStubs(); + // Still starting for the first check, the re-check in the lock, and the + // first wait for it. + stoneBecomes('Startup', 'OK', 3); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(stderr).toContain('waiting for the database to finish starting'); + expect(stderr).toContain("can't open file"); + }); + + it('names the stone log when a stone that was starting disappears', async () => { + writeCliScripts(ext); + const { starts } = installEngineStubs(); + stoneBecomes('Startup', undefined, 3); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(stderr).toMatch(/stopped while it was starting\. See .*gemdb\.log/); + }); }); diff --git a/src/cli.ts b/src/cli.ts index 5850490..16fc7ce 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -473,21 +473,31 @@ fi # # mkdir is the primitive: it creates or fails, with no window between the test # and the claim, and it is there on a stock macOS where flock is not. -stone_is_up() { +# +# Two questions, kept apart. Whether a stone is LISTED decides whether to start +# one: a stone still at Startup -- recovering from a crash, or another +# process's start not finished -- is listed, and a second startstone beside it +# is the two-stones case above. Whether it is READY (status OK) decides whether +# a login can go ahead, so that is what the waiting is for. A two-word status +# such as "exe deleted" does not start with OK, so it is not ready either. +stone_is_listed() { "$GEMSTONE/bin/gslist" 2>/dev/null | awk -v s="$STONE" '$(NF-1) == "Stone" && $NF == s { found = 1 } END { exit !found }' } +stone_is_ready() { + "$GEMSTONE/bin/gslist" -cvl 2>/dev/null | awk -v s="$STONE" '$1 == "OK" && $(NF-1) == "Stone" && $NF == s { found = 1 } END { exit !found }' +} ${ external ? `# This machine's administrator runs the database, so a stopped stone is theirs # to start: starting it here would run it as this user. -if ! stone_is_up; then +if ! stone_is_listed; then echo "gemdb: the database (stone $STONE) is not running. It is run by this machine's administrator." >&2 exit 1 fi ` : '' -}if ! stone_is_up; then +}if ! stone_is_ready; then STONE_LOCK="$ROOT/.gemdb-stone.lock" # mkdir and the pid write are two steps, here and in the extension, so a # lock with no pid yet is one being taken right now. It is debris only once @@ -552,7 +562,7 @@ fi continue fi fi - stone_is_up && break + stone_is_ready && break sleep 0.1 tries=$((tries + 1)) done @@ -560,8 +570,9 @@ fi if [ -n "$held" ]; then # Re-check inside the lock. Between our first check and this one, whoever # we queued behind may have started it -- which is the case the bare - # check-then-act got wrong. - if ! stone_is_up; then + # check-then-act got wrong. Listed, not ready: one still starting is + # waited for below, never started again. + if ! stone_is_listed; then echo "gemdb: starting the database…" >&2 if ! "$GEMSTONE/bin/startstone" -l "$ROOT/db/log/$STONE.log" "$STONE" >/dev/null 2>&1; then release_stone_lock @@ -570,11 +581,28 @@ fi fi fi release_stone_lock - elif ! stone_is_up; then + elif ! stone_is_listed; then echo "gemdb: the database is not running and another process has been starting it for" >&2 echo "gemdb: ten seconds. See $ROOT/db/log/$STONE.log, or remove $STONE_LOCK if nothing is." >&2 exit 1 fi + + # Listed but not yet ready: ours or someone else's, it is still starting, and + # a login now would fail. A minute, as the extension waits. + ready_tries=0 + until stone_is_ready; do + if ! stone_is_listed; then + echo "gemdb: the database stopped while it was starting. See $ROOT/db/log/$STONE.log" >&2 + exit 1 + fi + if [ "$ready_tries" -ge 600 ]; then + echo "gemdb: the database has been starting for over a minute. See $ROOT/db/log/$STONE.log" >&2 + exit 1 + fi + [ "$ready_tries" -eq 0 ] && echo "gemdb: waiting for the database to finish starting…" >&2 + sleep 0.1 + ready_tries=$((ready_tries + 1)) + done fi # -c 'code': materialise the code as a file, like CPython's -c but visibly so. From 2925490ef8acc37898c679f62dd295c67da240f0 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Fri, 9 Oct 2026 16:59:25 -0300 Subject: [PATCH 05/14] Note in CLAUDE.md how the processes start and what ready means Co-Authored-By: Claude Opus 5.5 --- CLAUDE.md | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/CLAUDE.md b/CLAUDE.md index cbdf434..b227bda 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -55,6 +55,11 @@ in progress and gets its result, and only the first caller reports telemetry — except after a Stop: a caller other than auto-start arriving once a Stop began during that bring-up waits for the Stop and starts again. +Below it, the processes themselves start only through `ensureProcesses` in +`processes.ts`, which checks and starts under the stone lock (NetLDI cannot be +started any other way), and "ready" means gslist status `OK`, not "listed": a +stone at `Startup` is listed and refuses logins, so wait on it, never start it. + ## CI `.github/workflows/ci.yml`, two jobs split on what they need. `checks` runs From 1e4a5b93d95f04807a20a97e0316ea1576e4bf63 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Fri, 9 Oct 2026 17:08:05 -0300 Subject: [PATCH 06/14] Race two real processes through ensureProcesses in integration Two node processes run ensureProcesses() against one temp root at the same moment and must end with one stone and one NetLDI, both OK, with exactly one of them reporting that it started the stone. A second test reproduces 1.6.0 (#89): a raw, unlocked startnetldi timed to overlap ensureProcesses' own; the ensureProcesses side must not fail. The overlap showed the loser of a true race exits 3 ("could not start server", the winner's lock file exists), not 1 "already running", so the startNetldi comment now names both. Neither is matched on: the tolerance checks the listener, not the text. Co-Authored-By: Claude Opus 5.5 --- .../fixtures/processContender.ts | 87 ++++++++ src/__integration__/processes.test.ts | 189 ++++++++++++++++++ src/processes.ts | 9 +- 3 files changed, 281 insertions(+), 4 deletions(-) create mode 100644 src/__integration__/fixtures/processContender.ts create mode 100644 src/__integration__/processes.test.ts diff --git a/src/__integration__/fixtures/processContender.ts b/src/__integration__/fixtures/processContender.ts new file mode 100644 index 0000000..95c3772 --- /dev/null +++ b/src/__integration__/fixtures/processContender.ts @@ -0,0 +1,87 @@ +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { spawn } from 'child_process'; +import { NETLDI_NAME } from '../../config'; +import { databaseLogPath } from '../../paths'; +import { engineEnvironment, ensureProcesses } from '../../processes'; + +/** + * One process starting the database, run as a process of its own. + * + * processes.test.ts bundles this with the same `vscode` alias the shell bundle + * uses and starts two at once, because the race it covers is between + * processes: two windows, or a window and a GemDB Shell, that both find the + * database down. The root path arrives as GEMDB_ROOT_PATH, as it does for the + * real wrapper. + * + * argv: [rival log] + * + * `ensure` is what every start does today. `raw-netldi` is what GemDB 1.6.0 + * did: `startnetldi` with no lock and no look first (#89). + * + * It says it is ready, waits for the go file so both start at the same + * moment, then appends one line saying what happened to the report. + * + * Released together, the raw `startnetldi` finishes before the other process + * has taken the lock and looked, so that one finds the listener up and the + * two never collide. Given a rival's log, the raw one waits after the go file + * until the rival logs its own `startnetldi`, so both commands run at once. + */ +const [mode, readyFile, goFile, reportFile, rivalLog] = process.argv.slice(2); +const me = process.pid; + +const sleep = (ms: number): Promise => new Promise((resolve) => setTimeout(resolve, ms)); +const report = (line: string): void => fs.appendFileSync(reportFile, `${line}\n`); + +/** `startnetldi` exactly as 1.6.0 ran it; resolves with its exit code and output. */ +function rawStartNetldi(): Promise<{ code: number | null; output: string }> { + const env = engineEnvironment(); + return new Promise((resolve, reject) => { + const child = spawn( + path.join(env.GEMSTONE, 'bin', 'startnetldi'), + [ + '-a', + os.userInfo().username, + '-g', + '-l', + path.join(databaseLogPath(), `${NETLDI_NAME}.log`), + NETLDI_NAME, + ], + { env: { ...process.env, ...env } }, + ); + let output = ''; + child.stdout.on('data', (data: Buffer) => (output += data.toString())); + child.stderr.on('data', (data: Buffer) => (output += data.toString())); + child.on('close', (code) => resolve({ code, output })); + child.on('error', reject); + }); +} + +/** Wait until the rival logs that it is running `startnetldi`, or give up after a while. */ +async function rivalStartsNetldi(log: string): Promise { + const deadline = Date.now() + 20_000; + while (Date.now() < deadline) { + if (fs.existsSync(log) && fs.readFileSync(log, 'utf8').includes('$ startnetldi')) return; + await sleep(2); + } +} + +async function main(): Promise { + fs.appendFileSync(readyFile, `${me}\n`); + while (!fs.existsSync(goFile)) await sleep(2); + if (rivalLog) await rivalStartsNetldi(rivalLog); + + if (mode === 'ensure') { + const started = await ensureProcesses(); + report(JSON.stringify({ mode, pid: me, ...started })); + } else { + const { code, output } = await rawStartNetldi(); + report(JSON.stringify({ mode, pid: me, code, output: output.trim() })); + } +} + +main().catch((e: unknown) => { + report(JSON.stringify({ mode, pid: me, error: String(e) })); + process.exitCode = 1; +}); diff --git a/src/__integration__/processes.test.ts b/src/__integration__/processes.test.ts new file mode 100644 index 0000000..c474354 --- /dev/null +++ b/src/__integration__/processes.test.ts @@ -0,0 +1,189 @@ +import { afterAll, beforeAll, describe, expect, it } from 'vitest'; +import * as esbuild from 'esbuild'; +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { execFile } from 'child_process'; +import { createDatabase } from '../database'; +import { isSharedMemoryConfigured } from '../osConfig'; +import { + isListening, + isRunning, + listProcesses, + startStone, + stopNetldi, + stopStone, +} from '../processes'; +import { Fixture, limitTestDatabase, makeFixture } from './fixture'; + +/** + * Two processes starting one database at the same moment. + * + * Two windows opened together, or a window and a GemDB Shell, both find the + * database down and both start it. Checked and started outside a lock, both + * ran `startnetldi`, and the loser reported a failure over a database that was + * up (#89). The lock that closes that race keeps separate processes apart, so + * an in-process test cannot exercise it: these bundle processContender.ts the + * way lock.test.ts bundles its contender, and race real node processes against + * a real engine. + * + * No Python is needed, so the database is the engine's own extent and the + * file skips on a missing engine alone. + */ + +interface Report { + mode: 'ensure' | 'raw-netldi'; + pid: number; + startedStone?: boolean; + startedNetldi?: boolean; + code?: number | null; + output?: string; + error?: string; +} + +let fixture: Fixture | undefined; +let bundleDir: string | undefined; +let bundle = ''; + +beforeAll(async () => { + fixture = makeFixture(); + if (!fixture) return; + if (!(await isSharedMemoryConfigured())) { + throw new Error( + 'Shared memory is below what the engine needs. Run "GemDB: Configure Shared Memory" ' + + 'in the editor, or resources/setSharedMemoryDarwin.sh, before running these tests.', + ); + } + createDatabase(fixture.engine); + limitTestDatabase(); + + bundleDir = fs.mkdtempSync(path.join(os.tmpdir(), 'gemdb-contender-')); + bundle = path.join(bundleDir, 'processContender.cjs'); + await esbuild.build({ + entryPoints: [path.join(__dirname, 'fixtures', 'processContender.ts')], + bundle: true, + platform: 'node', + format: 'cjs', + outfile: bundle, + logLevel: 'silent', + alias: { vscode: path.join(__dirname, '..', 'cliVscode.ts') }, + }); +}); + +afterAll(async () => { + if (bundleDir) fs.rmSync(bundleDir, { recursive: true, force: true }); + if (!fixture) return; + try { + if (isListening()) await stopNetldi(); + if (isRunning()) await stopStone(true); + } finally { + fixture.remove(); + } +}); + +/** See database.test.ts — skipIf is evaluated during collection. */ +function canMakeFixture(): boolean { + const probe = makeFixture(); + if (!probe) return false; + probe.remove(); + return true; +} + +const sleep = (ms: number): Promise => new Promise((resolve) => setTimeout(resolve, ms)); + +/** + * Start one contender per mode, release them together, and return what each + * reported. A contender's log goes to a file beside the report, and a + * contender that exits non-zero rejects with that log, which is the only + * account of what it did. + */ +async function race( + modes: Report['mode'][], + opts: { rawWaitsForRival?: boolean } = {}, +): Promise { + const root = fixture!.root; + const dir = fs.mkdtempSync(path.join(root, 'race-')); + const ready = path.join(dir, 'ready'); + const go = path.join(dir, 'go'); + const reportFile = path.join(dir, 'report'); + fs.writeFileSync(ready, ''); + const logFile = (i: number): string => path.join(dir, `contender-${i}.log`); + const rivalLog = logFile(modes.indexOf('ensure')); + const exits = modes.map( + (mode, i) => + new Promise((resolve, reject) => { + const log = logFile(i); + const waitFor = mode === 'raw-netldi' && opts.rawWaitsForRival ? [rivalLog] : []; + const child = execFile( + process.execPath, + [bundle, mode, ready, go, reportFile, ...waitFor], + { env: { ...process.env, GEMDB_ROOT_PATH: root, GEMDB_SHELL_LOG: log } }, + (error, _stdout, stderr) => { + if (!error) return resolve(); + const logged = fs.existsSync(log) ? fs.readFileSync(log, 'utf8') : ''; + reject(new Error(`${mode} contender failed: ${stderr || String(error)}\n${logged}`)); + }, + ); + child.on('error', reject); + }), + ); + + // Release only once both are parked at the starting line, or the first + // would be done before the second had started. + const deadline = Date.now() + 20_000; + while (fs.readFileSync(ready, 'utf8').split('\n').filter(Boolean).length < modes.length) { + if (Date.now() > deadline) throw new Error('contenders never got ready'); + await sleep(10); + } + fs.writeFileSync(go, ''); + await Promise.all(exits); + + return fs + .readFileSync(reportFile, 'utf8') + .split('\n') + .filter(Boolean) + .map((line) => JSON.parse(line) as Report); +} + +/** What `gslist` lists, reduced to what the end state is judged on. */ +function listed(): { type: string; status: string }[] { + return listProcesses().map((p) => ({ type: p.type, status: p.status })); +} + +describe.skipIf(!canMakeFixture())('starting the database from two processes at once', () => { + it('starts one stone and one session listener, and neither process fails', async () => { + const reports = await race(['ensure', 'ensure']); + + expect(reports.filter((r) => r.error)).toEqual([]); + expect(reports).toHaveLength(2); + expect(reports.filter((r) => r.startedStone)).toHaveLength(1); + expect(listed()).toEqual( + expect.arrayContaining([ + { type: 'stone', status: 'OK' }, + { type: 'netldi', status: 'OK' }, + ]), + ); + expect(listed()).toHaveLength(2); + }); + + it('does not fail when a release that takes no lock starts the session listener alongside', async () => { + if (isListening()) await stopNetldi(); + await startStone(); + expect(isListening()).toBe(false); + + const reports = await race(['raw-netldi', 'ensure'], { rawWaitsForRival: true }); + + const ensured = reports.find((r) => r.mode === 'ensure'); + expect(ensured).toBeDefined(); + expect(ensured?.error).toBeUndefined(); + expect(ensured?.startedStone).toBe(false); + expect(reports.find((r) => r.mode === 'raw-netldi')?.error).toBeUndefined(); + expect(listed()).toEqual( + expect.arrayContaining([ + { type: 'stone', status: 'OK' }, + { type: 'netldi', status: 'OK' }, + ]), + ); + expect(listed()).toHaveLength(2); + }); +}); diff --git a/src/processes.ts b/src/processes.ts index dc0f748..4ef2ce9 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -419,10 +419,11 @@ function fileSize(file: string): number { * * That race is not rare (#89): the window's start, the GemDB Shell's, and * releases before this one, which start the listener without any lock, can - * all find it missing and start it together. The loser's `startnetldi` exits - * 1 with "Server 'gemdbldi' is already running", and everything the caller - * wanted is true, so a listener that is up and answering afterwards is not a - * failure. One that is not still fails with startnetldi's own words. The lock + * all find it missing and start it together. The loser's `startnetldi` fails + * — exit 1, "Server 'gemdbldi' is already running", when the winner is fully + * up; exit 3, "could not start server" over the winner's lock file, when the + * two overlap — and everything the caller wanted is true, so a listener that + * is up and answering afterwards is not a failure. One that is not still fails with startnetldi's own words. The lock * closes the race between GemDB's own callers; this covers what takes no lock. */ async function startNetldi(): Promise { From d8104d087040c3b9938966745a440b6d2759fe28 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:32:41 -0300 Subject: [PATCH 07/14] Read every gslist status, not just OK, before waiting on the stone Waiting for exactly "OK" turned every other listed status into a minute's wait ending in "starting for over a minute": "exe deleted" (a stone left running when the engine tree was replaced, which takes logins), "frozen", "full", and "Shutdown", which is a stop in progress. Main let all of those go on to the login. Only Startup and recovery are waited on now, Shutdown fails at once with a message that says so, and anything else goes on to the login as before. Statuses are compared without case because the engine prints them mixed. stoneReady/listenerReady use the parser's `responding` instead of a second spelling of the same test. The wrapper asks gslist -cvl once per check (a frozen stone makes each call take about five seconds) and branches on the status it printed. Co-Authored-By: Claude Opus 5.5 --- CLAUDE.md | 4 ++ src/__tests__/cli.test.ts | 44 +++++++++++++- src/__tests__/startProcesses.test.ts | 53 ++++++++++++++++- src/cli.ts | 86 ++++++++++++++++++---------- src/processes.ts | 83 +++++++++++++++++++++------ 5 files changed, 220 insertions(+), 50 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index b227bda..a1095ec 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -59,6 +59,10 @@ Below it, the processes themselves start only through `ensureProcesses` in `processes.ts`, which checks and starts under the stone lock (NetLDI cannot be started any other way), and "ready" means gslist status `OK`, not "listed": a stone at `Startup` is listed and refuses logins, so wait on it, never start it. +`stoneState` reads the rest, case-insensitively since the engine prints mixed +case: `Shutdown` fails at once, and any other listed status (`exe deleted`, +`frozen`, ...) goes on to the login as it always did. The wrapper in `cli.ts` +makes the same calls in shell; change both together. ## CI diff --git a/src/__tests__/cli.test.ts b/src/__tests__/cli.test.ts index 18bdfe0..d5a1f00 100644 --- a/src/__tests__/cli.test.ts +++ b/src/__tests__/cli.test.ts @@ -313,7 +313,7 @@ describe('putCliOnPath', () => { * path. `startstone` records that it ran and leaves a marker holding the * stone's status; `gslist` reports a stone, with that status, only once the * marker exists, so a wrapper that re-checks after taking the lock sees what - * a real one would. + * a real one would. Each `gslist` call is counted in `gslist.calls`. */ describe('starting the database', () => { function installEngineStubs(): { starts: string } { @@ -323,11 +323,13 @@ describe('starting the database', () => { const starts = path.join(root, 'starts.log'); const countdown = path.join(root, 'stone.countdown'); const next = path.join(root, 'stone.next'); + const calls = path.join(root, 'gslist.calls'); fs.writeFileSync( path.join(bin, 'gslist'), [ '#!/bin/sh', + `echo "$*" >> '${calls}'`, // A stone that changes state on its own: see stoneBecomes. `if [ -f '${countdown}' ]; then`, ` n=$(cat '${countdown}')`, @@ -336,7 +338,8 @@ describe('starting the database', () => { ` if [ -f '${next}' ]; then mv '${next}' '${marker}'; else rm -f '${marker}'; fi`, ` else echo $((n - 1)) > '${countdown}'; fi`, 'fi', - `[ -f '${marker}' ] && echo "$(cat '${marker}') 4.0.0 me 1 1 x Stone gemdb"`, + // The shape of a real -cvl row: status, version, owner, pid, port, date, type, name. + `[ -f '${marker}' ] && echo "$(cat '${marker}') 4.0.0.a4 me 1 1 Oct 13 15:57 Stone gemdb"`, 'exit 0', '', ].join('\n'), @@ -361,6 +364,13 @@ describe('starting the database', () => { fs.writeFileSync(path.join(root, 'stone.countdown'), String(calls)); } + function gslistCalls(): number { + const calls = path.join(root, 'gslist.calls'); + return fs.existsSync(calls) + ? fs.readFileSync(calls, 'utf8').split('\n').filter(Boolean).length + : 0; + } + /** Run the wrapper on a path that does not exist: it exits after the * stone-start block and before topaz, which is the part under test. */ function runWrapper(): Promise { @@ -520,4 +530,34 @@ describe('starting the database', () => { expect(fs.existsSync(starts)).toBe(false); expect(stderr).toMatch(/stopped while it was starting\. See .*gemdb\.log/); }); + + // Statuses the engine prints that are neither OK nor starting. They went on + // to the login before GemDB waited for OK, and still do: "exe deleted" is a + // stone left running when the engine tree was replaced, and it takes logins. + for (const status of ['exe deleted', 'frozen', 'full']) { + it(`goes on to the login for a stone that reads "${status}", asking once`, async () => { + writeCliScripts(ext); + const { starts } = installEngineStubs(); + fs.writeFileSync(path.join(root, 'stone.up'), status); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(gslistCalls()).toBe(1); + expect(stderr).toContain("can't open file"); + }); + } + + it('says a stone at Shutdown is shutting down, at once, rather than waiting on it', async () => { + writeCliScripts(ext); + const { starts } = installEngineStubs(); + fs.writeFileSync(path.join(root, 'stone.up'), 'Shutdown'); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(gslistCalls()).toBe(1); + expect(stderr).toContain('the database is shutting down'); + expect(stderr).not.toContain("can't open file"); + }); }); diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts index 666f99e..1a7e26c 100644 --- a/src/__tests__/startProcesses.test.ts +++ b/src/__tests__/startProcesses.test.ts @@ -62,7 +62,7 @@ vi.mock('../lock', async (importOriginal) => { }); const { expectedEnginePath } = await import('../paths'); -const { ensureProcesses, stoneReady, waitForStoneReady } = await import('../processes'); +const { ensureProcesses, stoneReady, stoneState, waitForStoneReady } = await import('../processes'); const { parseGslist } = await import('../gslist'); function row(status: string, type: 'Stone' | 'Netldi', name: string): string { @@ -246,3 +246,54 @@ describe('a stone that is still starting', () => { ]); }); }); + +describe('what the stone’s status means', () => { + const stateOf = (status: string): string => + stoneState(parseGslist(row(status, 'Stone', 'gemdb'))); + + it('reads the statuses the engine prints, whatever their case', () => { + expect(stateOf('OK')).toBe('ready'); + expect(stateOf('Startup')).toBe('starting'); + expect(stateOf('recovery')).toBe('starting'); + expect(stateOf('Shutdown')).toBe('stopping'); + expect(stoneState([])).toBe('absent'); + }); + + it('leaves every other listed status to the login, as before GemDB waited for OK', () => { + for (const status of ['exe deleted', 'frozen', 'full', 'killed', 'exists', 'restoreBkup']) { + expect(stateOf(status)).toBe('other'); + } + }); + + it('does not wait on a stone that is listed but neither OK nor starting', async () => { + listings = [row('exe deleted', 'Stone', 'gemdb')]; + + await waitForStoneReady(undefined, { pollMs: 1, timeoutMs: 20 }); + }); + + it('says a stone at Shutdown is shutting down, without waiting on it', async () => { + listings = [row('Shutdown', 'Stone', 'gemdb')]; + + await expect(waitForStoneReady(undefined, { pollMs: 1, timeoutMs: 1000 })).rejects.toThrow( + 'The database is shutting down', + ); + }); + + it('starts nothing beside a stone that is shutting down', async () => { + listings = [row('Shutdown', 'Stone', 'gemdb')]; + + await expect(ensureProcesses()).rejects.toThrow('The database is shutting down'); + expect(spawned).toEqual([]); + }); + + it('brings the listener up beside a stone in any other listed state', async () => { + listings = [row('exe deleted', 'Stone', 'gemdb')]; + const beforeStoneStart = vi.fn(); + + const started = await ensureProcesses({ beforeStoneStart }); + + expect(started).toEqual({ startedStone: false, startedNetldi: true }); + expect(spawned).toEqual(['startnetldi']); + expect(beforeStoneStart).not.toHaveBeenCalled(); + }); +}); diff --git a/src/cli.ts b/src/cli.ts index 16fc7ce..52cc574 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -474,30 +474,64 @@ fi # mkdir is the primitive: it creates or fails, with no window between the test # and the claim, and it is there on a stock macOS where flock is not. # -# Two questions, kept apart. Whether a stone is LISTED decides whether to start -# one: a stone still at Startup -- recovering from a crash, or another -# process's start not finished -- is listed, and a second startstone beside it -# is the two-stones case above. Whether it is READY (status OK) decides whether -# a login can go ahead, so that is what the waiting is for. A two-word status -# such as "exe deleted" does not start with OK, so it is not ready either. -stone_is_listed() { - "$GEMSTONE/bin/gslist" 2>/dev/null | awk -v s="$STONE" '$(NF-1) == "Stone" && $NF == s { found = 1 } END { exit !found }' +# What the stone's status says decides what to do. Not listed: start one. A +# stone still at Startup -- recovering from a crash, or another process's start +# not finished -- is listed, and a second startstone beside it is the +# two-stones case above, so it is waited for until it is past Startup, since a +# login now would fail. One at Shutdown is being stopped, and saying so beats +# waiting a minute for it. Anything else goes on to the login, which judges it: +# a stone left running when the engine tree was replaced reads "exe deleted" +# and takes logins. +# +# The status as gslist -cvl lists it, lowercased (the engine prints "OK", +# "Startup", "frozen"), or nothing when the stone is not listed. One call per +# question: -v asks the stone itself, which takes about five seconds when it is +# frozen (measured). A row is status, version, owner, pid, port, three date +# fields, type and name, and "exe deleted" is the one two-word status. A row of +# any other shape is still this stone, so it answers something: nothing would +# mean "start one". +stone_status() { + "$GEMSTONE/bin/gslist" -cvl 2>/dev/null | awk -v s="$STONE" '$(NF-1) == "Stone" && $NF == s { print tolower(NF == 10 ? $1 : NF == 11 ? $1 " " $2 : "listed"); exit }' +} +starting() { case "$1" in startup|recovery) return 0 ;; *) return 1 ;; esac; } +shutting_down() { + echo "gemdb: the database is shutting down. Run this again once it has stopped." >&2 + exit 1 } -stone_is_ready() { - "$GEMSTONE/bin/gslist" -cvl 2>/dev/null | awk -v s="$STONE" '$1 == "OK" && $(NF-1) == "Stone" && $NF == s { found = 1 } END { exit !found }' +# Wait while the stone is starting, from the status last seen ($1). $2 is where +# to look when it fails. +wait_for_stone() { + local st="$1" tries=0 + while starting "$st"; do + if [ "$tries" -ge 600 ]; then + echo "gemdb: the database has been starting for over a minute.$2" >&2 + exit 1 + fi + [ "$tries" -eq 0 ] && echo "gemdb: waiting for the database to finish starting…" >&2 + sleep 0.1 + tries=$((tries + 1)) + st=$(stone_status) + done + [ "$st" = shutdown ] && shutting_down + if [ -z "$st" ]; then + echo "gemdb: the database stopped while it was starting.$2" >&2 + exit 1 + fi } +STATUS=$(stone_status) ${ external ? `# This machine's administrator runs the database, so a stopped stone is theirs # to start: starting it here would run it as this user. -if ! stone_is_listed; then +if [ -z "$STATUS" ]; then echo "gemdb: the database (stone $STONE) is not running. It is run by this machine's administrator." >&2 exit 1 fi ` : '' -}if ! stone_is_ready; then +}[ "$STATUS" = shutdown ] && shutting_down +if [ -z "$STATUS" ] || starting "$STATUS"; then STONE_LOCK="$ROOT/.gemdb-stone.lock" # mkdir and the pid write are two steps, here and in the extension, so a # lock with no pid yet is one being taken right now. It is debris only once @@ -562,7 +596,8 @@ fi continue fi fi - stone_is_ready && break + STATUS=$(stone_status) + [ -n "$STATUS" ] && ! starting "$STATUS" && break sleep 0.1 tries=$((tries + 1)) done @@ -572,37 +607,26 @@ fi # we queued behind may have started it -- which is the case the bare # check-then-act got wrong. Listed, not ready: one still starting is # waited for below, never started again. - if ! stone_is_listed; then + STATUS=$(stone_status) + if [ -z "$STATUS" ]; then echo "gemdb: starting the database…" >&2 if ! "$GEMSTONE/bin/startstone" -l "$ROOT/db/log/$STONE.log" "$STONE" >/dev/null 2>&1; then release_stone_lock echo "gemdb: the database at $ROOT could not be started. See $ROOT/db/log/$STONE.log" >&2 exit 1 fi + STATUS=$(stone_status) fi release_stone_lock - elif ! stone_is_listed; then + elif [ -z "$STATUS" ]; then echo "gemdb: the database is not running and another process has been starting it for" >&2 echo "gemdb: ten seconds. See $ROOT/db/log/$STONE.log, or remove $STONE_LOCK if nothing is." >&2 exit 1 fi - # Listed but not yet ready: ours or someone else's, it is still starting, and - # a login now would fail. A minute, as the extension waits. - ready_tries=0 - until stone_is_ready; do - if ! stone_is_listed; then - echo "gemdb: the database stopped while it was starting. See $ROOT/db/log/$STONE.log" >&2 - exit 1 - fi - if [ "$ready_tries" -ge 600 ]; then - echo "gemdb: the database has been starting for over a minute. See $ROOT/db/log/$STONE.log" >&2 - exit 1 - fi - [ "$ready_tries" -eq 0 ] && echo "gemdb: waiting for the database to finish starting…" >&2 - sleep 0.1 - ready_tries=$((ready_tries + 1)) - done + # Ours or someone else's, a stone still starting is waited for: a login now + # would fail. A minute, as the extension waits. + wait_for_stone "$STATUS" " See $ROOT/db/log/$STONE.log" fi # -c 'code': materialise the code as a file, like CPython's -c but visibly so. diff --git a/src/processes.ts b/src/processes.ts index 4ef2ce9..3193060 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -180,42 +180,88 @@ export function isListening(processes = listProcesses()): boolean { * whether there is a stone at all, keep asking that. */ export function stoneReady(processes: EngineProcess[]): boolean { - return findStone(processes)?.status === 'OK'; + return findStone(processes)?.responding === true; } /** True when the listener is up and answering, the listener's half of {@link stoneReady}. */ export function listenerReady(processes: EngineProcess[]): boolean { - return findNetldi(processes)?.status === 'OK'; + return findNetldi(processes)?.responding === true; } +/** + * What to do about the stone, from its gslist status. + * + * The engine prints statuses in mixed case — `OK`, `Startup`, `Shutdown`, + * `frozen`, `killed`, `exists`, `exe deleted` were all seen — and `gslist -h` + * also lists `recovery`, `full`, `restoreBkup`, `restoreLogs` and + * `contRestore`, so they are compared without case. Only a stone that is + * starting is worth waiting for. One shutting down is said to be, rather than + * waited on for a minute. Anything else that is listed goes on to the login, + * which judges it, as it did before GemDB waited for `OK`: a stone left + * running when the engine tree was replaced reads `exe deleted` and takes + * logins, and refusing it would stop a working database. + */ +export type StoneState = 'absent' | 'ready' | 'starting' | 'stopping' | 'other'; + +export function stoneState(processes: EngineProcess[]): StoneState { + const stone = findStone(processes); + if (!stone) return 'absent'; + if (stone.responding) return 'ready'; + switch (stone.status.toLowerCase()) { + case 'startup': + case 'recovery': + return 'starting'; + case 'shutdown': + return 'stopping'; + default: + return 'other'; + } +} + +/** What to say about a stone that is on its way down, wherever it is met. */ +export const SHUTTING_DOWN_MESSAGE = + 'The database is shutting down. Start it again once it has stopped.'; + /** * Wait for a listed stone to finish starting. * - * Returns at once for a stone that is ready. One this process did not start — - * a crash being recovered, or one an older GemDB started without waiting — is - * polled until it reports `OK`. A stone that disappears while we wait failed - * to start, and one still starting after a minute is not going to soon; both - * end in an error naming the stone's log, which says why. + * Returns at once for a stone that is not starting. One this process did not + * start — a crash being recovered, or one an older GemDB started without + * waiting — is polled until it is past `Startup`. A stone that disappears + * while we wait failed to start, and one still starting after a minute is not + * going to soon; both end in an error naming the stone's log, which says why. + * A stone at `Shutdown` ends the wait at once: it is being stopped. */ export async function waitForStoneReady( report?: (message: string) => void, wait: { pollMs?: number; timeoutMs?: number } = {}, ): Promise { - if (stoneReady(await listProcessesAsync())) return; - report?.('Waiting for the database to finish starting…'); - log('The database is still starting; waiting for it.'); const stoneLog = path.join(databaseLogPath(), `${STONE_NAME}.log`); const deadline = Date.now() + (wait.timeoutMs ?? STONE_LOCK_TIMEOUT_MS); + let running = await listProcessesAsync(); + let waiting = false; for (;;) { - await new Promise((resolve) => setTimeout(resolve, wait.pollMs ?? STONE_LOCK_POLL_MS)); - const running = await listProcessesAsync(); - if (stoneReady(running)) return; - if (!findStone(running)) { - throw new Error(`The database stopped while it was starting. See ${stoneLog}.`); + switch (stoneState(running)) { + case 'ready': + case 'other': + return; + case 'stopping': + throw new Error(SHUTTING_DOWN_MESSAGE); + case 'absent': + throw new Error(`The database stopped while it was starting. See ${stoneLog}.`); + case 'starting': + break; + } + if (!waiting) { + waiting = true; + report?.('Waiting for the database to finish starting…'); + log('The database is still starting; waiting for it.'); } if (Date.now() > deadline) { throw new Error(`The database has been starting for over a minute. See ${stoneLog}.`); } + await new Promise((resolve) => setTimeout(resolve, wait.pollMs ?? STONE_LOCK_POLL_MS)); + running = await listProcessesAsync(); } } @@ -280,7 +326,12 @@ export async function ensureProcesses( const started = await withStoneLock( async () => { let startedStone = false; - if (!findStone(await listProcessesAsync())) { + const state = stoneState(await listProcessesAsync()); + // Said here, before any wait: a stopping stone's last moments read + // `Startup` before it disappears (measured), which a wait would report + // as a start that failed. + if (state === 'stopping') throw new Error(SHUTTING_DOWN_MESSAGE); + if (state === 'absent') { opts.beforeStoneStart?.(); opts.report?.('Starting the database…'); logStep('Starting the database'); From 2ec1b1b991b02a548ab01087334c30e14b0cca11 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:33:33 -0300 Subject: [PATCH 08/14] Time the wrapper's waits by the clock instead of counting polls The ready wait was 600 polls of 0.1 s and the lock wait 100, each poll a gslist call. Against a frozen stone every -cvl call takes about five seconds, so "a minute" became most of an hour. Both waits now end at a date +%s deadline, one gslist per iteration. Co-Authored-By: Claude Opus 5.5 --- src/cli.ts | 15 +++++++-------- 1 file changed, 7 insertions(+), 8 deletions(-) diff --git a/src/cli.ts b/src/cli.ts index 52cc574..4ad4576 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -499,17 +499,17 @@ shutting_down() { exit 1 } # Wait while the stone is starting, from the status last seen ($1). $2 is where -# to look when it fails. +# to look when it fails. Waits are timed by the clock, not by counting polls: +# each poll is a gslist call, and those vary from milliseconds to seconds. wait_for_stone() { - local st="$1" tries=0 + local st="$1" deadline=$(( $(date +%s) + 60 )) said="" while starting "$st"; do - if [ "$tries" -ge 600 ]; then + if [ "$(date +%s)" -ge "$deadline" ]; then echo "gemdb: the database has been starting for over a minute.$2" >&2 exit 1 fi - [ "$tries" -eq 0 ] && echo "gemdb: waiting for the database to finish starting…" >&2 + [ -z "$said" ] && said=1 && echo "gemdb: waiting for the database to finish starting…" >&2 sleep 0.1 - tries=$((tries + 1)) st=$(stone_status) done [ "$st" = shutdown ] && shutting_down @@ -576,8 +576,8 @@ if [ -z "$STATUS" ] || starting "$STATUS"; then return "$took" } held="" - tries=0 - while [ "$tries" -lt 100 ]; do + lock_deadline=$(( $(date +%s) + 10 )) + while [ "$(date +%s)" -lt "$lock_deadline" ]; do if mkdir "$STONE_LOCK" 2>/dev/null; then held=yes echo $$ > "$STONE_LOCK/pid" 2>/dev/null @@ -599,7 +599,6 @@ if [ -z "$STATUS" ] || starting "$STATUS"; then STATUS=$(stone_status) [ -n "$STATUS" ] && ! starting "$STATUS" && break sleep 0.1 - tries=$((tries + 1)) done if [ -n "$held" ]; then From c35d083cd088c48e2ab2578591f359918ac7ddbf Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:35:13 -0300 Subject: [PATCH 09/14] Generate no lock and no start for an external database in the wrapper For an external database the wrapper checked that the stone was listed and then fell into the same block as GemDB's own: a stone at Startup took the lock in GemDB's root path and, had it disappeared meanwhile, ran startstone as this user on the administrator's stone, logging to a GemDB path that does not describe it. GemDB never starts someone else's database. The external branch is now only: not listed fails as before, Shutdown fails, starting is waited for (by the clock), anything else proceeds. Co-Authored-By: Claude Opus 5.5 --- src/__tests__/cli.test.ts | 62 ++++++++++++++++++++++++++++++++++++++- src/cli.ts | 12 ++++---- 2 files changed, 68 insertions(+), 6 deletions(-) diff --git a/src/__tests__/cli.test.ts b/src/__tests__/cli.test.ts index d5a1f00..5d63f29 100644 --- a/src/__tests__/cli.test.ts +++ b/src/__tests__/cli.test.ts @@ -3,7 +3,7 @@ import * as fs from 'fs'; import * as os from 'os'; import * as path from 'path'; import { afterEach, beforeEach, describe, expect, it } from 'vitest'; -import { __setSetting } from '../__mocks__/vscode'; +import { __resetSettings, __setSetting } from '../__mocks__/vscode'; import { cliPath, ensureCliCurrent, putCliOnPath, writeCliScripts } from '../cli'; import { STONE_LOCK_NAME } from '../lock'; import { cliStampPath, expectedEnginePath } from '../paths'; @@ -35,6 +35,7 @@ function makeExtensionDir(): string { } beforeEach(() => { + __resetSettings(); root = fs.mkdtempSync(path.join(os.tmpdir(), 'gemdb-cli-')); ext = makeExtensionDir(); __setSetting('gemdb.rootPath', root); @@ -560,4 +561,63 @@ describe('starting the database', () => { expect(stderr).toContain('the database is shutting down'); expect(stderr).not.toContain("can't open file"); }); + + describe('for a database this machine’s administrator runs', () => { + /** The stubbed engine, configured as someone else's, with a stone named as the stubs name it. */ + function external(): void { + __setSetting('gemdb.externalDatabase.gemstone', expectedEnginePath()); + __setSetting('gemdb.externalDatabase.globalDirectory', root); + __setSetting('gemdb.externalDatabase.stone', 'gemdb'); + } + + const lock = (): string => path.join(root, STONE_LOCK_NAME); + + it('starts nothing and takes no lock when the stone is not running', async () => { + external(); + writeCliScripts(ext); + const { starts } = installEngineStubs(); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(fs.existsSync(lock())).toBe(false); + expect(stderr).toContain("It is run by this machine's administrator"); + }); + + it('waits for a stone that is still starting, and never starts one', async () => { + external(); + writeCliScripts(ext); + const { starts } = installEngineStubs(); + stoneBecomes('Startup', 'OK', 2); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(fs.existsSync(lock())).toBe(false); + expect(stderr).toContain('waiting for the database to finish starting'); + expect(stderr).toContain("can't open file"); + }); + + it('does not start a stone that disappears while starting, or point at a log of ours', async () => { + external(); + writeCliScripts(ext); + const { starts } = installEngineStubs(); + stoneBecomes('Startup', undefined, 2); + + const stderr = await runWrapper(); + + expect(fs.existsSync(starts)).toBe(false); + expect(stderr).toContain('stopped while it was starting.'); + expect(stderr).not.toContain('gemdb.log'); + }); + + it('generates no way to reach startstone at all', () => { + external(); + writeCliScripts(ext); + + const wrapper = fs.readFileSync(cliPath(), 'utf8'); + expect(wrapper).not.toContain('bin/startstone'); + expect(wrapper).not.toContain(STONE_LOCK_NAME); + }); + }); }); diff --git a/src/cli.ts b/src/cli.ts index 4ad4576..d90863c 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -520,18 +520,19 @@ wait_for_stone() { } STATUS=$(stone_status) +[ "$STATUS" = shutdown ] && shutting_down ${ external ? `# This machine's administrator runs the database, so a stopped stone is theirs -# to start: starting it here would run it as this user. +# to start: starting it here would run it as this user. So no lock and no +# start, only a wait for one that is still starting. if [ -z "$STATUS" ]; then echo "gemdb: the database (stone $STONE) is not running. It is run by this machine's administrator." >&2 exit 1 fi +wait_for_stone "$STATUS" "" ` - : '' -}[ "$STATUS" = shutdown ] && shutting_down -if [ -z "$STATUS" ] || starting "$STATUS"; then + : `if [ -z "$STATUS" ] || starting "$STATUS"; then STONE_LOCK="$ROOT/.gemdb-stone.lock" # mkdir and the pid write are two steps, here and in the extension, so a # lock with no pid yet is one being taken right now. It is debris only once @@ -627,7 +628,8 @@ if [ -z "$STATUS" ] || starting "$STATUS"; then # would fail. A minute, as the extension waits. wait_for_stone "$STATUS" " See $ROOT/db/log/$STONE.log" fi - +` +} # -c 'code': materialise the code as a file, like CPython's -c but visibly so. # mktemp is given an explicit template — BSD and GNU disagree about -t. CODE_FILE="" From 6c447af8e21109e9d8b85b3d2345fa59012c753e Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:36:22 -0300 Subject: [PATCH 10/14] Put back only the listener after a declined force-stop Declining "Stop Anyway" restarted the listener through ensureProcesses, which starts whatever is missing. If the stone finished stopping while the modal was up, that started it again: a database the user had just stopped, brought back without the pre-start guards or statmonitor. ensureListener starts the listener under the stone lock and nothing else, and does nothing when the stone is gone or shutting down. runStop also re-checks the stone after the answer and reports a stone that went away as stopped. Co-Authored-By: Claude Opus 5.5 --- CLAUDE.md | 3 ++- src/__tests__/startProcesses.test.ts | 33 +++++++++++++++++++++++++- src/__tests__/stop.test.ts | 21 +++++++++++++++++ src/lifecycle.ts | 13 ++++++++--- src/processes.ts | 35 ++++++++++++++++++++++++---- 5 files changed, 95 insertions(+), 10 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index a1095ec..84b8017 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -57,7 +57,8 @@ during that bring-up waits for the Stop and starts again. Below it, the processes themselves start only through `ensureProcesses` in `processes.ts`, which checks and starts under the stone lock (NetLDI cannot be -started any other way), and "ready" means gslist status `OK`, not "listed": a +started any other way; `ensureListener` is the listener-only door a declined +force-stop uses), and "ready" means gslist status `OK`, not "listed": a stone at `Startup` is listed and refuses logins, so wait on it, never start it. `stoneState` reads the rest, case-insensitively since the engine prints mixed case: `Shutdown` fails at once, and any other listed status (`exe deleted`, diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts index 1a7e26c..6f99ede 100644 --- a/src/__tests__/startProcesses.test.ts +++ b/src/__tests__/startProcesses.test.ts @@ -62,7 +62,8 @@ vi.mock('../lock', async (importOriginal) => { }); const { expectedEnginePath } = await import('../paths'); -const { ensureProcesses, stoneReady, stoneState, waitForStoneReady } = await import('../processes'); +const { ensureListener, ensureProcesses, stoneReady, stoneState, waitForStoneReady } = + await import('../processes'); const { parseGslist } = await import('../gslist'); function row(status: string, type: 'Stone' | 'Netldi', name: string): string { @@ -297,3 +298,33 @@ describe('what the stone’s status means', () => { expect(beforeStoneStart).not.toHaveBeenCalled(); }); }); + +describe('putting the listener back after a declined force-stop', () => { + it('starts the listener beside a stone that is still up', async () => { + listings = [STONE_UP]; + + expect(await ensureListener()).toBe(true); + expect(spawned).toEqual(['startnetldi']); + }); + + it('starts nothing when the stone went away while the user was deciding', async () => { + listings = ['']; + + expect(await ensureListener()).toBe(false); + expect(spawned).toEqual([]); + }); + + it('starts nothing beside a stone that is shutting down', async () => { + listings = [row('Shutdown', 'Stone', 'gemdb')]; + + expect(await ensureListener()).toBe(false); + expect(spawned).toEqual([]); + }); + + it('starts nothing when the listener is already back', async () => { + listings = [BOTH_UP]; + + expect(await ensureListener()).toBe(false); + expect(spawned).toEqual([]); + }); +}); diff --git a/src/__tests__/stop.test.ts b/src/__tests__/stop.test.ts index 5f08d8a..71156d9 100644 --- a/src/__tests__/stop.test.ts +++ b/src/__tests__/stop.test.ts @@ -37,6 +37,8 @@ function makeWorld(options: { stoneRefuses?: boolean; /** Fail the stop but go down anyway, the way a timeout does. */ stoneStopsLate?: boolean; + /** Finish stopping while the question is up, as a refused stop that was already under way can. */ + stoneStopsDuringQuestion?: boolean; confirm?: boolean; }): { calls: string[]; world: StopWorld } { let stoneUp = options.stoneUp ?? true; @@ -75,6 +77,7 @@ function makeWorld(options: { }, confirmForce: () => { calls.push('confirmForce'); + if (options.stoneStopsDuringQuestion) stoneUp = false; return Promise.resolve(options.confirm ?? false); }, log: () => {}, @@ -126,6 +129,24 @@ describe('runStop', () => { ]); }); + it('puts nothing back when the stone stopped while the user was deciding', async () => { + // Starting the listener now would, through ensureProcesses, start the stone + // the user had just stopped, without any of a start's guards. + const { calls, world } = makeWorld({ + stoneRefuses: true, + stoneStopsDuringQuestion: true, + confirm: false, + }); + await runStop(world); + expect(calls).toEqual([ + 'logout', + 'stopMcpServer', + 'stopNetldi', + 'stopStone(false)', + 'confirmForce', + ]); + }); + it('forces only after the user confirms', async () => { const { calls, world } = makeWorld({ stoneRefuses: true, confirm: true }); await runStop(world); diff --git a/src/lifecycle.ts b/src/lifecycle.ts index 801412b..d83e13d 100644 --- a/src/lifecycle.ts +++ b/src/lifecycle.ts @@ -52,6 +52,7 @@ import { mcpPath, } from './paths'; import { + ensureListener, ensureProcesses, externalDatabaseDownError, findNetldi, @@ -901,7 +902,12 @@ export async function runStop(world: StopWorld): Promise { if (!(await world.confirmForce(reason))) { // Declining means "leave it running", and a running database with no // listener accepts no new sessions — so put back what we stopped on the - // way in rather than leaving a half-stopped machine behind. + // way in rather than leaving a half-stopped machine behind. Unless it + // finished stopping while the question was up: then it is stopped. + if (!world.stoneUp()) { + world.log('GemDB stopped.'); + return; + } if (!world.listenerUp()) await world.startNetldi(); world.log('GemDB is still running.'); return; @@ -945,8 +951,9 @@ async function stopOnce(): Promise { stopStone, stopNetldi, // Through the lock, like every other start: the window that declined - // is not the only one that may be putting the listener back. - startNetldi: () => ensureProcesses(), + // is not the only one that may be putting the listener back. The + // listener only: a stone gone by now is not this call's to restart. + startNetldi: () => ensureListener(), confirmForce, log, }); diff --git a/src/processes.ts b/src/processes.ts index 3193060..1bdb987 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -304,9 +304,9 @@ export function externalDatabaseDownError(external: { * Bring up whichever of the stone and the session listener is not already * up, and say which of them this call started. * - * Every start of GemDB's own database goes through here — the window's, the - * GemDB Shell's, and the listener a declined force-stop puts back — and all - * of it happens under the stone lock the `gemdb` wrapper also takes. Checking + * Every start of GemDB's own database goes through here — the window's and + * the GemDB Shell's (the listener a declined force-stop puts back goes through + * {@link ensureListener}) — and all of it happens under the stone lock the `gemdb` wrapper also takes. Checking * and starting have to be one step: checked outside the lock, two callers * that both found the listener missing both ran `startnetldi`, and the loser * reported a failure over a database that was up. So the look happens inside @@ -361,6 +361,31 @@ export async function ensureProcesses( return started ?? { startedStone: false, startedNetldi: false }; } +/** + * Put the session listener back, and never the stone: what a declined + * force-stop needs. By the time the user has answered, the stone may have gone + * after all, or be on its way down, and starting one then would undo a stop + * without the guards a start runs. True when this call started the listener. + * Under the stone lock, like every other start. + */ +export async function ensureListener(): Promise { + requireOwnDatabase('start'); + const started = await withStoneLock( + async () => { + const running = await listProcessesAsync(); + const state = stoneState(running); + if (state === 'absent' || state === 'stopping') { + log('The database is not running; not starting the session listener.'); + return false; + } + if (findNetldi(running)) return false; + return startNetldi(); + }, + { satisfied: async () => findNetldi(await listProcessesAsync()) !== undefined }, + ); + return started ?? false; +} + /** * Start the stone alone, for what needs no session listener: the `gemdb` * wrapper's file runs are linked sessions, and so are the tests that use this. @@ -465,8 +490,8 @@ function fileSize(file: string): number { * Start the session listener. True when this call started it; false when * `startnetldi` refused because another process had started it first. * - * Not exported: the listener starts only through {@link ensureProcesses}, - * under the stone lock. + * Not exported: the listener starts only through {@link ensureProcesses} or + * {@link ensureListener}, under the stone lock. * * That race is not rare (#89): the window's start, the GemDB Shell's, and * releases before this one, which start the listener without any lock, can From 14380ca7c08fa0c42492f9c773b17806a06433ae Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:38:01 -0300 Subject: [PATCH 11/14] Skip the stone lock when both processes are already up ensureRunning runs before every notebook cell, and with the lock in place each call made three gslist calls and a lock round trip to learn that nothing needed starting; main made one. A listing before the lock now returns at once when the stone is up (or in a state left to the login) and the listener is listed. A stone starting or stopping always takes the lock, and inside it the processes are listed again, since the first look may be stale by then. The listener is judged from waitForStoneReady's last listing, so a cold start makes no more gslist calls than it did before. Co-Authored-By: Claude Opus 5.5 --- src/__tests__/startProcesses.test.ts | 51 +++++++++++++++++++++++++--- src/processes.ts | 24 ++++++++++--- 2 files changed, 66 insertions(+), 9 deletions(-) diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts index 6f99ede..4817ee2 100644 --- a/src/__tests__/startProcesses.test.ts +++ b/src/__tests__/startProcesses.test.ts @@ -14,10 +14,12 @@ import { __log, __resetSettings, __setSetting } from '../__mocks__/vscode'; */ let listings: string[] = []; +let gslistCalls = 0; const exitCodes: Record = {}; const spawned: string[] = []; function gslist(): string { + gslistCalls++; return listings.length > 1 ? (listings.shift() ?? '') : (listings[0] ?? ''); } @@ -84,6 +86,7 @@ beforeEach(() => { fs.mkdirSync(path.join(expectedEnginePath(), 'bin'), { recursive: true }); fs.writeFileSync(path.join(expectedEnginePath(), 'bin', 'gslist'), ''); listings = []; + gslistCalls = 0; spawned.length = 0; satisfied = undefined; for (const key of Object.keys(exitCodes)) delete exitCodes[key]; @@ -105,8 +108,47 @@ describe('ensureProcesses', () => { expect(beforeStoneStart).not.toHaveBeenCalled(); }); + it('asks gslist once and takes no lock when both are up, as every cell finds them', async () => { + listings = [BOTH_UP]; + + await ensureProcesses(); + + expect(gslistCalls).toBe(1); + expect(satisfied).toBeUndefined(); + }); + + it('takes the lock and waits for a stone that is starting, even with a listener up', async () => { + const starting = [STONE_STARTING, LISTENER_UP].join('\n'); + listings = [starting, starting, starting, BOTH_UP]; + const report = vi.fn(); + + const started = await ensureProcesses({ report }); + + expect(started).toEqual({ startedStone: false, startedNetldi: false }); + expect(satisfied).toBeDefined(); + expect(report).toHaveBeenCalledWith('Waiting for the database to finish starting…'); + }); + + it('takes the lock for a stone that is shutting down, even with a listener up', async () => { + listings = [[row('Shutdown', 'Stone', 'gemdb'), LISTENER_UP].join('\n')]; + + await expect(ensureProcesses()).rejects.toThrow('The database is shutting down'); + expect(spawned).toEqual([]); + }); + + it('asks gslist no more often than before the fast path on a cold start', async () => { + // Before the lock, inside it, and once the stone is up; the listener is + // judged from that last one. + listings = ['', '', STONE_UP]; + + await ensureProcesses(); + + expect(gslistCalls).toBe(3); + }); + it('starts both, guards first, when neither is up', async () => { - listings = ['', STONE_UP]; + // Before the lock, inside it, then the stone after starting it. + listings = ['', '', STONE_UP]; const beforeStoneStart = vi.fn(() => { expect(spawned).toEqual([]); }); @@ -144,7 +186,7 @@ describe('ensureProcesses', () => { it('looks for the listener again after starting the stone, not at a list from before', async () => { // Another process started the listener while this one started the stone. - listings = ['', BOTH_UP]; + listings = ['', '', BOTH_UP]; const started = await ensureProcesses(); @@ -186,7 +228,8 @@ describe('ensureProcesses', () => { }); it('stops waiting for the lock only once both are up and answering', async () => { - listings = [BOTH_UP]; + // Anything short of both up takes the lock, which is what records the wait. + listings = [STONE_UP]; await ensureProcesses(); const check = async (listing: string): Promise => { listings = [listing]; @@ -235,7 +278,7 @@ describe('a stone that is still starting', () => { }); it('holds back the listener until it is ready', async () => { - listings = [STONE_STARTING, STONE_STARTING, STONE_UP]; + listings = [STONE_STARTING, STONE_STARTING, STONE_STARTING, STONE_UP]; const report = vi.fn(); const started = await ensureProcesses({ report }); diff --git a/src/processes.ts b/src/processes.ts index 1bdb987..f435ce8 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -230,12 +230,13 @@ export const SHUTTING_DOWN_MESSAGE = * waiting — is polled until it is past `Startup`. A stone that disappears * while we wait failed to start, and one still starting after a minute is not * going to soon; both end in an error naming the stone's log, which says why. - * A stone at `Shutdown` ends the wait at once: it is being stopped. + * A stone at `Shutdown` ends the wait at once: it is being stopped. Returns + * the last listing, so the caller need not take another. */ export async function waitForStoneReady( report?: (message: string) => void, wait: { pollMs?: number; timeoutMs?: number } = {}, -): Promise { +): Promise { const stoneLog = path.join(databaseLogPath(), `${STONE_NAME}.log`); const deadline = Date.now() + (wait.timeoutMs ?? STONE_LOCK_TIMEOUT_MS); let running = await listProcessesAsync(); @@ -244,7 +245,7 @@ export async function waitForStoneReady( switch (stoneState(running)) { case 'ready': case 'other': - return; + return running; case 'stopping': throw new Error(SHUTTING_DOWN_MESSAGE); case 'absent': @@ -323,9 +324,20 @@ export async function ensureProcesses( opts: { beforeStoneStart?: () => void; report?: (message: string) => void } = {}, ): Promise<{ startedStone: boolean; startedNetldi: boolean }> { requireOwnDatabase('start'); + // Every notebook cell lands here, and nearly always both are up: one + // listing and no lock then. Never for a stone starting or stopping, which + // the lock and the wait below are for. + const before = await listProcessesAsync(); + const stoneUp = ['ready', 'other'].includes(stoneState(before)); + if (stoneUp && findNetldi(before)) { + log('The database is already running.'); + log('The session listener is already running.'); + return { startedStone: false, startedNetldi: false }; + } const started = await withStoneLock( async () => { let startedStone = false; + // Listed again: what was true before the lock may not be now. const state = stoneState(await listProcessesAsync()); // Said here, before any wait: a stopping stone's last moments read // `Startup` before it disappears (measured), which a wait would report @@ -340,10 +352,12 @@ export async function ensureProcesses( } else { log('The database is already running.'); } - await waitForStoneReady(opts.report); + // The wait's last listing is recent enough to judge the listener by: + // it was taken after the stone, ours or not, finished starting. + const running = await waitForStoneReady(opts.report); let startedNetldi = false; - if (!findNetldi(await listProcessesAsync())) { + if (!findNetldi(running)) { opts.report?.('Starting the session listener…'); startedNetldi = await startNetldi(); } else { From 6a85528382793c73408808f926f72c1f37c378d0 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:40:41 -0300 Subject: [PATCH 12/14] Keep waiting for the stone lock while its holder visibly makes progress A waiter gave up at the lock's one-minute deadline, but the holder now keeps the lock through the guards (copydbf -i alone up to 30 s), startstone, up to a minute's wait for the stone, and startnetldi. A start that took 70 s (startstone 20 s, then 50 s at Startup) made a second window fail at 60 s with "another process has been starting the database", over a database that came up ten seconds later. The minute still applies to a holder that shows nothing. Past it, a stone listed and not shutting down counts as progress and keeps the wait going for 30 s after it was last seen, up to 2.5 minutes. When the holder is this very process the message says so instead of sending the user looking for another one. Co-Authored-By: Claude Opus 5.5 --- src/__tests__/startProcesses.test.ts | 85 ++++++++++++++++++++++++++++ src/lock.ts | 54 ++++++++++++++---- src/processes.ts | 8 ++- 3 files changed, 135 insertions(+), 12 deletions(-) diff --git a/src/__tests__/startProcesses.test.ts b/src/__tests__/startProcesses.test.ts index 4817ee2..66a5336 100644 --- a/src/__tests__/startProcesses.test.ts +++ b/src/__tests__/startProcesses.test.ts @@ -15,11 +15,14 @@ import { __log, __resetSettings, __setSetting } from '../__mocks__/vscode'; let listings: string[] = []; let gslistCalls = 0; +/** When set, what gslist lists at a given time, instead of `listings`. */ +let listingAt: ((now: number) => string) | undefined; const exitCodes: Record = {}; const spawned: string[] = []; function gslist(): string { gslistCalls++; + if (listingAt) return listingAt(Date.now()); return listings.length > 1 ? (listings.shift() ?? '') : (listings[0] ?? ''); } @@ -64,6 +67,7 @@ vi.mock('../lock', async (importOriginal) => { }); const { expectedEnginePath } = await import('../paths'); +const { STONE_LOCK_NAME } = await import('../lock'); const { ensureListener, ensureProcesses, stoneReady, stoneState, waitForStoneReady } = await import('../processes'); const { parseGslist } = await import('../gslist'); @@ -87,12 +91,14 @@ beforeEach(() => { fs.writeFileSync(path.join(expectedEnginePath(), 'bin', 'gslist'), ''); listings = []; gslistCalls = 0; + listingAt = undefined; spawned.length = 0; satisfied = undefined; for (const key of Object.keys(exitCodes)) delete exitCodes[key]; }); afterEach(() => { + vi.useRealTimers(); fs.rmSync(root, { recursive: true, force: true }); }); @@ -371,3 +377,82 @@ describe('putting the listener back after a declined force-stop', () => { expect(spawned).toEqual([]); }); }); + +/** + * Queued behind a start that holds the stone lock for longer than a minute, + * which the holder can: guards, startstone, a minute's wait for the stone and + * startnetldi, all inside the lock. The holder here is another live process. + */ +describe('waiting for the stone lock', () => { + /** Hold the lock as `pid` would, from now until `releaseAfterMs`, if given. */ + function holdLock(pid: number, releaseAfterMs?: number): void { + const lock = path.join(root, STONE_LOCK_NAME); + fs.mkdirSync(lock); + fs.writeFileSync(path.join(lock, 'pid'), `${pid}\n`); + if (releaseAfterMs !== undefined) { + setTimeout(() => fs.rmSync(lock, { recursive: true, force: true }), releaseAfterMs); + } + } + + /** Settle `promise` while fake time runs `ms`, so a rejection is never left unhandled. */ + async function after( + promise: Promise, + ms: number, + ): Promise<{ value?: T; error?: Error; settled: boolean }> { + const outcome: { value?: T; error?: Error; settled: boolean } = { settled: false }; + promise.then( + (value) => Object.assign(outcome, { value, settled: true }), + (error: Error) => Object.assign(outcome, { error, settled: true }), + ); + await vi.advanceTimersByTimeAsync(ms); + return outcome; + } + + it('outlasts a minute while the holder is visibly starting the stone', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'Date'] }); + const t0 = Date.now(); + // startstone for 20 s, then 50 s at Startup, then both up. + listingAt = (now) => (now - t0 < 20_000 ? '' : now - t0 < 70_000 ? STONE_STARTING : BOTH_UP); + holdLock(process.ppid, 70_000); + + const outcome = await after(ensureProcesses(), 75_000); + + expect(outcome.error).toBeUndefined(); + expect(outcome.value).toEqual({ startedStone: false, startedNetldi: false }); + expect(spawned).toEqual([]); + }); + + it('still gives up after a minute on a holder that shows nothing', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'Date'] }); + listingAt = () => ''; + holdLock(process.ppid); + + const start = ensureProcesses(); + expect((await after(start, 59_000)).settled).toBe(false); + const outcome = await after(start, 2_000); + + expect(outcome.error?.message).toMatch(/Another process has been starting the database/); + }); + + it('gives up on a stone that never finishes starting, past the holder’s worst case', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'Date'] }); + listingAt = () => STONE_STARTING; + holdLock(process.ppid); + + const start = ensureProcesses(); + expect((await after(start, 140_000)).settled).toBe(false); + const outcome = await after(start, 15_000); + + expect(outcome.error?.message).toMatch(/Another process has been starting the database/); + }); + + it('says it is this window that is starting the database when it is', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'Date'] }); + listingAt = () => ''; + holdLock(process.pid); + + const outcome = await after(ensureProcesses(), 65_000); + + expect(outcome.error?.message).toMatch(/^This window has been starting the database/); + }); +}); diff --git a/src/lock.ts b/src/lock.ts index 5c8398a..8fcd05e 100644 --- a/src/lock.ts +++ b/src/lock.ts @@ -503,6 +503,17 @@ function stoneLockPath(): string { export const STONE_LOCK_POLL_MS = 200; export const STONE_LOCK_TIMEOUT_MS = 60_000; +/** + * How long past {@link STONE_LOCK_TIMEOUT_MS} a holder that is visibly + * getting somewhere keeps a waiter waiting. The holder keeps the lock through + * the pre-start guards (`copydbf -i` alone can take 30 s), `startstone`, up to + * a minute's wait for the stone and `startnetldi`, so a minute is not its + * worst case; this ceiling is above it. Progress counts for + * {@link STONE_LOCK_IDLE_MS} after it was last seen. + */ +export const STONE_LOCK_CEILING_MS = 150_000; +export const STONE_LOCK_IDLE_MS = 30_000; + /** * Run `work` while holding the stone lock, waiting for another process to * release it first. @@ -516,31 +527,54 @@ export const STONE_LOCK_TIMEOUT_MS = 60_000; * Waiting is the point: a caller that stepped aside used to carry on as if * the stone were up — to the listener and the Grail file-in — while the * wrapper was still starting it. `satisfied` is asked between polls, and true - * ends the wait with undefined and `work` not run: for `startStone`, the stone - * came up while we waited, which is what we were waiting for. A lock still - * held after a minute is an error naming it, since only a person can say - * whether whatever holds it is really still working. + * ends the wait with undefined and `work` not run: whoever held the lock + * brought up what we wanted, which is what we were waiting for. `progressing` + * is asked right after it, so it may judge by what `satisfied` just looked + * at: true means the holder is visibly getting somewhere, which keeps the wait + * going past the minute, up to {@link STONE_LOCK_CEILING_MS}. A lock still + * held after that is an error naming it, since only a person can say whether + * whatever holds it is really still working. */ export async function withStoneLock( work: () => Promise, - wait: { satisfied?: () => boolean | Promise; pollMs?: number; timeoutMs?: number } = {}, + wait: { + satisfied?: () => boolean | Promise; + progressing?: () => boolean; + pollMs?: number; + timeoutMs?: number; + } = {}, ): Promise { const lock = stoneLockPath(); ensureRootPath(); - const deadline = Date.now() + (wait.timeoutMs ?? STONE_LOCK_TIMEOUT_MS); + const start = Date.now(); + const timeoutMs = wait.timeoutMs ?? STONE_LOCK_TIMEOUT_MS; + let lastProgress = -Infinity; let logged = false; while (!claimStoneLock(lock)) { + // Two starts in this one process wait on each other too, and "another + // process" would send the user looking for one that does not exist. + const ours = readStoneLockPid(lock) === String(process.pid); if (!logged) { logged = true; - log('Another process is starting the database; waiting for it.'); + log( + ours + ? 'This window is already starting the database; waiting for it.' + : 'Another process is starting the database; waiting for it.', + ); } await sleep(wait.pollMs ?? STONE_LOCK_POLL_MS); if (await wait.satisfied?.()) return undefined; - if (Date.now() > deadline) { + const now = Date.now(); + if (wait.progressing?.()) lastProgress = now; + const stalled = now - start > timeoutMs && now - lastProgress > STONE_LOCK_IDLE_MS; + if (stalled || now - start > STONE_LOCK_CEILING_MS) { throw new Error( - `Another process has been starting the database for over a minute. ` + - `If nothing is, remove ${lock} and try again.`, + ours + ? 'This window has been starting the database for over a minute and has not ' + + 'finished. See the GemDB log for what it is waiting on.' + : 'Another process has been starting the database for over a minute. ' + + `If nothing is, remove ${lock} and try again.`, ); } } diff --git a/src/processes.ts b/src/processes.ts index f435ce8..d6f70ce 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -334,6 +334,7 @@ export async function ensureProcesses( log('The session listener is already running.'); return { startedStone: false, startedNetldi: false }; } + let seen = before; const started = await withStoneLock( async () => { let startedStone = false; @@ -367,9 +368,12 @@ export async function ensureProcesses( }, { satisfied: async () => { - const running = await listProcessesAsync(); - return stoneReady(running) && listenerReady(running); + seen = await listProcessesAsync(); + return stoneReady(seen) && listenerReady(seen); }, + // A stone listed and not going down means whoever holds the lock is past + // startstone: waiting on it, or starting the listener beside it. + progressing: () => ['starting', 'ready', 'other'].includes(stoneState(seen)), }, ); return started ?? { startedStone: false, startedNetldi: false }; From 58627bc57fac892396ff2a6e3a79eb912beb348e Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:41:59 -0300 Subject: [PATCH 13/14] Drop startStone, a second way to start the stone that nothing ships startStone had no production caller, its comment said the wrapper used it (the wrapper starts the stone in shell), and it contradicted the rule that processes start only through ensureProcesses. The integration tests that wanted a stone without a listener get startStoneAlone in the fixture, which goes through ensureProcesses and stops a listener it started. References to it in comments and docs now name what they meant. Co-Authored-By: Claude Opus 5.5 --- docs/repository-space.md | 2 +- src/__integration__/cli.test.ts | 12 +++++++++--- src/__integration__/database.test.ts | 5 ++--- src/__integration__/fixture.ts | 12 ++++++++++++ src/__integration__/processes.test.ts | 13 +++---------- src/__tests__/externalDatabase.test.ts | 2 -- src/networkFileSystem.ts | 2 +- src/processes.ts | 26 -------------------------- 8 files changed, 28 insertions(+), 46 deletions(-) diff --git a/docs/repository-space.md b/docs/repository-space.md index 7baabfd..8252cff 100644 --- a/docs/repository-space.md +++ b/docs/repository-space.md @@ -51,7 +51,7 @@ DBF_PRE_GROW = TRUE; numbers and a way out rather than the stone's log line: `assertRoomForSetup` before setup downloads anything (the cap plus the engine), and `assertRoomForExtent` before every start (what the extent still needs), and - `startStone` explains a startup that failed with "No space left on device" + `runStartstone` explains a startup that failed with "No space left on device" anyway. With the extent pregrown, `SystemRepository freeSpace` alone is the room left, for every tool that reads it. - **The test suite reserves 1 GB, not 10.** Each integration file makes a diff --git a/src/__integration__/cli.test.ts b/src/__integration__/cli.test.ts index 3d3928b..1e7e2ea 100644 --- a/src/__integration__/cli.test.ts +++ b/src/__integration__/cli.test.ts @@ -5,8 +5,14 @@ import * as path from 'path'; import { afterAll, beforeAll, describe, expect, it } from 'vitest'; import { cliPath } from '../cli'; import { bundledGrailStamp, stageGrail } from '../grail'; -import { isRunning, startStone, stopStone } from '../processes'; -import { createDatabaseWithPython, Fixture, haveTestExtent, makeFixture } from './fixture'; +import { isRunning, stopStone } from '../processes'; +import { + createDatabaseWithPython, + Fixture, + haveTestExtent, + makeFixture, + startStoneAlone, +} from './fixture'; /** * The `gemdb` shell command, run the way a user runs it: bash, a file @@ -69,7 +75,7 @@ beforeAll(async () => { createDatabaseWithPython(fixture); // Python already filed in — see testExtentPath stageGrail(ext); // stages Grail and generates the CLI - await startStone(); + await startStoneAlone(); fs.writeFileSync(path.join(workDir, 'hello.py'), 'print("hello from", 6 * 7)\n'); fs.writeFileSync(path.join(workDir, 'both.py'), 'print("partial")\n1 / 0\n'); diff --git a/src/__integration__/database.test.ts b/src/__integration__/database.test.ts index 1d94819..dcd8494 100644 --- a/src/__integration__/database.test.ts +++ b/src/__integration__/database.test.ts @@ -11,13 +11,12 @@ import { isListening, isRunning, listProcesses, - startStone, stopNetldi, stopStone, } from '../processes'; import { execute, isConnected, logout } from '../session'; import { ensureStatmonitor, recordedFiles } from '../statmonitor'; -import { Fixture, TEST_CAP_MB, limitTestDatabase, makeFixture } from './fixture'; +import { Fixture, TEST_CAP_MB, limitTestDatabase, makeFixture, startStoneAlone } from './fixture'; /** * The parts of GemDB that are only interesting against a real database. @@ -162,7 +161,7 @@ describe.skipIf(!makeFixtureIsPossible())('a real database', () => { it('stops cleanly once nothing is logged in', async () => { logout(); - await startStone(); + await startStoneAlone(); expect(isRunning()).toBe(true); await stopStone(false); diff --git a/src/__integration__/fixture.ts b/src/__integration__/fixture.ts index 33c09d1..3b4afc8 100644 --- a/src/__integration__/fixture.ts +++ b/src/__integration__/fixture.ts @@ -5,6 +5,7 @@ import { __setSetting } from '../__mocks__/vscode'; import { STONE_NAME, databasePasswordPath } from '../config'; import { createDatabase } from '../database'; import { databaseConfPath, ensureRootPath, expectedEnginePath, extentPath } from '../paths'; +import { ensureProcesses, stopNetldi } from '../processes'; /** * A database of GemDB's own making, in a directory of its own, on the real @@ -149,3 +150,14 @@ export function createDatabaseWithPython(fixture: Fixture): void { fs.copyFileSync(testExtentPasswordPath(), databasePasswordPath()); fs.chmodSync(databasePasswordPath(), 0o600); } + +/** + * Bring the stone up without leaving a session listener this call started, + * for tests of what needs no listener (linked sessions) or of starting one. + * Through `ensureProcesses`, the one way GemDB starts processes, rather than a + * stone-only start of the tests' own. + */ +export async function startStoneAlone(): Promise { + const { startedNetldi } = await ensureProcesses(); + if (startedNetldi) await stopNetldi(); +} diff --git a/src/__integration__/processes.test.ts b/src/__integration__/processes.test.ts index c474354..eb91baf 100644 --- a/src/__integration__/processes.test.ts +++ b/src/__integration__/processes.test.ts @@ -6,15 +6,8 @@ import * as path from 'path'; import { execFile } from 'child_process'; import { createDatabase } from '../database'; import { isSharedMemoryConfigured } from '../osConfig'; -import { - isListening, - isRunning, - listProcesses, - startStone, - stopNetldi, - stopStone, -} from '../processes'; -import { Fixture, limitTestDatabase, makeFixture } from './fixture'; +import { isListening, isRunning, listProcesses, stopNetldi, stopStone } from '../processes'; +import { Fixture, limitTestDatabase, makeFixture, startStoneAlone } from './fixture'; /** * Two processes starting one database at the same moment. @@ -168,7 +161,7 @@ describe.skipIf(!canMakeFixture())('starting the database from two processes at it('does not fail when a release that takes no lock starts the session listener alongside', async () => { if (isListening()) await stopNetldi(); - await startStone(); + await startStoneAlone(); expect(isListening()).toBe(false); const reports = await race(['raw-netldi', 'ensure'], { rawWaitsForRival: true }); diff --git a/src/__tests__/externalDatabase.test.ts b/src/__tests__/externalDatabase.test.ts index 4e14a0b..849795e 100644 --- a/src/__tests__/externalDatabase.test.ts +++ b/src/__tests__/externalDatabase.test.ts @@ -25,7 +25,6 @@ import { ensureProcesses, findNetldi, findStone, - startStone, stopNetldi, stopStone, } from '../processes'; @@ -227,7 +226,6 @@ describe('processes', () => { it('are never started or stopped by GemDB', async () => { useExternal(); - await expect(startStone()).rejects.toBeInstanceOf(ExternalDatabaseError); await expect(ensureProcesses()).rejects.toBeInstanceOf(ExternalDatabaseError); await expect(stopStone()).rejects.toBeInstanceOf(ExternalDatabaseError); await expect(stopNetldi()).rejects.toBeInstanceOf(ExternalDatabaseError); diff --git a/src/networkFileSystem.ts b/src/networkFileSystem.ts index 7779bba..70faa43 100644 --- a/src/networkFileSystem.ts +++ b/src/networkFileSystem.ts @@ -26,7 +26,7 @@ import * as path from 'path'; * be created. Anything that cannot be read answers false. A wrong "NFS" blocks * setup on a machine that could run it; a wrong "local" costs what happened * before this check existed, and the stone's refusal is recognised then too - * (see `startStone`). + * (see `refusedNfs`). */ export function isOnNfs(dir: string, world: FileSystemWorld = realWorld): boolean { const existing = nearestExisting(path.resolve(dir), world); diff --git a/src/processes.ts b/src/processes.ts index d6f70ce..5c06105 100644 --- a/src/processes.ts +++ b/src/processes.ts @@ -404,32 +404,6 @@ export async function ensureListener(): Promise { return started ?? false; } -/** - * Start the stone alone, for what needs no session listener: the `gemdb` - * wrapper's file runs are linked sessions, and so are the tests that use this. - * Under the same lock as {@link ensureProcesses}. - */ -export async function startStone(): Promise { - requireOwnDatabase('start'); - // Under the lock the generated `gemdb` wrapper also takes, because both - // doors start the same stone and nothing downstream refuses a second one. - // The re-check inside the lock is the point: whoever we queued behind was - // most likely starting it, and without this we would start another. For the - // same reason, a stone that comes up while we wait ends the wait. - await withStoneLock( - async () => { - if (isRunning()) { - log('The database is already running; nothing to start.'); - } else { - logStep(`Starting the database`); - await runStartstone(); - } - await waitForStoneReady(); - }, - { satisfied: async () => stoneReady(await listProcessesAsync()) }, - ); -} - /** * Run `startstone`, turning the two refusals the stone explains only in its * log into errors that say what to do. The caller holds the stone lock. From 15433f4ee6e1e0bcec956c44a2a33c41c2fa6469 Mon Sep 17 00:00:00 2001 From: MatiasFernandez <7898112+MatiasFernandez@users.noreply.github.com> Date: Wed, 14 Oct 2026 15:44:21 -0300 Subject: [PATCH 14/14] Count listeners in the race test by process, and fix the guard note The race test asserted one startedStone but nothing about the listener, and gslist cannot catch a duplicate: two startnetldi run together can both exit 0 and leave two netldid processes behind one row. It now asserts that exactly one contender started the listener and counts netldid processes for the fixture's listener with pgrep, keyed on the fixture's root path so a developer's own gemdbldi is not counted. CLAUDE.md still said the engine-version guard runs in startProcesses; it runs in assertSafeToStart, which ensureProcesses calls as beforeStoneStart. Co-Authored-By: Claude Opus 5.5 --- CLAUDE.md | 5 +++-- src/__integration__/processes.test.ts | 23 ++++++++++++++++++++++- 2 files changed, 25 insertions(+), 3 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index 84b8017..229e773 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -250,8 +250,9 @@ something GemDB could do on a user's behalf. The guard reads the repository's version with `copydbf -i` and refuses, naming both versions and the directory to delete. Checked in two places, and both are needed: `prepareFiles`, which is the -first-install path, and `startProcesses` before the stone starts, because an -extension update reaches that line without preparing anything — engine +first-install path, and `assertSafeToStart` before the stone starts (the +`beforeStoneStart` that `ensureProcesses` runs inside the stone lock), because +an extension update reaches that line without preparing anything — engine downloaded, database present, Grail staged, so `isInstalled()` is true. **Below its free-space threshold the stone stops collecting garbage.** GemDB diff --git a/src/__integration__/processes.test.ts b/src/__integration__/processes.test.ts index eb91baf..4ec6d4a 100644 --- a/src/__integration__/processes.test.ts +++ b/src/__integration__/processes.test.ts @@ -3,7 +3,8 @@ import * as esbuild from 'esbuild'; import * as fs from 'fs'; import * as os from 'os'; import * as path from 'path'; -import { execFile } from 'child_process'; +import { execFile, execFileSync } from 'child_process'; +import { NETLDI_NAME } from '../config'; import { createDatabase } from '../database'; import { isSharedMemoryConfigured } from '../osConfig'; import { isListening, isRunning, listProcesses, stopNetldi, stopStone } from '../processes'; @@ -138,6 +139,24 @@ async function race( .map((line) => JSON.parse(line) as Report); } +/** + * How many `netldid` processes are serving this fixture's listener. gslist + * cannot answer that: it keys rows by name and shows one row for two + * listeners, and two `startnetldi` run at once can both exit 0 and leave two. + * The fixture's root path is in each one's `-l` log argument, which keeps a + * developer's own `gemdbldi` out of the count. + */ +function netldidProcesses(): number { + const escape = (text: string): string => text.replace(/[.*+?^${}()|[\]\\]/g, '\\$&'); + const pattern = `netldid ${escape(NETLDI_NAME)} .*${escape(fixture!.root)}/`; + try { + return execFileSync('pgrep', ['-f', pattern], { encoding: 'utf8' }).split('\n').filter(Boolean) + .length; + } catch { + return 0; // pgrep exits 1 when nothing matches + } +} + /** What `gslist` lists, reduced to what the end state is judged on. */ function listed(): { type: string; status: string }[] { return listProcesses().map((p) => ({ type: p.type, status: p.status })); @@ -150,6 +169,8 @@ describe.skipIf(!canMakeFixture())('starting the database from two processes at expect(reports.filter((r) => r.error)).toEqual([]); expect(reports).toHaveLength(2); expect(reports.filter((r) => r.startedStone)).toHaveLength(1); + expect(reports.filter((r) => r.startedNetldi)).toHaveLength(1); + expect(netldidProcesses()).toBe(1); expect(listed()).toEqual( expect.arrayContaining([ { type: 'stone', status: 'OK' },