[SERVER-27090] sharding/cursor_timeout.js sets cursorTimeoutMillis incorrectly Created: 17/Nov/16  Updated: 28/Dec/16  Resolved: 22/Nov/16

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 3.4.0-rc5, 3.5.1

Type: Bug Priority: Major - P3
Reporter: James Wahlin Assignee: James Wahlin
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Depends
Related
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Completed:
Steps To Reproduce:

Run the jstests/sharding/cursor_timeout.js test with --repeat. I was able to reproduce in under 200 iterations on my Mac.

Sprint: Query 2016-12-12
Participants:
Linked BF Score: 0

 Description   

The sharding/cursor_timeout.js test sets cursorTimeoutMillis to the same time interval as clientCursorMonitorFrequencySecs. This results in immediate timeout (when the clientcursormon thread wakes up from a clientCursorMonitorFrequencySecs sleep), as the elapsed time interval passed to the timeout check is based on a clientcursormon-level timer and will never be less than clientCursorMonitorFrequencySecs.

In light of the above, the sequence of events that causes this test failure is:

  1. A find() is run that returns a subset of the result set and leaves an open cursor.
  2. Just after (on the order of <1ms) the clientcursormon thread wakes up from a 1 second sleep and attempts to kill expired cursors.
  3. The clientcursormon passes to the kill method its timer value as the elapsed time. In my testing this would be ballpark 1004ms.
  4. The open cursor is killed after only being open for a few milliseconds.

A quick fix for the test would be to increase cursorTimeoutMillis to 2000. This will give us what I expect was the desired behavior which is kill after 1 second has passed (and will translate to kill between 1 and 2 seconds).

We may also want to consider failing startup when 0 < cursorTimeoutMillis <= (clientCursorMonitorFrequencySecs * 1000) as the test (or at a minimum perform an audit to make sure there are no other tests that setup cursorTimeoutMillis in this manner).



 Comments   
Comment by Githook User [ 22/Nov/16 ]

Author:

{u'username': u'jameswahlin', u'name': u'James Wahlin', u'email': u'james.wahlin@10gen.com'}

Message: SERVER-27090 cursor_timeout.js sets cursorTimeoutMillis incorrectly

(cherry picked from commit 4d301a60b68fcc7cfad8499a0fe60c758da45f3e)
Branch: v3.4
https://github.com/mongodb/mongo/commit/18ff331c446023d25cb349e757f063bdd83c9cf9

Comment by Githook User [ 22/Nov/16 ]

Author:

{u'username': u'jameswahlin', u'name': u'James Wahlin', u'email': u'james.wahlin@10gen.com'}

Message: SERVER-27090 cursor_timeout.js sets cursorTimeoutMillis incorrectly
Branch: master
https://github.com/mongodb/mongo/commit/4d301a60b68fcc7cfad8499a0fe60c758da45f3e

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