在MongoDB中打开连接的SocketTimeout


问题内容

我有一个Java应用程序,它在MongoDB上执行一些聚合,但是有时它会挂起并抛出SocketTimeout异常。异常发生后,应用程序将正常运行(稍等片刻,然后它可能会再次引发异常)。

我刚刚发现这种解释似乎是可能的原因,但不确定。

我启动MongoClient并保持与数据库的连接打开。我不确定这是否可能是一个问题,我应该每次都获取数据库,然后让数据库进行垃圾回收(并关闭连接)。

另一种方法是定期ping Mongo以保持连接池“新鲜”。

使用的客户端是这样的:

public class DbClient {

    private static MongoClient mongoClient;
    private static MongoDatabase db;

    private DbClient() {}

    public static void init() throws Exception {
        mongoClient = new MongoClient();
    }

    public static MongoDatabase getDB() {
        if(mongoClient == null)
            throw new IllegalStateException("Client not initialized!");

        if(db == null) {
            db = mongoClient.getDatabase("my_db");
        }
        return db;
    }
}

这是SocketTimeout的可能原因吗?

这是抛出的异常:

09:20:45.742 [qtp605535417-46] INFO  org.mongodb.driver.connection - Closed connection [connectionId{localValue:16, serverValue:6562}] to myapp.com:27017 because there was a socket exception raised by this connection.
09:20:45.743 [qtp605535417-46] ERROR myapp.service.Api - Error processing request
com.mongodb.MongoSocketReadTimeoutException: Timeout while receiving message
    at com.mongodb.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:474) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:225) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.UsageTrackingInternalConnection.receiveMessage(UsageTrackingInternalConnection.java:102) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.DefaultConnectionPool$PooledConnection.receiveMessage(DefaultConnectionPool.java:435) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.CommandProtocol.execute(CommandProtocol.java:112) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:159) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:286) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:173) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:215) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:206) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:112) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.FindOperation$1.call(FindOperation.java:487) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.FindOperation$1.call(FindOperation.java:482) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:239) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:212) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.FindOperation.execute(FindOperation.java:482) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.operation.FindOperation.execute(FindOperation.java:79) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.Mongo.execute(Mongo.java:772) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.Mongo$2.execute(Mongo.java:759) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.OperationIterable.iterator(OperationIterable.java:47) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.FindIterableImpl.iterator(FindIterableImpl.java:143) ~[mongo-java-driver-3.2.2.jar!/:na]
    at myapp.common.db.service.dao.AnalysisMongoImpl.getAnalysis(AnalysisMongoImpl.java:66) ~[common-0.2.0-SNAPSHOT.jar!/:na]
    at myapp.common.db.service.AnalysisServiceImpl.getAnalysis(AnalysisServiceImpl.java:31) ~[common-0.2.0-SNAPSHOT.jar!/:na]
    at myapp.aggregator.service.Api$1.handle(Api.java:88) ~[aggregator-0.2.0-SNAPSHOT.jar!/:na]
    at spark.webserver.MatcherFilter.doFilter(MatcherFilter.java:139) [spark-core-1.1.1.jar!/:na]
    at spark.webserver.JettyHandler.doHandle(JettyHandler.java:54) [spark-core-1.1.1.jar!/:na]
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:179) [jetty-server-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:136) [jetty-server-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.server.Server.handle(Server.java:451) [jetty-server-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:252) [jetty-server-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:266) [jetty-server-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:240) [jetty-io-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596) [jetty-util-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527) [jetty-util-9.0.2.v20130417.jar!/:9.0.2.v20130417]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_95]
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_95]
    at java.net.SocketInputStream.read(SocketInputStream.java:152) ~[na:1.7.0_95]
    at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_95]
    at com.mongodb.connection.SocketStream.read(SocketStream.java:85) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:491) ~[mongo-java-driver-3.2.2.jar!/:na]
    at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:221) ~[mongo-java-driver-3.2.2.jar!/:na]
    ... 34 common frames omitted

问题答案:

经过几次尝试,我发现这是Azure的Load
Balancer的问题

闲置60秒钟后,它将断开所有未决的TCP连接。

进一步挖掘之后,我发现了MongoDB诊断常见问题解答的这篇文章,并将tcp keepalive设置为120s:

sudo sysctl -w net.ipv4.tcp_keepalive_time=<value>

并且我还将MongoClient的socketKeepAlive设置为true:

MongoClientOptions.Builder options = MongoClientOptions.builder();
options.socketKeepAlive(true);
mongoClient = new MongoClient(mongoAddress, options.build());

这些修复之后,问题似乎消失了!