[JAVA-852] Mongo options does not seem to work while working with replica-set Created: 10/Jun/13  Updated: 11/Sep/19  Resolved: 12/Jun/13

Status: Closed
Project: Java Driver
Component/s: Cluster Management
Affects Version/s: None
Fix Version/s: None

Type: Task Priority: Major - P3
Reporter: Atul Gupta Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

We are using replica-set and providing the configuration like the following, but these configuration options does not seem to work. We seem to be getting 2 problems-

1) if all the nodes of the mongo db are down, requests (e.g. mongoTemplate.save) hang for about 60-120 seconds and then throw an exception. Following is the configuration we are using, the behavior is same whether we use mongo options or not. We are using mongo db for logging purpose only which is used for logging requests and responses and want even if all nodes of the mongo db are down, requests should not hang (if these fail, these should exit immediately)

2) We see very fast re-connection attempts being made (hundreds of them in a sec) which clogs the log files very fast and we are not sure if #1 may be caused by this.

<mongo:mongo id="mongo" replica-set="${nosql.db.replicaset}">
<mongo:options
connect-timeout="5000"
max-wait-time="1500"
auto-connect-retry="true"
socket-keep-alive="true"
socket-timeout="1500"
slave-ok="true"
write-number="1"
write-timeout="1000"
write-fsync="true"/>
</mongo:mongo>

The following error is seen in the logs repeatedly-

org.springframework.data.mongodb.UncategorizedMongoDbException: Rare case where master=null, probably all servers are down; nested exception is com.mongodb.MongoException: Rare case where master=null, probably all servers are down
at org.springframework.data.mongodb.core.MongoExceptionTranslator.translateExceptionIfPossible(MongoExceptionTranslator.java:78)
at org.springframework.data.mongodb.core.MongoTemplate.potentiallyConvertRuntimeException(MongoTemplate.java:1694)
at org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:375)
at org.springframework.data.mongodb.core.MongoTemplate.collectionExists(MongoTemplate.java:437)
at com.expedia.globalpayments.svs.checker.MongoDatabaseChecker.check(MongoDatabaseChecker.java:56)
at com.expedia.e3.es.payment.common.status.cache.ComponentStatusUpdateTask.update(ComponentStatusUpdateTask.java:37)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:299)
at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:111)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:525)
Caused by: com.mongodb.MongoException: Rare case where master=null, probably all servers are down
at com.mongodb.DBTCPConnector$MyPort.get(DBTCPConnector.java:435)
at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:277)
at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:256)
at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:289)
at com.mongodb.DB.command(DB.java:259)
at com.mongodb.DB.command(DB.java:241)
at com.mongodb.DB.command(DB.java:282)
at com.mongodb.DB.command(DB.java:196)
at com.mongodb.DB$AuthenticationCredentials.authenticate(DB.java:796)
at com.mongodb.DB.authenticate(DB.java:569)
at org.springframework.data.mongodb.core.MongoDbUtils.doGetDB(MongoDbUtils.java:114)
at org.springframework.data.mongodb.core.MongoDbUtils.getDB(MongoDbUtils.java:75)
at org.springframework.data.mongodb.core.SimpleMongoDbFactory.getDb(SimpleMongoDbFactory.java:118)
at org.springframework.data.mongodb.core.SimpleMongoDbFactory.getDb(SimpleMongoDbFactory.java:107)
at org.springframework.data.mongodb.core.MongoTemplate.getDb(MongoTemplate.java:1286)
at org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:372)
... 12 more

Any help is highly appreciated-

Thanks,
Atul Gupta



 Comments   
Comment by Atul Gupta [ 12/Jun/13 ]

It was some problem with my Eclipse which was not setting the property properly, I tried it with command line and seems to work properly.

Thanks a lot for the help Jeff, both the issues stand resolved now

Comment by Jeffrey Yemin [ 11/Jun/13 ]

Hi Atul,

