MongoDB Atlas connections reset/refused

Iggy · March 3, 2023, 10:15am

I have a Spring Boot service deployed on AWS ECS. The service offers a REST API for clients and stores its data on a MongoDB Atlas M2 cluster (Replica Set - 3 nodes).

Recently, I noticed some strange logs popping up:

MongoSocketReadException

2023-02-17 15:09:46.998  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server <server-id>.mongodb.net:27017
com.mongodb.MongoSocketReadException: Prematurely reached end of stream
	at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:112) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:135) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:713) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.receiveMessageWithAdditionalTimeout(InternalStreamConnection.java:571) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:410) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.receive(InternalStreamConnection.java:369) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:221) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:157) ~[mongodb-driver-core-4.6.1.jar:na]
	at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]

MongoSocketWriteException

2023-02-17 15:09:47.015  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server <server-id>.mongodb.net:27017
com.mongodb.MongoSocketWriteException: Exception sending message
	at com.mongodb.internal.connection.InternalStreamConnection.translateWriteException(InternalStreamConnection.java:684) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:555) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendCommandMessage(InternalStreamConnection.java:381) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:329) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.CommandHelper.sendAndReceive(CommandHelper.java:101) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.CommandHelper.executeCommand(CommandHelper.java:45) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.initializeConnectionDescription(InternalStreamConnectionInitializer.java:131) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.startHandshake(InternalStreamConnectionInitializer.java:73) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:182) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:193) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:157) ~[mongodb-driver-core-4.6.1.jar:na]
	at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketException: Connection reset
	at java.base/java.net.SocketInputStream.read(Unknown Source) ~[na:na]
	at java.base/java.net.SocketInputStream.read(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketInputRecord.read(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketInputRecord.decode(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLTransport.decode(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketImpl.decode(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketImpl.readHandshakeRecord(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketImpl.ensureNegotiated(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(Unknown Source) ~[na:na]
	at com.mongodb.internal.connection.SocketStream.write(SocketStream.java:99) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:552) ~[mongodb-driver-core-4.6.1.jar:na]
	... 10 common frames omitted

MongoSocketOpenException

2023-02-17 15:09:57.018  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server <server-id>.mongodb.net:27017
com.mongodb.MongoSocketOpenException: Exception opening socket
	at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:70) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:180) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:193) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:157) ~[mongodb-driver-core-4.6.1.jar:na]
	at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.ConnectException: Connection refused (Connection refused)
	at java.base/java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:na]
	at java.base/java.net.AbstractPlainSocketImpl.doConnect(Unknown Source) ~[na:na]
	at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(Unknown Source) ~[na:na]
	at java.base/java.net.AbstractPlainSocketImpl.connect(Unknown Source) ~[na:na]
	at java.base/java.net.SocksSocketImpl.connect(Unknown Source) ~[na:na]
	at java.base/java.net.Socket.connect(Unknown Source) ~[na:na]
	at java.base/sun.security.ssl.SSLSocketImpl.connect(Unknown Source) ~[na:na]
	at com.mongodb.internal.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:107) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.SocketStream.initializeSocket(SocketStream.java:79) ~[mongodb-driver-core-4.6.1.jar:na]
	at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:65) ~[mongodb-driver-core-4.6.1.jar:na]
	... 4 common frames omitted

As this seems to consistently happen after idle periods, I figured this may be a timeout issue. Various sources on the internet suggest setting maxIdleTimeMS, but to no avail. Please note that my service is working nonetheless and I can retrieve data via its REST API w/o any issues. It seems to be able to recover from the above-mentioned connection exceptions…

My connection string looks as follows:

mongodb+srv://<user>:<password>@<server>.mongodb.net/<db>?retryWrites=true&w=majority&maxIdleTimeMS=60000

What am I missing?

Jeffrey_Yemin · March 3, 2023, 2:45pm

The key line in the logs is “Exception in monitor thread while connecting to server …”.

It’s normal to see these sorts of messages during planned maintenance of MongoDB servers (e.g. restarts for upgrades). The automatic retry features of the driver should hide most of these from your application and avoid exceptions being thrown to application threads via the drivers’s CRUD API.

Hope this helps.

Iggy · March 3, 2023, 5:09pm

Thanks Jeffrey for the quick response!

So what you are saying is those info logs are expected and the result of an Atlas node becoming (temporarily) unavailable, which is a perfectly normal scenario that won’t affect my service thanks to the driver’s retry features?

If so, could you please share some details on those “monitor threads”? What are they monitoring exactly?

Jeffrey_Yemin · March 4, 2023, 6:33pm

We refer to this as Server Discover and Monitoring (SDAM).

The general description is here.

The gory details are here.

system · March 17, 2023, 8:35am

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.