Skip to content

fix: log idle client errors instead of crashing - #235

Open
TemoSulava wants to merge 2 commits into
fastify:mainfrom
TemoSulava:fix/pool-idle-client-error
Open

TemoSulava wants to merge 2 commits into
fastify:mainfrom
TemoSulava:fix/pool-idle-client-error

Conversation

@TemoSulava

Copy link
Copy Markdown

Fixes #168

If an idle client in the pool hits an error, for example when Postgres restarts or the
backend gets terminated, pg-pool emits 'error' on the pool. Nothing was listening
for it, so the whole Fastify process went down with an unhandled 'error' event.

The plugin now attaches a listener on the pool and logs the error with
fastify.log.error. The broken client is already removed by pg-pool, so the next
query just gets a fresh connection. Users who attach their own listener on
fastify.pg.pool still receive the event as before.

One behaviour change worth calling out: apps that relied on the crash to get
restarted by a supervisor will now keep running instead.

The test kills an idle backend with pg_terminate_backend, waits for the log
entry (57P01), and checks the pool still answers queries afterwards. It fails
without the fix.


const result = await fastify.pg.query('SELECT 1 AS one')
t.assert.strictEqual(result.rows[0].one, 1)
})

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
})
})
test('Should log instead of crashing when a checked-out client errors', { timeout: 10000 }, async (t) => {
t.plan(3)
const errorLogs = []
const stream = {
write (line) {
const log = JSON.parse(line)
if (log.level === 50) errorLogs.push(log)
}
}
const fastify = Fastify({ logger: { stream } })
await fastify.register(fastifyPostgres, {
connectionString
})
await fastify.ready()
const client = await fastify.pg.connect()
t.after(() => {
client.release()
return fastify.close()
})
const { rows } = await client.query('SELECT pg_backend_pid() AS pid')
const ended = new Promise((resolve) => client.once('end', resolve))
const admin = new fastify.pg.Client({ connectionString })
await admin.connect()
await admin.query('SELECT pg_terminate_backend($1)', [rows[0].pid])
await admin.end()
await ended
t.assert.strictEqual(errorLogs[0]?.err.code, '57P01')
await t.assert.rejects(client.query('SELECT 1'), /not queryable/)
const result = await fastify.pg.query('SELECT 1 AS one')
t.assert.strictEqual(result.rows[0].one, 1)
})

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updated the test to assert checked-out client error handling and pool recovery.

Comment thread index.js Outdated
Comment on lines +91 to +95
// stop idle client errors (e.g. a server restart) from crashing the process
pool.on('error', (err) => {
fastify.log.error({ err }, 'idle client error in pg pool')
})

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// stop idle client errors (e.g. a server restart) from crashing the process
pool.on('error', (err) => {
fastify.log.error({ err }, 'idle client error in pg pool')
})
// pg-pool re-emits idle client errors here; unhandled, it crashes the process
pool.on('error', () => {})
// fires for idle and checked-out clients, so log only here
pool.on('connect', (client) => {
client.on('error', (err) => {
fastify.log.error({ err, name }, 'pg client error')
})
})

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch, handling client errors on connect covers both idle and active clients while absorbing the pool re-emit. Applied!

@gurgunday gurgunday left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  1. Every dropped connection logs two errors (index.js:95). When a backend dies (Postgres restarts, or pg_terminate_backend), pg's Client emits the original error and then a second Connection terminated unexpectedly. The new permanent listener logs both, while pg-pool deliberately ignores the follow-ups. With 20 pooled clients, one restart writes 40 pg client error lines at error level. The test only checks errorLogs[0], so it doesn't notice.

  2. The test never covers the idle-client case from issue #168 (test/initialization.test.js:241). The new test kills a client that is still checked out. pg-pool removes its idle listener while a client is checked out, so the pool-level 'error' path never fires. You could delete pool.on('error', () => {}) at index.js:92, bringing back the #168 crash, and the suite would still pass. The PR description says the test kills an idle backend, but it doesn't. A better test would connect, release, terminate the now-idle backend, then assert the process survives and the error is logged.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

pg-pool force closing fastify instance

4 participants