Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-12595

findandmodify not honoring maxTimeMS

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 2.6.0-rc0
    • Affects Version/s: 2.5.5
    • Component/s: Concurrency
    • None
    • Environment:
    • Fully Compatible
    • Linux
    • Hide

      See description.

      Show
      See description.

      The findandmodify command the group commands are not honoring the maxTimeMS option.

      Here is an example using the findandmodify command:

      $ ./mongo
      MongoDB shell version: 2.5.5
      connecting to: test
      Server has startup warnings: 
      2014-02-03T19:24:05.729-0500 [initandlisten] 
      2014-02-03T19:24:05.729-0500 [initandlisten] ** NOTE: This is a development version (2.5.5) of MongoDB.
      2014-02-03T19:24:05.729-0500 [initandlisten] **       Not recommended for production.
      2014-02-03T19:24:05.729-0500 [initandlisten] 
      > for (var i = 1; i <= 1000000; i++) db.testData.insert( { x : i } )
      SingleWriteResult({
      	"writeErrors" : [ ],
      	"writeConcernErrors" : [ ],
      	"nInserted" : 1,
      	"nUpserted" : 0,
      	"nUpdated" : 0,
      	"nModified" : 0,
      	"nRemoved" : 0,
      	"upserted" : [ ]
      })
      > db.testData.stats()
      {
      	"ns" : "test.testData",
      	"count" : 1000000,
      	"size" : 48000144,
      	"avgObjSize" : 48,
      	"storageSize" : 86310912,
      	"numExtents" : 10,
      	"nindexes" : 1,
      	"lastExtentSize" : 27869184,
      	"paddingFactor" : 1,
      	"systemFlags" : 1,
      	"userFlags" : 1,
      	"totalIndexSize" : 32458720,
      	"indexSizes" : {
      		"_id_" : 32458720
      	},
      	"ok" : 1
      }
      > db.runCommand( { "findandmodify" : "testData", "query" : { "z" : 1 }, "update" : { "$inc" : { "x" : 1 } }, "maxTimeMS" : 1 } )
      { "value" : null, "ok" : 1 }
      > db.runCommand( { "findandmodify" : "testData", "query" : { "z" : 1 }, "update" : { "$inc" : { "x" : 1 } }, "maxTimeMS" : 10 } )
      { "value" : null, "ok" : 1 }
      > db.runCommand( { "findandmodify" : "testData", "query" : { "z" : 1 }, "update" : { "$inc" : { "x" : 1 } }, "maxTimeMS" : 100 } )
      { "value" : null, "ok" : 1 }
      

      In the server logs I see:

      2014-02-03T19:53:34.262-0500 [conn1] command test.$cmd command: { findandmodify: "testData", query: { z: 1.0 }, update: { $inc: { x: 1.0 } }, maxTimeMS: 1.0 } keyUpdates:0 numYields:0 locks(micros) w:219550 reslen:44 219ms
      2014-02-03T19:53:38.555-0500 [conn1] command test.$cmd command: { findandmodify: "testData", query: { z: 1.0 }, update: { $inc: { x: 1.0 } }, maxTimeMS: 10.0 } keyUpdates:0 numYields:0 locks(micros) w:195078 reslen:44 195ms
      2014-02-03T19:53:43.077-0500 [conn1] command test.$cmd command: { findandmodify: "testData", query: { z: 1.0 }, update: { $inc: { x: 1.0 } }, maxTimeMS: 100.0 } keyUpdates:0 numYields:0 locks(micros) w:213143 reslen:44 213ms
      

      Similar for the group command:

      > db.runCommand( { group: { key: "z", $reduce: function ( curr, result ) { }, initial: {}, maxTimeMS: 100.0, ns: "testData" } } )
      { "retval" : [ { } ], "count" : 1000000, "keys" : 1, "ok" : 1 }
      

      and in the log:

      2014-02-03T20:03:21.412-0500 [conn1] command test.$cmd command: { group: { key: "z", $reduce: function ( curr, result ) { }, initial: {}, maxTimeMS: 100.0, ns: "testData" } } keyUpdates:0 numYields:0 locks(micros) r:6083207 reslen:83 6083ms
      

      Note: I am only manually creating the commands so I can inspect the full results.

            Assignee:
            milkie@mongodb.com Eric Milkie
            Reporter:
            robert.j.moore@allanbank.com Robert Moore
            Votes:
            0 Vote for this issue
            Watchers:
            9 Start watching this issue

              Created:
              Updated:
              Resolved: