8

This is repeated over and over again in my MongoDB logs. Some notes:

  • MongoDB 1.8.1 on Ubuntu 11.04
  • Primary in a replica set
  • 64gb disk
  • 5gb RAM
  • new Date(5610408224193773570) is always the same
  • verbose = true is commented out in the config file

Could it be that my oplog is too large, so every time a secondary queries it it takes 4 seconds?

Wed May 25 00:35:58 [dur] lsn set 1552362
Wed May 25 00:36:02 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:06 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:11 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3884ms
Wed May 25 00:36:15 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:19 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:23 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:27 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:31 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:35 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:39 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:43 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:47 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:51 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:55 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:36:58 [dur] lsn set 1582372
Wed May 25 00:36:59 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:02 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:817 nreturned:1 3229ms
Wed May 25 00:37:06 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3685ms
Wed May 25 00:37:10 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:14 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:18 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:22 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:26 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:30 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:34 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:38 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:42 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:46 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:50 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:54 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:58 [conn14] getmore local.oplog.rs cid:265112601668423723 getMore: { ts: { $gte: new Date(5610408224193773570) } }  bytes:20 nreturned:0 3979ms
Wed May 25 00:37:58 [dur] lsn set 1612372
Seamus Abshere
  • 8,326
  • 4
  • 44
  • 61
  • Kristina Chodorow writes: "...The time doesn't refresh because the cursor hasn't died. The cursor will probably die once your oplog is full and starts overwriting old entries..." – Seamus Abshere May 26 '11 at 15:59

1 Answers1

3

Given that the date is the same, it looks like a secondary is querying for new oplog entries and simply not getting anything. Are you writing any data to the primary?

The behavior looks a little unusual. However, I'm getting the same thing simply by starting a replica set and not writing to it. The behavior you're seeing is expected.

Gates VP
  • 44,957
  • 11
  • 105
  • 108
  • 1
    Kristina Chodorow confirmed that you're correct on https://jira.mongodb.org/browse/SERVER-3148: "No, you can't speed them up, sorry." – Seamus Abshere May 26 '11 at 18:55