Prisma1: Mongo connector leaks connections

[divyenduz]

Describe the bug
MongoDB connector opens connection when under load but does not release them

To Reproduce
https://github.com/divyenduz/prisma-4165

Expected behavior
MongoDB should release unused connections

Screenshots
MongoDB Atlast connection dashboard

Versions (please complete the following information):

• Connector: MongoDB
• Prisma Server: 1.26.5 - Not tested on latest yet because https://github.com/prisma/prisma/issues/4151
• prisma CLI: prisma/1.28.2 (darwin-x64) node-v10.4.0

[do4gr]

The MongoDB connector is configured by providing the connection string uri. This allows you to also set its connection pooling behaviour.

Atlas provides you with a string that does not explicitly configure the connection pooling:
mongodb+srv://user:[email protected]/test?retryWrites=true

The MongoClient instantiated by Prisma then falls back to the defaults, a pool size of 100 and no timeout for the connections.

If you want different behaviour, you can attach options to your uri, see here https://docs.mongodb.com/manual/reference/connection-string/#urioption.connectTimeoutMS

The following string limits the MongoClient to 10 connections and forces a connection close after 60s.
mongodb+srv://user:[email protected]/test?retryWrites=true&maxIdleTimeMS=60000&maxPoolSize=10

Prisma will instantiate a client for Deploys and one for API calls, so you might see up to 20 connections here from Prisma if you mix a lot of deploys and normal queries/mutations.

This shows the connection behaviour with default options (the first two plateaus), where Prisma will open a lot of connections and not close them (I manually shut down the Prisma container for the drops).

The later smaller peaks show the behaviour with the second connection string. Prisma will start fewer connections and close them after 60s of idle time.

[soqt]

I have a problem with every new connection takes too much time(a couple seconds from server), then the client can perform queries or mutations very fast. And after certain time users need to wait the same time to reconnect to mongoDB. Is this the same problem?
Some errors I got

[WARNING] Got socket exception on connection [connectionId{localValue:3, serverValue:2}] to mongo:27017. All connections to mongo:27017 will be closed.
[INFO] Closed connection [connectionId{localValue:3, serverValue:2}] to mongo:27017 because there was a socket exception raised by this connection.
[Telemetry] Warning: Telemetry call failed with com.mongodb.MongoSocketReadException: Prematurely reached end of stream
[INFO] Exception in monitor thread while connecting to server mongo:27017
mongo: System error
com.mongodb.MongoSocketException: mongo: System error
    at com.mongodb.ServerAddress.getSocketAddress(ServerAddress.java:188)
    at com.mongodb.internal.connection.AsynchronousSocketChannelStream.openAsync(AsynchronousSocketChannelStream.java:86)
    at com.mongodb.internal.connection.AsynchronousSocketChannelStream.open(AsynchronousSocketChannelStream.java:67)
    at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:126)
    at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:131)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.net.UnknownHostException: mongo: System error
    at java.net.Inet4AddressImpl.lookupAllHostAddr(Native Method)
    at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:929)
    at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1324)
    at java.net.InetAddress.getAllByName0(InetAddress.java:1277)
    at java.net.InetAddress.getAllByName(InetAddress.java:1193)
    at java.net.InetAddress.getAllByName(InetAddress.java:1127)
    at java.net.InetAddress.getByName(InetAddress.java:1077)
    at com.mongodb.ServerAddress.getSocketAddress(ServerAddress.java:186)
    ... 5 more
No log level set, defaulting to INFO.
[INFO] Cluster created with settings {hosts=[mongo:27017], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
[INFO] Opened connection [connectionId{localValue:1, serverValue:1}] to mongo:27017
[INFO] Monitor thread successfully connected to server with description ServerDescription{address=mongo:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 6]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=11497236}
[INFO] Obtaining exclusive agent lock...
[INFO] Obtaining exclusive agent lock... Successful.

[do4gr]

Hey @soqt, I think this is a different issue.

So this com.mongodb.MongoSocketException: mongo: System error indicates a networking related issue. See: https://mongodb.github.io/mongo-java-driver/3.6/javadoc/com/mongodb/MongoSocketException.html

Since Prisma is able to pick up the connection I suspect that that is not a Prisma issue but that the network connection between Prisma and Mongo is somehow unstable.

You can of course also try to play around with the connection string settings for Mongo and see if that helps. See here: https://docs.mongodb.com/manual/reference/connection-string/#connections-connection-options

socketTimeoutMS and connectTimeoutMS are related to the connection.