Good to hear that updating to 2.11.1 solved the first problem. Regarding the second problem, I wrote a small test program and ran it with -Dcom.mongodb.updaterIntervalNoMasterMS=5000, and it works as expected.

Program:

public class JAVA852 {
    public static void main(String[] args) throws UnknownHostException, InterruptedException {
        Mongo m = new Mongo(Arrays.asList(new ServerAddress("localhost:30000"), new ServerAddress("localhost:30001")));
        Thread.sleep(100000000);
    }

Command line:

java -Dcom.mongodb.updaterIntervalNoMasterMS=5000 -classpath mongo-java-driver-2.11.1.jar JAVA852

Output:

Jun 11, 2013 10:41:26 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:26 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:31 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:31 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:36 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:36 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:41 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:41 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:46 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:51 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:51 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused

If you can supply a test program which demonstrates the behavior you're seeing, we can investigate further.

Comment by Jeffrey Yemin [ 11/Jun/13 ]

Hi Atul,

Good to hear that updating to 2.11.1 solved the first problem. Regarding the second problem, I wrote a small test program and ran it with -Dcom.mongodb.updaterIntervalNoMasterMS=5000, and it works as expected.

Program:

public class JAVA852 {
    public static void main(String[] args) throws UnknownHostException, InterruptedException {
        Mongo m = new Mongo(Arrays.asList(new ServerAddress("localhost:30000"), new ServerAddress("localhost:30001")));
        Thread.sleep(100000000);
    }

Command line:

java -Dcom.mongodb.updaterIntervalNoMasterMS=5000 -classpath mongo-java-driver-2.11.1.jar JAVA852

Output:

Jun 11, 2013 10:41:26 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:26 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:31 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:31 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:36 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:36 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:41 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:41 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:46 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:51 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30000 - java.io.IOException - message: Connection refused
Jun 11, 2013 10:41:51 AM com.mongodb.ConnectionStatus$UpdatableNode update
WARNING: Server seen down: localhost/127.0.0.1:30001 - java.io.IOException - message: Connection refused

If you can supply a test program which demonstrates the behavior you're seeing, we can investigate further.

Comment by Atul Gupta [ 11/Jun/13 ]

Update---------------

There seems to be some problem with java driver 2.9.3 version as it does not make use of MongoOptions, I updated the jar to 2.11.1 and #1 is solved.

Regarding #2, I noticed that in ConnectionStatus.java line#97,

updaterIntervalNoMasterMS = Integer.parseInt(System.getProperty("com.mongodb.updaterIntervalNoMasterMS", "10"));

Now even when i have created a system property with name "com.mongodb.updaterIntervalNoMasterMS" and its value set to 5000, it is not picking it up and the default value of 10 ms is getting passed, hence it keeps retrying every 10 ms and floods the logs.

Is there any other way to update this to 5 seconds instead of default 10 ms?

Thanks,
Atul Gupta

Comment by Atul Gupta [ 11/Jun/13 ]

Hi Jeff,

Thanks a lot for replying.

java driver version - 2.9.3
Constructor called - public Mongo( List<ServerAddress> seeds , MongoOptions options )
MongoOptions - description=null, connectionsPerHost=10, threadsAllowedToBlockForConnectionMultiplier=5, maxWaitTime=1500, connectTimeout=1000, socketTimeout=1500, socketKeepAlive=true, autoConnectRetry=true, maxAutoConnectRetryTime=0, slaveOk=true, safe=false, w=1, wtimeout=1000, fsync=true, j=false, cursorFinalizerEnabled=true, alwaysUseMBeans=false

Please let me know if you require any additional inputs.

Thanks,
Atul Gupta

Comment by Jeffrey Yemin [ 10/Jun/13 ]

Hi Atul,

What version of the driver are you using? And can you determine which Mongo/MongoClient constructor is being invoked given your configuration?

Generated at Thu Feb 08 08:53:13 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.