[Java Driver] Very slow response from Slave with network partition

[Emanuele Bragagnolo]

Hello!

I have noticed this strange behavior when simulating a network
partition with replica set. I have seen this problem with 2.6.5 and
2.7.2 java driver version.

I have a simple script that query mongo slaves and then print response
time

Configuration:

2 mongo instance in a datacenter (fr)
1 mongo instance in an other (de)

In normal situation a query takes about 15ms to be resolved.


If i turn off the 2 nodes in fr to simulate network partition, node in
de becomes, or remains, a slave because it does not have majority. But
when i try to read from it using SlaveOK the time response raise:
query take from 1 sec to 6 secs. When a node returns on line and a
master is elected the problem disappears.

If i run the same query inside mongo shell there's no delay.

With 2.7.2 driver i use replace SlaveOk with setReadPreference using
tag for data center awareness.

[Nat]

Can you try to lower MongoOptions.connectionTimeout to see whether it reduces the response time when you take down fr nodes?

--
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To post to this group, send email to mongod...@googlegroups.com.
To unsubscribe from this group, send email to mongodb-user...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/mongodb-user?hl=en.

[Scott Hernandez]

If you do the same query from the mongo javascript shell from the host
the java code is running to the remote data center how long does the
query take?

Also, tagging is not yet supported in the driver for ReadPreferences.
Can you post your java code, esp. the part where you create the Mongo
instance and ReadPreference for the query?

Also, can you describe which machine the java code is running on and
when you simulate the network error which hosts you are querying?
Including their geographical location and latency would help as well.

[Emanuele Bragagnolo]

On 9 Feb, 14:09, Scott Hernandez <scotthernan...@gmail.com> wrote:
> If you do the same query from the mongo javascript shell from the host
> the java code is running to the remote data center how long does the
> query take?

I don't know how to measure it. It looks to return immediatly. Surely
not seconds.

>
> Also, tagging is not yet supported in the driver for ReadPreferences.
> Can you post your java code, esp. the part where you create the Mongo
> instance and ReadPreference for the query?

Well, I've discovered this problem while I was testing new driver for
tagging feature. Actually we have 2.6.5 in production. This is the
scala code


val host1 = "fr01-baldb01:27017" // parigi
val host2 = "de01-baldb01:27017" // francoforte

val addresses = new ArrayList[String]()
addresses.add(host1)
addresses.add(host2)

val mongo1 = new Mongo(addresses.map(new ServerAddress(_)))//

mongo1.setReadPreference( new ReadPreference.TaggedReadPreference
(Map("dc" -> tag))).


'tag' is argument of the script


When I use 2.6.5 driver I replace last line with SlaveOK option.

>
> Also, can you describe which machine the java code is running on and
> when you simulate the network error which hosts you are querying?
> Including their geographical location and latency would help as well.
> On Thu, Feb 9, 2012 at 3:49 AM, Emanuele Bragagnolo

This is the conf for replica set

config = {_id: 'testmultisite', members: [
{_id: 0, host: 'fr01-baldb01:27017', tags :
{"dc": "fr"}},
{_id: 1, host: 'de01-baldb01:27017', tags :
{"dc": "de"}},
{_id: 2, host: 'fr01-baldb01:27019', tags :
{"dc": "fr"}}]
}

Fr: node in Paris, France
De: node in Frankfurt, Germany

Ping time 13 ms.

Hosts are connected with vpn.

Script run in a host in Paris.

When master is up:

Mongo Response time from Paris: 0-1 ms
Mongo Response time from Frankfurt: 14 ms

When master is down:

Mongo Response time from Paris: 1 - 6 sec
Mongo Response time from Frankfurt: 1 - 6 sec



About java driver tag feature suppport:

I am a little bit confused about it: Java Driver API and release notes
indicates tag feature is supported, but in https://jira.mongodb.org/browse
I've found several open issues about tag feature.

Do you mean that actually java driver tag feature has some bugs? If
yes, do you know if 2.7.4 release will fix them?


However this is what I've seen running the test :


