[SERVER-4680] Inconsistent query results on large data and result sets Created: 14/Jan/12  Updated: 04/Feb/15  Resolved: 07/Aug/12

Status: Closed
Project: Core Server
Component/s: Sharding
Affects Version/s: 2.0.1, 2.0.2
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Kay Agahd Assignee: Randolph Tan
Resolution: Cannot Reproduce Votes: 0
Labels: query
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu lucid (10.4) 64 Bit


Issue Links:
Depends
Operating System: ALL
Participants:

 Description   

Iterating through a large record set stops before all documents were fetched, even when a small batchSize is used and the returned documents are tiny.
Using the no-timeout query option solves the problem but may not be an option for all users.
See also: http://groups.google.com/group/mongodb-user/browse_thread/thread/6b5f8bb97510707b



 Comments   
Comment by Kay Agahd [ 08/Aug/12 ]

I tested again on mongodb-linux-x86_64-2.2.0-rc0. Both test cases above passed this time, so we will update our production servers as soon as v2.2.0 is released.
You may close this issue. We'll reopen it when we encounter the same problem with v2.2.0 in production.

Comment by Kay Agahd [ 23/May/12 ]

Yes, I can reproduce it as well in v2.1.1
I exported a set of documents to reproduce it in a sandbox. As the documents are confidental, I'll attach them to the private JIRA SUPPORT-202. Please have a look there.

Comment by Greg Studer [ 22/May/12 ]

Hmm - does this also occur in 2.1 for you? Also, if you turn your logLevel up to 2, are there any version errors reported in mongod? The test case is easy to try on my system too, but just to verify.

Comment by Kay Agahd [ 22/May/12 ]

Have a look at this. Without sleep, it returns all documents. When sleeping only 2 ms per doc, it stops already after 261000 docs even though batch size is very small (500).
mongos> var cursor = db.offer.find(

{shopId: 5040}

,{_id:1}).batchSize(500);
mongos> var count=0;while(cursor.hasNext())

{obj=cursor.next(); sleep(2); count++;}

261000
mongos> db.offer.count(

{shopId:5040}

)
398160
mongos>

Comment by Kay Agahd [ 22/May/12 ]

This bug still persists in v2.0.5.
The test case I've sent you works but I can reproduce it with another test case. I'll try to isolate it so you can play with it.

Comment by auto [ 20/Apr/12 ]

Author:

{u'login': u'gregstuder', u'name': u'Greg Studer', u'email': u'greg@10gen.com'}

Message: SERVER-4680 sendNextBatch logic isn't correct with nonzero batch size (corrected backport)
Branch: v2.0
https://github.com/mongodb/mongo/commit/36ae8786453dff62875d600490db19d47e4975f7

Comment by auto [ 20/Apr/12 ]

Author:

{u'login': u'gregstuder', u'email': u'greg@10gen.com', u'name': u'Greg Studer'}

Message: Revert "SERVER-4680 sendNextBatch logic isn't correct with nonzero batch size"

This reverts commit e50b2e242875405f2b52d8757139961243b21b78.
Branch: v2.0
https://github.com/mongodb/mongo/commit/e51ea6f0893cfe62ae84ff570587b2e4df73a40b

Comment by auto [ 20/Apr/12 ]

Author:

{u'login': u'gregstuder', u'name': u'Greg Studer', u'email': u'greg@10gen.com'}

Message: SERVER-4680 sendNextBatch logic isn't correct with nonzero batch size
Branch: v2.0
https://github.com/mongodb/mongo/commit/e50b2e242875405f2b52d8757139961243b21b78

Comment by Eliot Horowitz (Inactive) [ 19/Mar/12 ]

Its marked backport: yes, which means we will try based on safety of patch.

Comment by Y. Wayne Huang [ 19/Mar/12 ]

+1 for 2.0 backport

Comment by Benedikt Waldvogel [ 19/Mar/12 ]

Greg’s patch also fixes SERVER-1285. Will the patch be backported to the 2.0 branch?

Comment by Kay Agahd [ 26/Jan/12 ]

Ok, thank you Antoine, I understand.

> Are you still seeing any issue on your side related to timeout?

