Skip to content

Application may exit 0 when reconnecting to broker after losing connection #101

@KristjanTammekivi

Description

@KristjanTammekivi

Hi, discovered some heisenbug, initially thought it was my side but I created a script into examples in this repository and it happens here as well (I'll append this script to the end of this issue).

The bug that happens is that when losing connection to RabbitMQ (in my case I had rabbitmq running with docker-compose and I just started it up, and randomly killed it with ctrl-c ctrl-c) and reconnecting when rabbitmq is started up again the application may exit with code 0.

This annoyingly doesn't happen every time, sometimes I've done it 10-20 times in a row without an exit, sometimes I get it twice in a row. In my own repository I opened up node_modules and added random console.logs and only thing that I noticed was that a few milliseconds before it exits the close event listener in https://github.com/cloudamqp/amqp-client.js/blob/main/src/amqp-socket-client.ts#L85 is called with hadError === false

close.js

import { AMQPClient } from '../lib/mjs/amqp-client.js'

const log = (...args) => {
  const stack = new Error().stack.split('\n')
  const caller = stack[2].split(' ').pop().match(/(close\.js:\d+:\d+)/)[1]
  return console.log(new Date().toISOString(), ...args, `-${caller}`);
}

async function loopGetConnection() {
  let connectionAttempt = 0
  // eslint-disable-next-line no-constant-condition
  while (true) {
    log('Trying to connect', ++connectionAttempt)
    try {
      const amqp = new AMQPClient("amqp://localhost")
      await amqp.connect()
      return amqp
    } catch (err) {
      log('Failed to connect', err)
      await new Promise((resolve) => setTimeout(resolve, 50))
    }
  }
}

let conn = null
async function getConnection() {
  if (conn) {
    return conn
  }
  conn = await loopGetConnection()
  conn.logger = {
    debug: (...args) => log('debug', ...args),
    info: (...args) => log('info', ...args),
    warn: (...args) => log('warn', ...args),
    error: (...args) => log('error', ...args),
  }
  conn.onerror = (err) => {
    log(err);
    conn = null;
  }
  return conn;
}

process.on('uncaughtException', (err) => {
  log('uncaughtException', err)
  process.exit(1)
})

process.on('unhandledRejection', (err) => {
  log('unhandledRejection', err)
  process.exit(1)
})

process.on('exit', (code) => {
  log('exit', code)
  process.exit(code)
})

async function run() {
  {
    const conn = await getConnection()
    const ch = await conn.channel()
    await ch.queue('test', { autoDelete: true })
  }
  // eslint-disable-next-line no-constant-condition
  while (true) {
    const conn = await getConnection()
    const ch = await conn.channel()
    try {
      await ch.queue('test', { autoDelete: true })
      log('published a message');
    } catch (err) {
      log('Failed to publish', err)
    } finally {
      await ch.close()
    }
    await new Promise((resolve) => setTimeout(resolve, 1000))
  }
}
try {
  await run()
  log('Run exited normally unexpectedly') // should never happen
} catch (e) {
  log('Run exited unexpectedly', e)
}

Note that I've added on unhandledException and unhandledRejection handlers, they don't get called and anyway the process exists with 0, indicating that there was no error.
The last 2 log lines that I get are as follows

2023-11-18T17:13:04.520Z Trying to connect 68 -close.js:13:5
2023-11-18T17:13:04.523Z exit 0 -close.js:55:3

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions