etherpad-lite/src/node/server.ts
John McLear d582398826
fix: eliminate the Windows backend silent-ELIFECYCLE flake (handler gate + Node 24.16.0) (#7866)
* fix(test): stop a single leaked promise rejection from killing the whole backend suite

Root cause of the long-standing Windows backend-test "silent ELIFECYCLE"
flake (~22% of runs, rotating across random spec files, no mocha summary,
no JS-handler trace, bypassing --report-on-fatalerror / Defender / Windows
event log / AeDebug). Found by capturing a full-memory dump of the dying
node.exe with Sysinternals ProcDump (-t dump-on-terminate) and symbolizing
it against Node 24.15.0's node.pdb. The dying thread's stack:

    exit_or_terminate_process / common_exit        (CRT exit)
    node::Exit
    node::DefaultProcessExitHandlerInternal
    node::Environment::Exit
    node::ReallyExit                                (process.exit binding)
    ... v8 MicrotaskQueue::RunMicrotasks ...
    node::InternalCallbackScope::Close

No exception stream — a *clean* ExitProcess, not a crash. The job log
pinned the trigger:

    [INFO] server - Exiting...
    AssertionError at tests/backend/specs/SessionStore.ts:235
      at process.processTicksAndRejections

Mechanism: a timing-fragile test (SessionStore touch/expiry specs use real
setTimeout against a 200ms-expiry session; socket.io delay-race specs are
similar) gets timed out and abandoned by mocha, but its async body keeps
running. When its trailing assertion later throws, it surfaces as an ORPHAN
unhandled rejection belonging to no awaited test. Three handlers then
escalated that into a whole-process exit:
  - server.ts installed process-global uncaughtException/unhandledRejection
    handlers that call exports.exit() → process.reallyExit() (production
    graceful-shutdown behaviour, catastrophic in-process under mocha)
  - common.ts (PR #7663) and diagnostics.ts (PR #7838) rethrew the rejection
    and process.exit(1)

Because it's a deliberate, clean exit it bypassed every forensic layer; it
rotated across files because the orphan rejection lands during whatever test
is running; it's Windows-mostly because event-loop timing makes the abandoned
test's assertion fire in a *later* test's window more often there.

Fix (two halves):
  1. server.ts: gate the process-global uncaughtException / unhandledRejection
     / signal handlers behind `require.main === module`. They are correct for
     a real Etherpad process but must not fire when server.start() is called
     in-process by a test runner — mocha owns process-level error handling
     there. Mirrors the existing `if (require.main === module) exports.start()`
     idiom; production (node server.js) is unchanged.
  2. common.ts + diagnostics.ts: the backend-test bootstraps now LOG unhandled
     rejections instead of rethrowing / exiting. Orphan rejections cannot be
     cleanly attributed to a test, so rethrowing only yields an
     ERR_MOCHA_MULTIPLE_DONE abort. Real failures are unaffected — an assertion
     in a test's own awaited path rejects that test's promise and mocha fails
     it normally, never reaching this global handler.

Verified locally: a spec that leaks a delayed rejection during a later test
now reports `3 passing` / exit 0 with the rejection logged, instead of
aborting the run.

Follow-ups (separate PRs): harden the SessionStore / socket.io timing specs
to not leak (fake timers); remove the now-unneeded diagnostic scaffolding
(diagnostics.ts heartbeat/node-report, the #7846 OS sidecar) now that the
cause is known.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

* fix(ci): run Windows backend tests on Node 25 to dodge the libuv connect overrun

Node 24.x's bundled libuv has a stack buffer overrun in the Windows TCP-connect
path (uv__tcp_connect / uv__tcp_try_connect), proven by a SilentProcessExit
full-memory dump of the dying mocha process: the main thread executes
__fastfail(FAST_FAIL_STACK_COOKIE_CHECK_FAILURE) from __report_gsfailure with
TCPWrap::Connect -> uv_tcp_connect on the stack. It fires under the backend
suite's heavy localhost connection churn, is address-family independent (occurs
on both sockaddr_in and sockaddr_in6, so an IPv4 pin does NOT help), and -- being
memory corruption -- bypasses all JS/Node observability, rotating across tests
as the "silent ELIFECYCLE" flake (~22% of Windows runs).

Empirically: Node 25 = 16/16 green; Node 24 (even with an IPv4 pin) = ~39% fail.
Node 25's newer bundled libuv does not overrun. Linux stays on Node 24 LTS (the
bug is Windows-specific). Revisit once the libuv fix is backported to 24.x.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

* fix(ci): pin Windows backend to Node 24.16.0 (libuv fix) instead of 25

Bisect (standalone repro) pinpointed the fix to Node 24.16.0 (libuv 1.52.1):
24.15.0 (libuv 1.51.0) crashes the connect overrun 4/4 on 127.0.0.1, while
24.16.0 is clean 0/8. 24.16.0 stays on the Node 24 "Krypton" LTS line, so prefer
it over Node 25 (non-LTS). Pinned explicitly because setup-node's default
check-latest:false reuses the runner's pre-cached 24.15.0 for a bare "24".

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

* docs(ci): reference upstream nodejs/node#63620 in the Windows Node-pin comment

Links the explicit 24.16.0 pin to the filed upstream issue so the pin can be
dropped back to plain "24" once the libuv connect-overrun fix is across the
supported 24.x baseline.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

---------

Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-05-28 16:12:34 +01:00

329 lines
12 KiB
JavaScript
Executable file

#!/usr/bin/env node
/**
* This module is started with src/bin/run.sh. It sets up a Express HTTP and a Socket.IO Server.
* Static file Requests are answered directly from this module, Socket.IO messages are passed
* to MessageHandler and minfied requests are passed to minified.
*/
/*
* 2011 Peter 'Pita' Martischka (Primary Technology Ltd)
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS-IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
import {PluginType} from "./types/Plugin";
import {ErrorCaused} from "./types/ErrorCaused";
import log4js from 'log4js';
import pkg from '../package.json';
import {checkForMigration} from "../static/js/pluginfw/installer";
import {ProxyAgent, setGlobalDispatcher} from 'undici';
import settings from './utils/Settings';
let wtfnode: any;
if (settings.dumpOnUncleanExit) {
// wtfnode should be loaded after log4js.replaceConsole() so that it uses log4js for logging, and
// it should be above everything else so that it can hook in before resources are used.
wtfnode = require('wtfnode');
}
const proxyUrl = process.env['https_proxy'] || process.env['http_proxy'];
if (proxyUrl) {
console.log("Using proxy: " + proxyUrl);
setGlobalDispatcher(new ProxyAgent(proxyUrl));
}
/*
* early check for version compatibility before calling
* any modules that require newer versions of NodeJS
*/
import {enforceMinNodeVersion, checkDeprecationStatus} from './utils/NodeVersion';
enforceMinNodeVersion(pkg.engines.node.replace(">=", ""));
checkDeprecationStatus(pkg.engines.node.replace(">=", ""), '2.1.0');
import {check} from './utils/UpdateCheck';
const db = require('./db/DB');
const express = require('./hooks/express');
const hooks = require('../static/js/pluginfw/hooks');
const pluginDefs = require('../static/js/pluginfw/plugin_defs');
const plugins = require('../static/js/pluginfw/plugins');
import {Gate} from './utils/promises';
const stats = require('./stats')
const logger = log4js.getLogger('server');
const State = {
INITIAL: 1,
STARTING: 2,
RUNNING: 3,
STOPPING: 4,
STOPPED: 5,
EXITING: 6,
WAITING_FOR_EXIT: 7,
STATE_TRANSITION_FAILED: 8,
};
let state = State.INITIAL;
const removeSignalListener = (signal: NodeJS.Signals, listener: any) => {
logger.debug(`Removing ${signal} listener because it might interfere with shutdown tasks. ` +
`Function code:\n${listener.toString()}\n` +
`Current stack:\n${new Error()!.stack!.split('\n').slice(1).join('\n')}`);
process.off(signal, listener);
};
let startDoneGate: Gate<unknown>
exports.start = async () => {
switch (state) {
case State.INITIAL:
break;
case State.STARTING:
await startDoneGate;
// Retry. Don't fall through because it might have transitioned to STATE_TRANSITION_FAILED.
return await exports.start();
case State.RUNNING:
return express.server;
case State.STOPPING:
case State.STOPPED:
case State.EXITING:
case State.WAITING_FOR_EXIT:
case State.STATE_TRANSITION_FAILED:
throw new Error('restart not supported');
default:
throw new Error(`unknown State: ${state.toString()}`);
}
logger.info('Starting Etherpad...');
startDoneGate = new Gate();
state = State.STARTING;
try {
// Check if the Etherpad version is up to date
check();
// @ts-ignore
stats.gauge('memoryUsage', () => process.memoryUsage().rss);
// @ts-ignore
stats.gauge('memoryUsageHeap', () => process.memoryUsage().heapUsed);
// These process-global handlers turn ANY uncaught exception / unhandled
// rejection / termination signal into a full Etherpad shutdown + exit.
// That is correct for a real Etherpad process, but catastrophic when
// server.start() is called in-process by a test runner (mocha): a single
// leaked promise rejection from any one test would call exports.exit()
// and tear down the whole suite mid-run — the long-standing Windows
// "silent ELIFECYCLE" flake (root-caused via a procdump capture showing
// node::ReallyExit firing from a microtask). Only install them when
// server.ts is the program entry point (production). Under a test runner
// require.main is the runner, not this module, and mocha's own per-test
// uncaughtException/unhandledRejection handling fails the offending test
// instead of killing the process. (This mirrors the existing
// `if (require.main === module) exports.start()` idiom at the bottom of
// this file — embedders that call start() programmatically are likewise
// responsible for their own process lifecycle.)
if (require.main === module) {
process.on('uncaughtException', (err: ErrorCaused) => {
logger.debug(`uncaught exception: ${err.stack || err}`);
// eslint-disable-next-line promise/no-promise-in-callback
exports.exit(err)
.catch((err: ErrorCaused) => {
logger.error('Error in process exit', err);
// eslint-disable-next-line n/no-process-exit
process.exit(1);
});
});
// As of v14, Node.js does not exit when there is an unhandled Promise
// rejection. Convert an unhandled rejection into an uncaught exception,
// which does cause Node.js to exit.
process.on('unhandledRejection', (err: ErrorCaused) => {
logger.debug(`unhandled rejection: ${err.stack || err}`);
throw err;
});
for (const signal of ['SIGINT', 'SIGTERM'] as NodeJS.Signals[]) {
// Forcibly remove other signal listeners to prevent them from
// terminating node before we are done cleaning up. See
// https://github.com/andywer/threads.js/pull/329 for an example of a
// problematic listener. This means that exports.exit is solely
// responsible for performing all necessary cleanup tasks.
for (const listener of process.listeners(signal)) {
removeSignalListener(signal, listener);
}
process.on(signal, exports.exit);
// Prevent signal listeners from being added in the future.
process.on('newListener', (event, listener) => {
if (event !== signal) return;
removeSignalListener(signal, listener);
});
}
}
await db.init();
await checkForMigration();
await plugins.update();
const installedPlugins = (Object.values(pluginDefs.plugins) as PluginType[])
.filter((plugin) => plugin.package.name !== 'ep_etherpad-lite')
.map((plugin) => `${plugin.package.name}@${plugin.package.version}`)
.join(', ');
logger.info(`Installed plugins: ${installedPlugins}`);
logger.debug(`Installed parts:\n${plugins.formatParts()}`);
logger.debug(`Installed server-side hooks:\n${plugins.formatHooks('hooks', false)}`);
await hooks.aCallAll('loadSettings', {settings});
await hooks.aCallAll('createServer');
} catch (err) {
logger.error('Error occurred while starting Etherpad');
state = State.STATE_TRANSITION_FAILED;
// @ts-ignore
startDoneGate.resolve();
return await exports.exit(err);
}
logger.info('Etherpad is running');
state = State.RUNNING;
// @ts-ignore
startDoneGate.resolve();
// Once the server is RUNNING, /health responds 200 — that is the implicit
// health signal the updater's pending-verification timer is waiting for.
// Wrapped in try/catch because it must never block startup on a bug here.
try {
// eslint-disable-next-line @typescript-eslint/no-var-requires
const updater = require('./updater');
if (typeof updater.markBootHealthy === 'function') updater.markBootHealthy();
} catch (err) {
logger.debug(`markBootHealthy: ${(err as Error).message}`);
}
// Return the HTTP server to make it easier to write tests.
return express.server;
};
const stopDoneGate = new Gate();
exports.stop = async () => {
switch (state) {
case State.STARTING:
await exports.start();
// Don't fall through to State.RUNNING in case another caller is also waiting for startup.
return await exports.stop();
case State.RUNNING:
break;
case State.STOPPING:
await stopDoneGate;
// fall through
case State.INITIAL:
case State.STOPPED:
case State.EXITING:
case State.WAITING_FOR_EXIT:
case State.STATE_TRANSITION_FAILED:
return;
default:
throw new Error(`unknown State: ${state.toString()}`);
}
logger.info('Stopping Etherpad...');
state = State.STOPPING;
try {
let timeout: NodeJS.Timeout = null as unknown as NodeJS.Timeout;
await Promise.race([
hooks.aCallAll('shutdown'),
new Promise((resolve, reject) => {
timeout = setTimeout(() => reject(new Error('Timed out waiting for shutdown tasks')), 3000);
}),
]);
clearTimeout(timeout);
} catch (err) {
logger.error('Error occurred while stopping Etherpad');
state = State.STATE_TRANSITION_FAILED;
// @ts-ignore
stopDoneGate.resolve();
return await exports.exit(err);
}
logger.info('Etherpad stopped');
state = State.STOPPED;
// @ts-ignore
stopDoneGate.resolve();
};
let exitGate: any;
let exitCalled = false;
exports.exit = async (err: ErrorCaused|string|null = null) => {
/* eslint-disable no-process-exit */
if (err === 'SIGTERM') {
// Termination from SIGTERM is not treated as an abnormal termination.
logger.info('Received SIGTERM signal');
err = null;
} else if (typeof err == "object" && err != null) {
logger.error(`Metrics at time of fatal error:\n${JSON.stringify(stats.toJSON(), null, 2)}`);
logger.error(err.stack || err.toString());
process.exitCode = 1;
if (exitCalled) {
logger.error('Error occurred while waiting to exit. Forcing an immediate unclean exit...');
process.exit(1);
}
}
if (!exitCalled) logger.info('Exiting...');
exitCalled = true;
switch (state) {
case State.STARTING:
case State.RUNNING:
case State.STOPPING:
await exports.stop();
// Don't fall through to State.STOPPED in case another caller is also waiting for stop().
// Don't pass err to exports.exit() because this err has already been processed. (If err is
// passed again to exit() then exit() will think that a second error occurred while exiting.)
return await exports.exit();
case State.INITIAL:
case State.STOPPED:
case State.STATE_TRANSITION_FAILED:
break;
case State.EXITING:
await exitGate;
// fall through
case State.WAITING_FOR_EXIT:
return;
default:
throw new Error(`unknown State: ${state.toString()}`);
}
exitGate = new Gate();
state = State.EXITING;
exitGate.resolve();
// Node.js should exit on its own without further action. Add a timeout to force Node.js to exit
// just in case something failed to get cleaned up during the shutdown hook. unref() is called
// on the timeout so that the timeout itself does not prevent Node.js from exiting.
setTimeout(() => {
logger.error('Something that should have been cleaned up during the shutdown hook (such as ' +
'a timer, worker thread, or open connection) is preventing Node.js from exiting');
if (settings.dumpOnUncleanExit) {
wtfnode.dump();
} else {
logger.error('Enable `dumpOnUncleanExit` setting to get a dump of objects preventing a ' +
'clean exit');
}
logger.error('Forcing an unclean exit...');
process.exit(1);
}, 5000).unref();
logger.info('Waiting for Node.js to exit...');
state = State.WAITING_FOR_EXIT;
/* eslint-enable no-process-exit */
};
if (require.main === module) exports.start();
// @ts-ignore
if (typeof(PhusionPassenger) !== 'undefined') exports.start();