Yes, I can reproduce it at any time with the test case I've sent you (https://jira.mongodb.org/browse/SUPPORT-202).
I wanted to test Greg's bug fix but it seems that's committed only to the 2.1 branch for which no binaries are available. When I checkout the master, scons fails to build mongod and mongos. However, building tag r2.0.2-rc2 works fine but it does not yet contain Greg's bug fix. I don't see any r2.1 tags in the repo.
See also: http://groups.google.com/group/mongodb-user/browse_thread/thread/4c549af76032475c/df8f2bab928c827a?q=#df8f2bab928c827a
So, how can I test Greg's bug fix?
Thanks!

Comment by Antoine Girbal [ 25/Jan/12 ]

sorry my previous comment only applied to the default behavior:

  • if no batchsize specified, server does 100 docs (or 1MB) for 1st batch, then 4MB for further ones
  • if batchsize is specified, server respects it

Are you still seeing any issue on your side related to timeout?

Comment by Kay Agahd [ 25/Jan/12 ]

> client must consume 4MB within 10min, that is by design.

When this is "by design" then batchSize is misleading, because you couldn't simply decrement batchSize to avoid connection timeouts.
Hence, mongos should ping the shards with every batch request or at least ping them once per 10 minutes if there was a batch request in the meantime. This would avoid connection timeouts by keeping batchSize and the 4MB design consistent.

Comment by Antoine Girbal [ 25/Jan/12 ]

client must consume 4MB within 10min, that is by design.

Comment by Antoine Girbal [ 25/Jan/12 ]

From testing it seems that mongos grabs about 4MB of doc from shard.
In my case (1.9KB doc) it represents 2300 docs.
If fetching 2300 docs takes more than 10min (meaning 260ms per doc) then cursor will be timed out on next batch.

Problem of this approach is that for smaller docs the timeout will be lower.
If doc is 200 bytes then cursor will time out if client takes more than 26ms per doc.
Could be a problem in certain application that apply processing to each doc.

Comment by Antoine Girbal [ 24/Jan/12 ]

It seems there is still an issue related to timeout.

mongos> db.hugecol.stats()
{
	"sharded" : false,
	"primary" : "shard0000",
	"ns" : "test.hugecol",
	"count" : 3000001,
	"size" : 5724003156,
	"avgObjSize" : 1908.0004159998614,
	"storageSize" : 7147814144,
	"numExtents" : 22,
	"nindexes" : 1,
	"lastExtentSize" : 1861541888,
	"paddingFactor" : 1,
	"flags" : 1,
	"totalIndexSize" : 97352144,
	"indexSizes" : {
		"_id_" : 97352144
	},
	"ok" : 1
}
mongos> var cur = db.hugecol.find()
mongos> var i = 0; while (cur.hasNext()) { var doc = cur.next(); if (++i %100 == 0) print(i); sleep(500); }
100
200
300
400
500
600
700
800
900
1000
1100
1200
1300
1400
1500
1600
1700
1800
1900
2000
2100
2200
2300
Tue Jan 24 11:25:04 exec error: src/mongo/shell/query.js:113 getMore: cursor didn't exist on server, possible restart or timeout?
var o = this._cursor.hasNext();

the test is pulling about 100 docs per minute.
It seems that mongos is caching much more than 100 and maybe it does not go back to mongod for more than 10min?
Maybe you want to create a new ticket for this since you already fixed a different bug, though the original problem was about timeout.

Comment by Greg Studer [ 20/Jan/12 ]

Feel free to reopen if you continue to see the problem.

Comment by Greg Studer [ 18/Jan/12 ]

Believe this should fix the issue - our batch logic with sharded cursors hadn't been touched in a long time.

Comment by auto [ 18/Jan/12 ]

Author:

{u'login': u'gregstuder', u'name': u'Greg Studer', u'email': u'greg@10gen.com'}

Message: SERVER-4680 sendNextBatch logic isn't correct with nonzero batch size
Branch: master
https://github.com/mongodb/mongo/commit/baa097c07b244a69a8d409059eca4ce42810266e

Comment by Kay Agahd [ 17/Jan/12 ]

I created a private JIRA having attached a dumped collection, so you can easily reproduce and hopefully track down the issue:
https://jira.mongodb.org/browse/SUPPORT-202

Generated at Thu Feb 08 03:06:41 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.