Why do my MongoDB logs fill up with "getmore local.oplog.rs"?

Question

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

Answer 1

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.