The result I've got with 3 nodes up seems to indicate that java driver
tagging function works quite well:

The test consist in reading 20 value in sequence and output response
time. I run it several times getting always similar results.

with tag="fr" I always got a 0 ms response time
with tag="de" 85% I got 15ms response time, 15% 0 ms

I don't konw how to interpret the second result. But the first clearly
indicates the query are routed to the closest slave.


This is how I measure time in scala

val then = System.currentTimeMillis
var resp = collection1.findOne(new BasicDBObject(newKey, newValue))
val now = System.currentTimeMillis
println("Got updated object: " + resp.toString + " after: " + (now -
then) + " ms")

[Emanuele Bragagnolo]

@Nat

Which value do you suggest for connect time out?



On 9 Feb, 15:34, Emanuele Bragagnolo <emanuele.bragagn...@gmail.com>
wrote:

> indicates tag feature is supported, but inhttps://jira.mongodb.org/browse

[Eliot Horowitz]

Its probably safe to keep it ~ 1 sec.

[Emanuele Bragagnolo]

I've discovered another similar problem with find operation:

consider this code:

*****************************************************************************************************
val tempCursor = ContentStore.store.collection.find(q,
fields).addOption(Bytes.QUERYOPTION_SLAVEOK)

tempCursor.sort(orderby.asInstanceOf[BasicDBObject].append("_id", 1))
val totalResults = tempCursor.count

while (resCursor.hasNext) {
res.add({
val contentResult = new MContentResult
val obj = resCursor.next
val cnt =
ContentStore.store.jacksonMapper.readValue(serialize(obj),
classOf[MContent])
contentResult.setContent(cnt)
contentResult
})


******************************************************************************************************************

where ContentStore.store.collection is a DBColletion. This code
raises an exception when master is not available:

com.mongodb.MongoException: can't find a master
at com.mongodb.DBTCPConnector.checkMaster(DBTCPConnector.java:406)
~[mongo-java-driver-2.6.5.jar:na]
at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:227) ~[mongo-
java-driver-2.6.5.jar:na]
at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
~[mongo-java-driver-2.6.5.jar:na]
at com.mongodb.DB.command(DB.java:159) ~[mongo-java-
driver-2.6.5.jar:na]
at com.mongodb.DBCollection.getCount(DBCollection.java:769) ~[mongo-
java-driver-2.6.5.jar:na]
at com.mongodb.DBCollection.getCount(DBCollection.java:740) ~[mongo-
java-driver-2.6.5.jar:na]
at com.mongodb.DBCursor.count(DBCursor.java:621) ~[mongo-java-
driver-2.6.5.jar:na]
at
it.newvision.nvp.xcontents.dal.mongo.SContentOpsMongo.findByCriteria(SContentOpsMongo.scala:
573) ~[xcontents-core-entities-3.5.5-4me.jar:na]



If I remove the following line no problems detected:

tempCursor.sort(orderby.asInstanceOf[BasicDBObject].append("_id", 1))
val totalResults = tempCursor.count


But I need them. The only workaround I've found is to set SlaveOK to
collection, not to single query:

ContentStore.store.collection.addOption(Bytes.QUERYOPTION_SLAVEOK)


Should I open a bug at https://jira.mongodb.org?

On 12 Feb, 07:28, Eliot Horowitz <el...@10gen.com> wrote:
> Its probably safe to keep it ~ 1 sec.
>
> On Thu, Feb 9, 2012 at 9:53 AM,Emanuele Bragagnolo
>
>
>
>
>
>
>
> <emanuele.bragagn...@gmail.com> wrote:
> > @Nat
>
> > Which value do you suggest for connect time out?
>

> > On 9 Feb, 15:34,Emanuele Bragagnolo<emanuele.bragagn...@gmail.com>

> >> > On Thu, Feb 9, 2012 at 3:49 AM,Emanuele Bragagnolo

[Scott Hernandez]

Can you run this again with the 2.7.3 driver please?

[Emanuele Bragagnolo]

Sure: got similar exception exception:

com.mongodb.MongoException: can't find a master

