Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
17 commits
Select commit Hold shift + click to select a range
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions .changeset/mysql-tcp-keepalive.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
---
'@powersync/service-module-mysql': patch
---

Enable TCP keepalive on MySQL connections, as well as a periodic liveness probe on the control connection, so that idle connections are no longer silently dropped by stateful firewalls.
4 changes: 2 additions & 2 deletions modules/module-mysql/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -19,11 +19,11 @@
},
"dependencies": {
"@powersync/lib-services-framework": "workspace:*",
"@powersync/mysql-zongji": "^0.6.2",
"@powersync/service-core": "workspace:*",
"@powersync/service-jsonbig": "workspace:*",
"@powersync/service-sync-rules": "workspace:*",
"@powersync/service-types": "workspace:*",
"@powersync/service-jsonbig": "workspace:*",
"@powersync/mysql-zongji": "^0.6.0",
"async": "^3.2.4",
"mysql2": "^3.11.0",
"node-sql-parser": "^5.3.9",
Expand Down
4 changes: 3 additions & 1 deletion modules/module-mysql/src/replication/BinLogReplicationJob.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,9 @@ export class BinLogReplicationJob extends replication.AbstractReplicationJob {
}

async keepAlive() {
// Keepalives are handled by the binlog heartbeat mechanism
// The binlog connection is kept alive by the MySQL server heartbeat mechanism. The control
// connection carries no traffic between metadata queries, so probe its liveness here.
this.lastStream?.probeControlConnection();
}

async replicate() {
Expand Down
11 changes: 11 additions & 0 deletions modules/module-mysql/src/replication/BinLogStream.ts
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,8 @@ export class BinLogStream {

private replicationLag = new ReplicationLagTracker();

private binLogListener: BinLogListener | null = null;

constructor(private options: BinLogStreamOptions) {
this.logger = options.logger ?? defaultLogger;
this.storage = options.storage;
Expand Down Expand Up @@ -465,6 +467,7 @@ export class BinLogStream {
activeServerUuid: this.activeServerUuid!,
eventHandler: binlogEventHandler
});
this.binLogListener = binlogListener;

this.abortSignal.addEventListener(
'abort',
Expand Down Expand Up @@ -700,6 +703,14 @@ export class BinLogStream {
return this.replicationLag.getLagMillis();
}

/**
* Probe the liveness of the BinLog Listener's control connection. Called from the replication
* job's keepAlive. Does nothing before streaming starts (during the initial snapshot).
*/
probeControlConnection(): void {
this.binLogListener?.probeControlConnection();
}

async tryRollback(promiseConnection: mysqlPromise.Connection) {
try {
await promiseConnection.query('ROLLBACK');
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -49,11 +49,17 @@ export class MySQLConnectionManager extends BaseObserver<MySQLConnectionManagerL
* Create a new replication listener
*/
createBinlogListener(): ZongJi {
// These options apply to both the binlog connection and the control connection Zongji creates.
const listener = new ZongJi({
host: this.options.hostname,
port: this.options.port,
user: this.options.username,
password: this.options.password,
// TCP keepalive is disabled by default in @vlasky/mysql. Without it, the idle control
// connection can be silently dropped by stateful firewalls, freezing replication on the
// next table metadata query until the TCP retransmission timeout (~950s).
enableKeepAlive: true,
keepAliveInitialDelay: mysql_utils.TCP_KEEPALIVE_INITIAL_DELAY,
// We want to avoid parsing date/time values to Date, because that drops sub-millisecond precision.
dateStrings: true,
timeZone: 'Z'
Expand Down
71 changes: 70 additions & 1 deletion modules/module-mysql/src/replication/zongji/BinLogListener.ts
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,19 @@ const { Parser } = pkg;
* Seconds of inactivity after which a keepalive event is sent by the MySQL server.
*/
export const KEEPALIVE_INACTIVITY_THRESHOLD = 30;

/**
* Maximum time in milliseconds to wait for Zongji to stop before force-closing its control connection.
*/
export const ZONGJI_STOP_TIMEOUT = 5_000;

/**
* Maximum time in milliseconds a control connection liveness probe may execute before the
* connection is considered dead. Time the probe spends queued behind other control queries
* does not count towards this.
*/
export const CTRL_CONNECTION_PROBE_TIMEOUT = 5_000;

export type Row = Record<string, any>;

/**
Expand Down Expand Up @@ -87,6 +100,7 @@ export interface BinLogListenerOptions {
startGTID: common.ReplicatedGTID;
logger?: Logger;
keepAliveInactivitySeconds?: number;
ctrlConnectionProbeTimeoutMs?: number;
}

/**
Expand All @@ -104,6 +118,9 @@ export class BinLogListener {
private isStopped: boolean = false;
private isStopping: boolean = false;

// Set while a control connection probe is awaiting a response, so repeated probes do not pile up behind it.
private probePending: boolean = false;

// Flag to indicate if are currently in a transaction that involves multiple row mutation events.
private isTransactionOpen = false;

Expand Down Expand Up @@ -222,12 +239,29 @@ export class BinLogListener {
private async stopZongji(): Promise<void> {
if (!this.zongji.stopped) {
this.logger.info('Stopping BinLog Listener...');
await new Promise<void>((resolve) => {
const controlConnection = this.zongji.ctrlConnection;
let stopped = false;
const stopPromise = new Promise<void>((resolve) => {
this.zongji.once('stopped', () => {
stopped = true;
resolve();
});
this.zongji.stop();
});
// Zongji only emits 'stopped' once the KILL query on its control connection has completed.
// If that connection has been dead for a while, the query can block on TCP retransmissions
// for many minutes, so we destroy the socket after a timeout to unblock the stop.
const timeout = timers.setTimeout(ZONGJI_STOP_TIMEOUT, undefined, { ref: false }).then(() => {
if (!stopped) {
this.logger.warn('Timed out waiting for the BinLog Listener to stop. Closing the control connection.');
controlConnection._socket?.destroy();
}
});
await Promise.race([stopPromise, timeout]);
// Zongji destroys the control connection when it stops, which drops pending query callbacks:
// a probe waiting on this connection would otherwise stay pending forever and disable
// probing after a restart.
this.probePending = false;
this.logger.info('BinLog Listener stopped.');
}
}
Expand All @@ -253,6 +287,41 @@ export class BinLogListener {
}
}

/**
* The binlog connection is kept alive by the MySQL server heartbeat, but the control connection
* carries no traffic between metadata queries. TCP keepalive stops it from being dropped when idle,
* but detects an already dead connection slowly, so the replication job's keepAlive additionally
* probes it with a lightweight query and stops the listener (restarting replication) if the probe
* does not respond in time.
*
* The driver starts the query timeout when the query begins executing, not when it is queued, so a
* probe waiting behind a legitimately slow metadata query does not produce a false failure. A probe
* queued on a dead socket is failed together with the queued query by TCP keepalive on the socket.
*/
public probeControlConnection(): void {
if (this.probePending || this.zongji.stopped || this.isStopped || this.isStopping) {
return;
}
this.probePending = true;
const controlConnection = this.zongji.ctrlConnection;
const timeout = this.options.ctrlConnectionProbeTimeoutMs ?? CTRL_CONNECTION_PROBE_TIMEOUT;
controlConnection.query({ sql: 'SELECT 1', timeout }, (error) => {
this.probePending = false;
// Only act if the probe failed on a connection that is still supposed to be alive.
if (
error != null &&
this.zongji.ctrlConnection === controlConnection &&
!this.zongji.stopped &&
!(this.isStopped || this.isStopping)
) {
this.logger.warn('MySQL control connection is unresponsive. Stopping the BinLog Listener...');
this.listenerError = new Error('MySQL control connection is unresponsive.');
controlConnection._socket?.destroy();
this.stop();
}
});
}

private createProcessingQueue(): async.QueueObject<BinLogEvent> {
const queue = async.queue(this.createQueueWorker(), 1);

Expand Down
11 changes: 11 additions & 0 deletions modules/module-mysql/src/utils/mysql-utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,13 @@ export type RetriedQueryOptions = {
retries?: number;
};

/**
* TCP keepalive initial delay in milliseconds for connections to the MySQL server.
* Keepalive prevents long-lived idle connections from being silently dropped by stateful
* firewalls, which commonly time out idle flows after an hour.
*/
export const TCP_KEEPALIVE_INITIAL_DELAY = 40_000;

/**
* Retry a simple query - up to 2 attempts total.
*/
Expand Down Expand Up @@ -54,6 +61,10 @@ export function createPool(config: types.NormalizedMySQLConnectionConfig, option
timezone: 'Z', // Ensure no auto timezone manipulation of the dates occur
jsonStrings: true, // Return JSON columns as strings
dateStrings: true, // We parse and format them ourselves
// mysql2 enables TCP keepalive by default, but without an initial delay the OS default of
// 7200 seconds applies, which is too late for common 3600 second firewall idle timeouts.
enableKeepAlive: true,
keepAliveInitialDelay: TCP_KEEPALIVE_INITIAL_DELAY,
// Apply URL connection parameters (explicit options override these via spread below)
...(params.connectTimeout != null ? { connectTimeout: params.connectTimeout } : {}),
...(params.connectionLimit != null ? { connectionLimit: params.connectionLimit } : {}),
Expand Down
123 changes: 122 additions & 1 deletion modules/module-mysql/test/src/BinLogListener.test.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,12 @@
import { MySQLConnectionManager } from '@module/replication/MySQLConnectionManager.js';
import { BinLogListener, SchemaChange, SchemaChangeType } from '@module/replication/zongji/BinLogListener.js';
import { getMySQLVersion, qualifiedMySQLTable, satisfiesVersion } from '@module/utils/mysql-utils.js';
import {
getMySQLVersion,
qualifiedMySQLTable,
satisfiesVersion,
TCP_KEEPALIVE_INITIAL_DELAY
} from '@module/utils/mysql-utils.js';
import { MySQLConnection } from '@powersync/mysql-zongji';
import { TablePattern } from '@powersync/service-sync-rules';
import crypto from 'crypto';
import { v4 as uuid } from 'uuid';
Expand All @@ -13,6 +19,11 @@ import {
TestBinLogEventHandler
} from './util.js';

// The zongji type definitions do not expose the connection config.
type ConnectionWithConfig = MySQLConnection & {
config: { enableKeepAlive?: boolean; keepAliveInitialDelay?: number };
};

describe('BinlogListener tests', { timeout: 60_000 }, () => {
const MAX_QUEUE_CAPACITY_MB = 1;
const BINLOG_LISTENER_CONNECTION_OPTIONS = {
Expand Down Expand Up @@ -59,6 +70,116 @@ describe('BinlogListener tests', { timeout: 60_000 }, () => {

expect(stopSpy).toHaveBeenCalled();
expect(queueStopSpy).toHaveBeenCalled();
// Zongji destroys its control connection when stopping.
expect(binLogListener.zongji.ctrlConnection.state).toBe('disconnected');
});

test('TCP keepalive is enabled on the binlog and control connections', async () => {
// Without keepalive, the control connection can idle for hours and be silently dropped by
// stateful firewalls. The next metadata query then blocks until the kernel gives up on TCP
// retransmissions, freezing the whole binlog pipeline for ~15 minutes.
const { connection } = binLogListener.zongji as unknown as { connection: ConnectionWithConfig };
const controlConnection = binLogListener.zongji.ctrlConnection as ConnectionWithConfig;

for (const conn of [connection, controlConnection]) {
expect(conn.config.enableKeepAlive).toBe(true);
expect(conn.config.keepAliveInitialDelay).toBe(TCP_KEEPALIVE_INITIAL_DELAY);
}
});

test('Stop completes when the control connection is unresponsive', { timeout: 20_000 }, async () => {
await binLogListener.start();

// Simulate a control connection that was silently dropped by the network: the KILL query
// issued by zongji.stop() never gets a response.
vi.spyOn(binLogListener.zongji.ctrlConnection, 'query').mockImplementation(() => {});

await binLogListener.stop();

expect(binLogListener.zongji.stopped).toBeTruthy();
});

test('Probe on a healthy control connection passes', { timeout: 20_000 }, async () => {
await binLogListener.start();

// No mocking: the real driver must accept the options form of query and answer the probe.
const controlConnection = binLogListener.zongji.ctrlConnection;
const realQuery = controlConnection.query.bind(controlConnection);
const probeError = new Promise((resolve) => {
vi.spyOn(controlConnection, 'query').mockImplementation(((options: any, callback: any) => {
realQuery(options, (error: any, results: any, fields: any) => {
callback(error, results, fields);
resolve(error);
});
}) as any);
});

binLogListener.probeControlConnection();

expect(await probeError).toBeNull();
expect(binLogListener.zongji.stopped).toBeFalsy();

await binLogListener.stop();
});

test('Probe detects an unresponsive control connection', { timeout: 20_000 }, async () => {
binLogListener = await createBinlogListener({
connectionManager,
sourceTables: [new TablePattern(connectionManager.databaseName, 'test_DATA')],
eventHandler,
ctrlConnectionProbeTimeoutMs: 500
});
await binLogListener.start();

// The probe query starts executing but never gets a response, like a connection that died
// without either side being notified: the driver's query timeout fires.
vi.spyOn(binLogListener.zongji.ctrlConnection, 'query').mockImplementation(((_options: any, callback: any) => {
const error: any = new Error('Query inactivity timeout');
error.code = 'PROTOCOL_SEQUENCE_TIMEOUT';
setTimeout(() => callback(error), 10);
}) as any);

const replication = binLogListener.replicateUntilStopped();
binLogListener.probeControlConnection();

await expect(replication).rejects.toThrow('control connection is unresponsive');
expect(binLogListener.zongji.stopped).toBeTruthy();
});

test('Probe queued behind a busy control connection does not report it dead', { timeout: 20_000 }, async () => {
binLogListener = await createBinlogListener({
connectionManager,
sourceTables: [new TablePattern(connectionManager.databaseName, 'test_DATA')],
eventHandler,
ctrlConnectionProbeTimeoutMs: 500
});
await binLogListener.start();

// The probe never even starts executing, as if queued behind a long-running metadata query on
// a healthy connection. The probe must not report the connection dead, and further probes must
// not pile up behind the pending one.
const querySpy = vi.spyOn(binLogListener.zongji.ctrlConnection, 'query').mockImplementation((() => {}) as any);

binLogListener.probeControlConnection();
binLogListener.probeControlConnection();

expect(querySpy).toHaveBeenCalledTimes(1);
expect(binLogListener.zongji.stopped).toBeFalsy();

querySpy.mockRestore();
await binLogListener.stop();
});

test('Control connection errors stop the listener', { timeout: 20_000 }, async () => {
await binLogListener.start();

const replication = binLogListener.replicateUntilStopped();
// The driver emits 'error' when the socket fails while no query is pending. Without the
// forwarding set up in createBinlogListener, this event has no listener and crashes the process.
(binLogListener.zongji.ctrlConnection as any).emit('error', new Error('Control connection failure'));

await expect(replication).rejects.toThrow('Control connection failure');
expect(binLogListener.zongji.stopped).toBeTruthy();
});

test('Zongji listener is stopped when processing queue reaches maximum memory size', async () => {
Expand Down
20 changes: 19 additions & 1 deletion modules/module-mysql/test/src/mysql-utils.test.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
import { isVersionAtLeast } from '@module/utils/mysql-utils.js';
import * as types from '@module/types/types.js';
import { createPool, isVersionAtLeast, TCP_KEEPALIVE_INITIAL_DELAY } from '@module/utils/mysql-utils.js';
import { describe, expect, test } from 'vitest';

describe('MySQL Utility Tests', () => {
Expand All @@ -14,4 +15,21 @@ describe('MySQL Utility Tests', () => {
expect(isVersionAtLeast(olderVersion, '8.0')).toBeFalsy();
expect(isVersionAtLeast(improperSemver, '5.7')).toBeTruthy();
});

test('Pool connections are configured with a TCP keepalive initial delay', async () => {
// mysql2 enables keepalive by default, but without an initial delay the OS default of
// 7200 seconds applies, which is too late for common 3600 second firewall idle timeouts.
const config = types.normalizeConnectionConfig({
type: 'mysql',
uri: 'mysql://root:password@localhost:3306/mydatabase'
});
// The pool is lazy, so no connection is made here.
const pool = createPool(config);
const { connectionConfig } = (pool as unknown as { config: { connectionConfig: Record<string, unknown> } }).config;

expect(connectionConfig.enableKeepAlive).toBe(true);
expect(connectionConfig.keepAliveInitialDelay).toBe(TCP_KEEPALIVE_INITIAL_DELAY);

await pool.promise().end();
});
});
Loading
Loading