[SERVER-12554] Count queries negatively impact concurrency Created: 30/Jan/14  Updated: 11/Jul/16  Resolved: 18/Feb/14

Status: Closed
Project: Core Server
Component/s: Concurrency, Querying
Affects Version/s: 2.5.5
Fix Version/s: 2.6.0-rc0

Type: Bug Priority: Major - P3
Reporter: Davide Italiano Assignee: Davide Italiano
Resolution: Done Votes: 0
Labels: 26qa
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Linux ip-10-232-37-146.ec2.internal 2.6.32-358.14.1.el6.x86_64 #1 SMP Mon Jun 17 15:54:20 EDT 2013 x86_64 x86_64 x86_64 GNU/Linux


Issue Links:
Related
related to SERVER-13336 Count with no results, never yields Closed
Operating System: ALL
Participants:

 Description   

My query concurrency tests showed up a clear regression when different kind of queries are executed concurrently.
I relied on git bisect to find out where the problem was, starting from

Good revision: 06851f4859a61019a17147ea96c4e6d9462f354b
Bad revision: f2ece186b189b2b9d09636c708f768fb3822b511

The commit that caused the regression is:

# git bisect good 2bee3f018b8d4351f8261c405adcdff44c7f9a70
3b3c25e571852893373ae2e2b361397b260687c9 is the first bad commit
commit 3b3c25e571852893373ae2e2b361397b260687c9
Author: Hari Khalsa <hkhalsa@10gen.com>
Date:   Mon Jan 27 18:01:26 2014 -0500
 
    SERVER-12460 faster count for simple queries

I more carefully looked at the server logs and realized there's something unusual:

2014-01-30T14:48:52.824-0500 [conn133] command test1.$cmd command: { count: "QA408", query: { timestamp: { $gte: new Date(1388927893439), $lte: new Date(1388999113439) } }, limit: 1 } keyUpdates:0 numYields:22 locks(micros) r:5722 reslen:48 111ms
2014-01-30T14:48:52.835-0500 [conn129] command test1.$cmd command: { count: "QA408", query: { timestamp: { $gte: new Date(1389166093427), $lte: new Date(1389327733427) } }, limit: 1 } keyUpdates:0 numYields:50 locks(micros) r:6720 reslen:48 129ms
2014-01-30T14:48:52.847-0500 [conn119] command test1.$cmd command: { count: "QA408", query: { timestamp: { $gte: new Date(1390298233437), $lte: new Date(1390424353437) } }, limit: 1 } keyUpdates:0 numYields:40 locks(micros) r:6359 reslen:48 136ms

Lots of yields – apparently this didn't happen before the change.
CPU profiling via gperftools confirmsthe suspects, FWIW.

(pprof) list mongo::PlanExecutor::getNext
[...]
     .      .   79:         for (;;) {
     .      .   80:             // Yield, if we can yield ourselves.
    76    337   81:             if (NULL != _yieldPolicy.get() && _yieldPolicy->shouldYield()) {
     .    166   82:                 saveState();
    23   4884   83:                 _yieldPolicy->yield();
     4      8   84:                 if (_killed) { return Runner::RUNNER_DEAD; }
     .    765   85:                 restoreState();
     .      .   86:             }
[...]



 Comments   
Comment by Githook User [ 25/Mar/14 ]

Author:

{u'username': u'hkhalsa', u'name': u'Hari Khalsa', u'email': u'hkhalsa@10gen.com'}

Message: SERVER-13336 count should always yield

Revert "SERVER-12554 Lazily yield on count queries."

This reverts commit 2850cc7253344c639bc9a01bc6dff3ffd2cca422.
Branch: v2.6
https://github.com/mongodb/mongo/commit/f77427bddf29b2f07dcd2620abffa57b1f7c2655

Comment by Githook User [ 25/Mar/14 ]

Author:

{u'username': u'hkhalsa', u'name': u'Hari Khalsa', u'email': u'hkhalsa@10gen.com'}

Message: SERVER-13336 count should always yield

Revert "SERVER-12554 Lazily yield on count queries."

This reverts commit 2850cc7253344c639bc9a01bc6dff3ffd2cca422.
Branch: master
https://github.com/mongodb/mongo/commit/1f762a3478bb2f794e72670d333f35c6b7e6cfa7

Comment by Githook User [ 18/Feb/14 ]

Author:

{u'username': u'dcci', u'name': u'Davide Italiano', u'email': u'davide.italiano@10gen.com'}

Message: SERVER-12554 Lazily yield on count queries.

This avoids a regression when scanning a small set of documents.
Branch: master
https://github.com/mongodb/mongo/commit/2850cc7253344c639bc9a01bc6dff3ffd2cca422

Comment by Githook User [ 12/Feb/14 ]

Author:

{u'username': u'IanWhalen', u'name': u'Ian Whalen', u'email': u'ian@mongodb.com'}

Message: Revert "SERVER-12554 Mimic 2.4 behaviour and lazily yield in order to"

This reverts commit d6873ccb663a07de47738af913fd25ceff23296f.

Reverting because commit broke counttests.cpp in core suite on all platforms
Branch: master
https://github.com/mongodb/mongo/commit/4de0fdb367ee24a1551989815ac8bff58d064118

Comment by Githook User [ 11/Feb/14 ]

Author:

{u'username': u'dcci', u'name': u'Davide Italiano', u'email': u'davide.italiano@10gen.com'}

Message: SERVER-12554 Mimic 2.4 behaviour and lazily yield in order to
avoid a regression whne scanning a small set of documents.
Branch: master
https://github.com/mongodb/mongo/commit/d6873ccb663a07de47738af913fd25ceff23296f

Comment by Githook User [ 11/Feb/14 ]

Author:

{u'username': u'dcci', u'name': u'Davide Italiano', u'email': u'davide.italiano@10gen.com'}

Message: SERVER-12554 There's no need to iterate all over the runner if limit
is set, because this is really expensive (the scan it done under
lock scope).
Branch: master
https://github.com/mongodb/mongo/commit/d8332443b6737565e32dc8d28317ed245173fa46

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