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

serverStatus metrics.cursor.timedOut field stays at 0 even after cursors have timed out

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Unresolved
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 7.0.3
    • Component/s: None
    • Query Execution
    • ALL
    • Hide

      The application looks roughly like this:

       

      var coll = client.getDatabase("test").getCollection("test");
coll.drop();
coll.insertMany(List.of(new Document(), new Document(), new Document()));
for (int i = 0; i < 6; i++)
{
    // set batch size to 2 to ensure that cursor is not immediately exhausted by
    // the first  batch.
    // establish the cursor but abandon it before exhausting or closing
    var cursor = coll.find().batchSize(2).cursor();
}

       

      Show
      The application looks roughly like this:   var coll = client.getDatabase( "test" ).getCollection( "test" ); coll.drop(); coll.insertMany(List.of( new Document(), new Document(), new Document())); for ( int i = 0; i < 6; i++) { // set batch size to 2 to ensure that cursor is not immediately exhausted by // the first batch. // establish the cursor but abandon it before exhausting or closing var cursor = coll.find().batchSize(2).cursor(); }  

      The serverStatus metrics.cursor.timedOut field stays at 0 even after cursors have timed out.

      I created a simple Java program that established a bunch of cursors, and then abandoned them before exhausting them. I see the cursors tracked on the server:

      Enterprise [direct: mongos] test> db.serverStatus().metrics.cursor
{
  timedOut: Long('0'),
  open: {
    multiTarget: Long('0'),
    singleTarget: Long('24'),
    pinned: Long('0'),
    total: Long('24')
  }
}

      After waiting 30 minutes, I tried again.

      Enterprise [direct: mongos] test> db.serverStatus().metrics.cursor
{
  timedOut: Long('0'),
  open: {
    multiTarget: Long('0'),
    singleTarget: Long('0'),
    pinned: Long('0'),
    total: Long('0')
  }
}

      As expected, metrics.cursor.open.total dropped from 24 to 0.
      But unexpectedly, metrics.cursor.timedOut remained at 0 instead of bumping to 24.

      I also looked on the primary of the single shard in the cluster:

      Enterprise shard01 [direct: primary] test> db.serverStatus().metrics.cursor
{
  moreThanOneBatch: Long('183'),
  timedOut: Long('0'),
  totalOpened: Long('180562'),
  lifespan: {
    greaterThanOrEqual10Minutes: Long('24'),
    lessThan10Minutes: Long('0'),
    lessThan15Seconds: Long('2'),
    lessThan1Minute: Long('0'),
    lessThan1Second: Long('180381'),
    lessThan30Seconds: Long('0'),
    lessThan5Seconds: Long('153')
  },
  open: { noTimeout: Long('0'), pinned: Long('2'), total: Long('2') }
}

      The value is also 0 there.

      This is unexpected based on the documentation: https://www.mongodb.com/docs/v3.0/reference/command/serverStatus/#serverStatus.cursors.timedOut

      timedOut provides a counter of the total number of cursors that have timed out since the server process started. If this number is large or growing at a regular rate, this may indicate an application error.

            Assignee:
            Unassigned Unassigned
            Reporter:
            jeff.yemin@mongodb.com Jeffrey Yemin
            Votes:
            0 Vote for this issue
            Watchers:
            13 Start watching this issue

              Created:
              Updated: