I continued to investigate this issue. Then I found some interesting facts.
I subscribed some connection pool events in my applicastion such as “connectionReady” “connectionClosed” “connectionCheckOutFailed” “connectionPoolCleared” “connectionPoolClosed” and so on. I kept watching my application’s output closely while my application was running.
I saw that some connections start to become ready after connection pool was created. At the beginning only a few connections were ready. When my application began to work and connected to mongodb instance more frequently more connections become ready. And the connection Id will increase one by one from 1.
name: ‘connectionReady’, connectionId: 1
name: ‘connectionReady’, connectionId: 2
name: ‘connectionReady’, connectionId: 4
name: ‘connectionReady’, connectionId: 3
name: ‘connectionReady’, connectionId: 6
name: ‘connectionReady’, connectionId: 7
name: ‘connectionReady’, connectionId: 8
name: ‘connectionReady’, connectionId: 9
name: ‘connectionReady’, connectionId: 5
…
Here are parts of my received ‘connectionReady’ events.
After a while the driver begins to close some old connections. I know that because my application got “connectionClosed” events. At the same time more connections were created and got ready.
event connection is ready: ConnectionReadyEvent {
time: 2024-04-16T07:40:16.745Z,
address: ‘db1.arts.mybusiness.com:27017’,
name: ‘connectionReady’,
connectionId: 43
}
event connection is ready: ConnectionReadyEvent {
time: 2024-04-16T07:40:16.746Z,
address: ‘db1.arts.mybusiness.com:27017’,
name: ‘connectionReady’,
connectionId: 44
}
Then more old connections were closed.
event connection is closed: ConnectionClosedEvent {
time: 2024-04-16T07:52:52.368Z,
address: ‘db1.arts.mybusiness.com:27017’,
name: ‘connectionClosed’,
connectionId: 14,
reason: ‘error’,
serviceId: undefined,
error: null
}
event connection is closed: ConnectionClosedEvent {
time: 2024-04-16T07:52:52.368Z,
address: ‘db1.arts.mybusiness.com:27017’,
name: ‘connectionClosed’,
connectionId: 37,
reason: ‘error’,
serviceId: undefined,
error: null
}
Then I saw that two connections 51 and 52 were skipped. My application didn’t receive “ConnectionReadyEvent” of these two connections. I could see “ConnectionCreatedEvent” of these two connections. But they didn’t become ready. I suppose that the driver failed to create the socket connection between client and the server for these two connections. I don’t know exactly why these two connections failed to become ready. I had not found any failure message in the mongodb server logs.
Although connections 51 and 52 were not ready the driver still tried to close these two connections after some time. My application got “connectionClosedEvent” of these two connections. Along with the “connectionClosedEvent” are some exception message.
event connection is closed: ConnectionClosedEvent {
time: 2024-04-16T07:53:13.458Z,
address: ‘db1.arts.mybussiness:27017’,
name: ‘connectionClosed’,
connectionId: 51,
reason: ‘error’,
serviceId: undefined,
error: MongoNetworkError: connect ETIMEDOUT 20.246.185.149:27017
at connectionFailureError (C:\app\node_modules\mongodb\lib\cmap\connect.js:353:20)
at TLSSocket. (C:\app\node_modules\mongodb\lib\cmap\connect.js:268:44)
at Object.onceWrapper (node:events:633:26)
at TLSSocket.emit (node:events:518:28)
at TLSSocket.emit (node:domain:488:12)
at emitErrorNT (node:internal/streams/destroy:169:8)
at emitErrorCloseNT (node:internal/streams/destroy:128:3)
at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
[Symbol(errorLabels)]: Set(0) {},
[cause]: Error: connect ETIMEDOUT 20.246.185.149:27017
at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
errno: -4039,
code: ‘ETIMEDOUT’,
syscall: ‘connect’,
address: ‘20.246.185.149’,
port: 27017
}
}
}
event failed to check out connection: ConnectionCheckOutFailedEvent {
time: 2024-04-16T07:53:13.460Z,
address: ‘db1.arts.mybussiness.com:27017’,
name: ‘connectionCheckOutFailed’,
reason: ‘connectionError’,
error: MongoNetworkError: connect ETIMEDOUT 20.246.185.149:27017
at connectionFailureError (C:\app\node_modules\mongodb\lib\cmap\connect.js:353:20)
at TLSSocket. (C:\app\node_modules\mongodb\lib\cmap\connect.js:268:44)
at Object.onceWrapper (node:events:633:26)
at TLSSocket.emit (node:events:518:28)
at TLSSocket.emit (node:domain:488:12)
at emitErrorNT (node:internal/streams/destroy:169:8)
at emitErrorCloseNT (node:internal/streams/destroy:128:3)
at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
connectionGeneration: 0,
[Symbol(errorLabels)]: Set(0) {},
[cause]: Error: connect ETIMEDOUT 20.246.185.149:27017
at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
errno: -4039,
code: ‘ETIMEDOUT’,
syscall: ‘connect’,
address: ‘20.246.185.149’,
port: 27017
}
}
}
event connection pool is cleared: ConnectionPoolClearedEvent {
time: 2024-04-16T07:53:13.461Z,
address: ‘db1.arts.mybussiness.com:27017’,
name: ‘connectionPoolCleared’,
serviceId: undefined,
interruptInUseConnections: false
}