at com.mongodb.DBTCPConnector.checkMaster(DBTCPConnector.java:434)
~[mongo-java-driver-2.7.3.jar:na]
at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:209) ~[mongo-
java-driver-2.7.3.jar:na]
at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:305)
~[mongo-java-driver-2.7.3.jar:na]
at com.mongodb.DB.command(DB.java:160) ~[mongo-java-
driver-2.7.3.jar:na]
at com.mongodb.DB.command(DB.java:183) ~[mongo-java-
driver-2.7.3.jar:na]
at com.mongodb.DBCollection.getCount(DBCollection.java:864) ~[mongo-
java-driver-2.7.3.jar:na]
at com.mongodb.DBCollection.getCount(DBCollection.java:835) ~[mongo-
java-driver-2.7.3.jar:na]
at com.mongodb.DBCursor.count(DBCursor.java:635) ~[mongo-java-
driver-2.7.3.jar:na]
at
it.newvision.nvp.xcontents.dal.mongo.SContentOpsMongo.findByCriteria(SContentOpsMongo.scala:
673) ~[xcontents-core-entities-3.5.6-rc6.jar:na]

> > Should I open a bug athttps://jira.mongodb.org?

[Emanuele Bragagnolo]

Another clue:

If I set
storeSlave.collection.setReadPreference(ReadPreference.SECONDARY)
I always get a com.mongodb.MongoException: can't find a master.

Instead with
ContentStore.store.collection.addOption(Bytes.QUERYOPTION_SLAVEOK)
or ContentStore.store.collection.slaveOk the query works, but takes a
long time
to return.

Is there any difference between .addOption(Bytes.QUERYOPTION_SLAVEOK)
and SlaveOk?


Again: should i open a bug report at https://jira.mongodb.org?

Can someone confirm this behaviour?


On 27 Feb, 16:51, Emanuele Bragagnolo <emanuele.bragagn...@gmail.com>
wrote:

> Sure: got similar exception exception:
>
> com.mongodb.MongoException: can't find a master
>         at com.mongodb.DBTCPConnector.checkMaster(DBTCPConnector.java:434)
> ~[mongo-java-driver-2.7.3.jar:na]
>         at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:209) ~[mongo-
> java-driver-2.7.3.jar:na]
>         at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:305)
> ~[mongo-java-driver-2.7.3.jar:na]
>         at com.mongodb.DB.command(DB.java:160) ~[mongo-java-
> driver-2.7.3.jar:na]
>         at com.mongodb.DB.command(DB.java:183) ~[mongo-java-
> driver-2.7.3.jar:na]
>         at com.mongodb.DBCollection.getCount(DBCollection.java:864) ~[mongo-
> java-driver-2.7.3.jar:na]
>         at com.mongodb.DBCollection.getCount(DBCollection.java:835) ~[mongo-
> java-driver-2.7.3.jar:na]
>         at com.mongodb.DBCursor.count(DBCursor.java:635) ~[mongo-java-
> driver-2.7.3.jar:na]
>         at
> it.newvision.nvp.xcontents.dal.mongo.SContentOpsMongo.findByCriteria(SContentOpsMongo.scala:
> 673) ~[xcontents-core-entities-3.5.6-rc6.jar:na]
>
> On 27 Feb, 15:08, Scott Hernandez <scotthernan...@gmail.com> wrote:
>
>
>
>
>
>
>
> > Can you run this again with the 2.7.3 driver please?
>

> > On Mon, Feb 27, 2012 at 8:36 AM,Emanuele Bragagnolo

> > >> > For more options, visit this group...
>
> leggi tutto

[Victor Voytovych]

Any updates on this issue?
I'm experiencing the same problem...

[Scott Hernandez]

The .addOption and .slaveOk settings are the same.

What version of the driver are you using Victor? Best to create a new
thread for this.

On Thu, Apr 5, 2012 at 11:12 AM, Victor Voytovych <vvoyt...@llnw.com> wrote:
> Any updates on this issue?
> I'm experiencing the same problem...
>
>