Skip to content

Commit 1d1443b

Browse files
authored
Merge pull request #851 from unix/codex/fix-listen-heartbeat
fix: recover silent LISTEN/NOTIFY connection failures
2 parents 52ec0b2 + 189cdec commit 1d1443b

4 files changed

Lines changed: 315 additions & 11 deletions

File tree

src/db.ts

Lines changed: 80 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,13 @@ import pg from 'pg'
33
import assert from 'node:assert'
44
import type * as types from './types.ts'
55

6+
// Keep silent network failures below the default 30-second notify polling backstop: in the
7+
// worst case a failure happens immediately after a successful check, then takes one interval,
8+
// one query timeout, and the existing first reconnect backoff (1s) to restore LISTEN.
9+
const LISTEN_HEARTBEAT_INTERVAL_MS = 10000
10+
const LISTEN_HEARTBEAT_TIMEOUT_MS = 5000
11+
const LISTEN_KEEP_ALIVE_INITIAL_DELAY_MS = 10000
12+
613
class Db extends EventEmitter implements types.IDatabase, types.EventsMixin {
714
private pool!: pg.Pool
815
private config: types.DatabaseOptions
@@ -57,8 +64,9 @@ class Db extends EventEmitter implements types.IDatabase, types.EventsMixin {
5764

5865
// Opens a dedicated, session-pinned connection for LISTEN/NOTIFY. A separate pg.Client
5966
// (not a pooled connection) is used so the listener never depletes the query pool and so
60-
// reconnection is self-contained. On any drop the client reconnects with capped backoff
61-
// and re-runs LISTEN, then calls onReconnect so the caller can recover missed messages.
67+
// reconnection is self-contained. TCP keepalive plus a same-session heartbeat detect silent
68+
// drops and lost subscriptions. The client reconnects with capped backoff, re-runs LISTEN,
69+
// then calls onReconnect so the caller can recover missed messages.
6270
async listen (
6371
channel: string,
6472
onNotification: (payload: string) => void,
@@ -69,14 +77,23 @@ class Db extends EventEmitter implements types.IDatabase, types.EventsMixin {
6977
let closed = false
7078
let client: pg.Client | null = null
7179
let reconnectTimer: ReturnType<typeof setTimeout> | null = null
80+
let heartbeatTimer: ReturnType<typeof setTimeout> | null = null
7281
let attempt = 0
82+
const heartbeatInterval = this.config.__test__listenHeartbeatIntervalMs ?? LISTEN_HEARTBEAT_INTERVAL_MS
83+
const heartbeatTimeout = this.config.__test__listenHeartbeatTimeoutMs ?? LISTEN_HEARTBEAT_TIMEOUT_MS
7384
// Only self-heal once the listener has been established at least once. If the INITIAL connect
7485
// fails, the rejection propagates to the caller (Notifier.start), which falls back to
7586
// polling-only and discards this subscription's close handle — so a reconnect scheduled from
7687
// the client 'error' handler would be an untracked connection nothing can close, keeping the
7788
// event loop alive and delivering notifications into a stopped manager.
7889
let established = false
7990

91+
const clearHeartbeat = () => {
92+
if (!heartbeatTimer) return
93+
clearTimeout(heartbeatTimer)
94+
heartbeatTimer = null
95+
}
96+
8097
const scheduleReconnect = () => {
8198
if (closed || reconnectTimer) return
8299
const backoff = Math.min(30000, 1000 * 2 ** Math.min(attempt, 5))
@@ -87,21 +104,72 @@ class Db extends EventEmitter implements types.IDatabase, types.EventsMixin {
87104
}, backoff)
88105
}
89106

107+
const disconnect = (target: pg.Client, error: Error) => {
108+
if (closed || client !== target) return
109+
110+
clearHeartbeat()
111+
client = null
112+
target.removeAllListeners()
113+
target.end().catch(() => {})
114+
this.emit('error', error)
115+
if (established) scheduleReconnect()
116+
}
117+
118+
const scheduleHeartbeat = (target: pg.Client) => {
119+
if (closed || client !== target) return
120+
heartbeatTimer = setTimeout(() => {
121+
heartbeatTimer = null
122+
heartbeat(target).catch(error => disconnect(target, error))
123+
}, heartbeatInterval)
124+
}
125+
126+
const heartbeat = async (target: pg.Client) => {
127+
if (closed || client !== target) return
128+
129+
let timeout: ReturnType<typeof setTimeout> | null = null
130+
const query = target.query(
131+
`SELECT EXISTS (
132+
SELECT 1
133+
FROM pg_listening_channels() AS active(channel)
134+
WHERE channel = $1
135+
) AS listening`,
136+
[channel]
137+
)
138+
query.catch(() => {})
139+
140+
try {
141+
const result = await Promise.race([
142+
query,
143+
new Promise<never>((resolve, reject) => {
144+
timeout = setTimeout(() => reject(new Error('LISTEN/NOTIFY heartbeat timed out')), heartbeatTimeout)
145+
})
146+
])
147+
148+
if (!result.rows[0]?.listening) {
149+
throw new Error('LISTEN/NOTIFY channel registration was lost')
150+
}
151+
} finally {
152+
if (timeout) clearTimeout(timeout)
153+
}
154+
155+
scheduleHeartbeat(target)
156+
}
157+
90158
const connect = async () => {
91159
if (closed) return
92160

93-
const next = new pg.Client(this.config)
161+
const next = new pg.Client({
162+
...this.config,
163+
keepAlive: true,
164+
keepAliveInitialDelayMillis: LISTEN_KEEP_ALIVE_INITIAL_DELAY_MS
165+
})
94166

95167
next.on('error', error => {
96-
this.emit('error', error)
97-
if (!closed) {
98-
next.removeAllListeners()
99-
next.end().catch(() => {})
100-
if (client === next) client = null
101-
if (established) scheduleReconnect()
102-
}
168+
disconnect(next, error)
103169
})
104170

171+
next.on('end', () => disconnect(next, new Error('LISTEN/NOTIFY connection ended')))
172+
105173
next.on('notification', msg => {
106174
if (msg.payload !== undefined) onNotification(msg.payload)
107175
})
@@ -125,6 +193,7 @@ class Db extends EventEmitter implements types.IDatabase, types.EventsMixin {
125193

126194
attempt = 0
127195
established = true
196+
scheduleHeartbeat(next)
128197
onReconnect()
129198
}
130199

@@ -137,6 +206,7 @@ class Db extends EventEmitter implements types.IDatabase, types.EventsMixin {
137206
clearTimeout(reconnectTimer)
138207
reconnectTimer = null
139208
}
209+
clearHeartbeat()
140210
if (client) {
141211
client.removeAllListeners()
142212
await client.end().catch(() => {})

src/types.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,10 @@ export interface DatabaseOptions {
4747
connectionTimeoutMillis?: number;
4848
/** @internal */
4949
debug?: boolean;
50+
/** @internal */
51+
__test__listenHeartbeatIntervalMs?: number;
52+
/** @internal */
53+
__test__listenHeartbeatTimeoutMs?: number;
5054
}
5155

5256
export interface SchedulingOptions {

test/dbListenTest.ts

Lines changed: 108 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,9 @@
1-
import { it, expect } from 'vitest'
1+
import pg from 'pg'
2+
import { it, expect, vi } from 'vitest'
3+
import Db from '../src/db.ts'
24
import * as helper from './testHelper.ts'
35
import { delay } from '../src/tools.ts'
6+
import HalfOpenProxy from './halfOpenProxy.ts'
47

58
// Exercises the low-level LISTEN/NOTIFY connection lifecycle on Db directly: the
69
// dedicated session-pinned client, capped-backoff reconnection after a dropped
@@ -18,6 +21,110 @@ async function terminateListener (db: any, channel: string): Promise<void> {
1821
// pg_terminate_backend, and capped-backoff reconnection. None of that exists for embedded
1922
// single-connection PGlite, so skip the whole file there (PGlite's listen is covered via fromPglite).
2023
helper.describePglite('db listen/notify', function () {
24+
it('detects a silent half-open listener and restores the subscription', async function () {
25+
const config = helper.getConfig()
26+
if (!config.host || !config.port) throw new Error('Postgres host and port are required')
27+
28+
const proxy = new HalfOpenProxy(config.host, config.port)
29+
const proxyPort = await proxy.start()
30+
const db = new Db({
31+
...config,
32+
application_name: 'pgboss_half_open_test',
33+
host: '127.0.0.1',
34+
port: proxyPort,
35+
__test__listenHeartbeatIntervalMs: 100,
36+
__test__listenHeartbeatTimeoutMs: 100
37+
})
38+
const channel = 'pgboss_db_half_open_test'
39+
const payloads: string[] = []
40+
const errors: Error[] = []
41+
let reconnects = 0
42+
let handle: Awaited<ReturnType<Db['listen']>> | undefined
43+
44+
db.on('error', error => errors.push(error))
45+
await db.open()
46+
47+
try {
48+
const generation = proxy.listenerGeneration
49+
handle = await db.listen(channel, payload => payloads.push(payload), () => { reconnects++ })
50+
const listener = await proxy.waitForListenerAfter(generation)
51+
expect(reconnects).toBe(1)
52+
53+
proxy.blackhole(listener)
54+
55+
for (let i = 0; i < 40; i++) {
56+
if (reconnects >= 2) break
57+
await delay(100)
58+
}
59+
60+
expect(reconnects).toBe(2)
61+
expect(errors.some(error => error.message === 'LISTEN/NOTIFY heartbeat timed out')).toBe(true)
62+
63+
await db.executeSql(`NOTIFY "${channel}", 'recovered'`)
64+
for (let i = 0; i < 30; i++) {
65+
if (payloads.length) break
66+
await delay(100)
67+
}
68+
expect(payloads).toContain('recovered')
69+
} finally {
70+
await handle?.close()
71+
await db.close()
72+
await proxy.close()
73+
}
74+
})
75+
76+
it('reconnects when the heartbeat finds the channel registration missing', async function () {
77+
const db = new Db({
78+
...helper.getConfig(),
79+
application_name: 'pgboss_lost_subscription_test',
80+
__test__listenHeartbeatIntervalMs: 100,
81+
__test__listenHeartbeatTimeoutMs: 100
82+
})
83+
const channel = 'pgboss_db_lost_subscription_test'
84+
const payloads: string[] = []
85+
const errors: Error[] = []
86+
let reconnects = 0
87+
let reportMissing = true
88+
let handle: Awaited<ReturnType<Db['listen']>> | undefined
89+
const originalQuery = pg.Client.prototype.query
90+
const querySpy = vi.spyOn(pg.Client.prototype, 'query').mockImplementation(function (this: pg.Client, ...args: any[]) {
91+
const [text] = args
92+
if (reportMissing && typeof text === 'string' && text.includes('FROM pg_listening_channels()')) {
93+
reportMissing = false
94+
return Promise.resolve({ rows: [{ listening: false }] }) as any
95+
}
96+
97+
return originalQuery.apply(this, args as any)
98+
})
99+
100+
db.on('error', error => errors.push(error))
101+
102+
try {
103+
await db.open()
104+
handle = await db.listen(channel, payload => payloads.push(payload), () => { reconnects++ })
105+
expect(reconnects).toBe(1)
106+
107+
for (let i = 0; i < 30; i++) {
108+
if (reconnects >= 2) break
109+
await delay(100)
110+
}
111+
112+
expect(reconnects).toBe(2)
113+
expect(errors.some(error => error.message === 'LISTEN/NOTIFY channel registration was lost')).toBe(true)
114+
115+
await db.executeSql(`NOTIFY "${channel}", 'recovered'`)
116+
for (let i = 0; i < 30; i++) {
117+
if (payloads.length) break
118+
await delay(100)
119+
}
120+
expect(payloads).toContain('recovered')
121+
} finally {
122+
querySpy.mockRestore()
123+
await handle?.close()
124+
await db.close()
125+
}
126+
})
127+
21128
it('reconnects after the listen connection drops and delivers later notifications', async function () {
22129
const db = await helper.getDb()
23130
const channel = 'pgboss_db_reconnect_test'

0 commit comments

Comments
 (0)