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
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.jsNote 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