Secondary nodes in recovering state and won't re-sync
1,160 views
Skip to first unread message
Pierre ARLAUD
Sep 21, 2016, 9:12:50 AM9/21/16
to mongodb-user
Hello everyone,
Yesterday I made a database duplication on the primary node of a mongo replica set with three data members. Due to a config error, this primary node likely reached its maximum storage limit so I dropped the database duplicate.
Since then, the other two secondary nodes in the set have been in RECOVERING state and seem not to make any progress whatsoever.
Because of that I tried removing the data on one of these nodes to do a full re-sync of that secondary node. The mongodb service runs as "STARTUP2" for a little while until it just stops with no apparent relevant logs (there is enough space in this node to run a full resync).
What strategy should we now go for? For the time being our replica set is unhealthy und runs similarly to a single mongo database as both secondary nodes are in recovering state.
Here's my replica set status:
Thanks in advance
Yesterday I made a database duplication on the primary node of a mongo replica set with three data members. Due to a config error, this primary node likely reached its maximum storage limit so I dropped the database duplicate.
Since then, the other two secondary nodes in the set have been in RECOVERING state and seem not to make any progress whatsoever.
Because of that I tried removing the data on one of these nodes to do a full re-sync of that secondary node. The mongodb service runs as "STARTUP2" for a little while until it just stops with no apparent relevant logs (there is enough space in this node to run a full resync).
What strategy should we now go for? For the time being our replica set is unhealthy und runs similarly to a single mongo database as both secondary nodes are in recovering state.
Here's my replica set status:
{
"set" : "actiSet",
"date" : ISODate("2016-09-21T14:41:36.974Z"),
"myState" : 1,
"term" : NumberLong(2771),
"heartbeatIntervalMillis" : NumberLong(2000),
"members" : [
{
"_id" : 0,
"name" : "192.168.4.71:27017",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 1032183,
"optime" : {
"ts" : Timestamp(1474468631, 1),
"t" : NumberLong(2771)
},
"optimeDate" : ISODate("2016-09-21T14:37:11Z"),
"electionTime" : Timestamp(1474468630, 1),
"electionDate" : ISODate("2016-09-21T14:37:10Z"),
"configVersion" : 5,
"self" : true
},
{
"_id" : 1,
"name" : "192.168.4.72:27017",
"health" : 1,
"state" : 3,
"stateStr" : "RECOVERING",
"uptime" : 43,
"optime" : {
"ts" : Timestamp(1474362665, 13717),
"t" : NumberLong(2614)
},
"optimeDate" : ISODate("2016-09-20T09:11:05Z"),
"lastHeartbeat" : ISODate("2016-09-21T14:41:35.105Z"),
"lastHeartbeatRecv" : ISODate("2016-09-21T14:41:32.898Z"),
"pingMs" : NumberLong(1),
"configVersion" : 5
},
{
"_id" : 2,
"name" : "192.168.4.73:27017",
"health" : 1,
"state" : 3,
"stateStr" : "RECOVERING",
"uptime" : 277,
"optime" : {
"ts" : Timestamp(1474362665, 13720),
"t" : NumberLong(2614)
},
"optimeDate" : ISODate("2016-09-20T09:11:05Z"),
"lastHeartbeat" : ISODate("2016-09-21T14:41:34.999Z"),
"lastHeartbeatRecv" : ISODate("2016-09-21T14:41:33.406Z"),
"pingMs" : NumberLong(0),
"configVersion" : 5
}
],
"ok" : 1
}
"set" : "actiSet",
"date" : ISODate("2016-09-21T14:41:36.974Z"),
"myState" : 1,
"term" : NumberLong(2771),
"heartbeatIntervalMillis" : NumberLong(2000),
"members" : [
{
"_id" : 0,
"name" : "192.168.4.71:27017",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 1032183,
"optime" : {
"ts" : Timestamp(1474468631, 1),
"t" : NumberLong(2771)
},
"optimeDate" : ISODate("2016-09-21T14:37:11Z"),
"electionTime" : Timestamp(1474468630, 1),
"electionDate" : ISODate("2016-09-21T14:37:10Z"),
"configVersion" : 5,
"self" : true
},
{
"_id" : 1,
"name" : "192.168.4.72:27017",
"health" : 1,
"state" : 3,
"stateStr" : "RECOVERING",
"uptime" : 43,
"optime" : {
"ts" : Timestamp(1474362665, 13717),
"t" : NumberLong(2614)
},
"optimeDate" : ISODate("2016-09-20T09:11:05Z"),
"lastHeartbeat" : ISODate("2016-09-21T14:41:35.105Z"),
"lastHeartbeatRecv" : ISODate("2016-09-21T14:41:32.898Z"),
"pingMs" : NumberLong(1),
"configVersion" : 5
},
{
"_id" : 2,
"name" : "192.168.4.73:27017",
"health" : 1,
"state" : 3,
"stateStr" : "RECOVERING",
"uptime" : 277,
"optime" : {
"ts" : Timestamp(1474362665, 13720),
"t" : NumberLong(2614)
},
"optimeDate" : ISODate("2016-09-20T09:11:05Z"),
"lastHeartbeat" : ISODate("2016-09-21T14:41:34.999Z"),
"lastHeartbeatRecv" : ISODate("2016-09-21T14:41:33.406Z"),
"pingMs" : NumberLong(0),
"configVersion" : 5
}
],
"ok" : 1
}
Thanks in advance
Lukas Lehner
Sep 22, 2016, 2:43:40 AM9/22/16
to mongod...@googlegroups.com
please post mongodb.log from RECOVERING nodes. Maybe you need to do an initial sync?
--
You received this message because you are subscribed to the Google Groups "mongodb-user"
group.
For other MongoDB technical support options, see: https://docs.mongodb.com/manual/support/
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user+unsubscribe@googlegroups.com.
To post to this group, send email to mongod...@googlegroups.com.
Visit this group at https://groups.google.com/group/mongodb-user.
To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/0f25d254-abde-4c4d-944b-f9480a5b7d69%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Pierre ARLAUD
Sep 22, 2016, 3:46:01 AM9/22/16
to mongodb-user
Hi Lukas, thanks for taking the time to answer.
If by doing an "initial sync" you mean dropping the data files and starting mongod again to fully resync a secondary node, it's what I meant by "re-sync": mongod writes some *.wt (wiredtiger) files on my disc and then stops for no apparent reason ; if I restart the daemon, it does the same thing from scratch until it crashes again.
Here are the recent logs of one of the secondary recovering nodes as you asked:
2016-09-22T09:18:39.701+0000 I COMMAND [conn51750] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:39.702+0000 I ACCESS [conn51748] Successfully authenticated as principal website-user on website
2016-09-22T09:18:39.702+0000 I COMMAND [conn51748] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:39.702+0000 I ACCESS [conn51751] Successfully authenticated as principal website-user on website
2016-09-22T09:18:39.702+0000 I COMMAND [conn51751] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:39.703+0000 I NETWORK [conn51747] end connection 172.16.3.43:51205 (6 connections now open)
2016-09-22T09:18:39.704+0000 I NETWORK [conn51748] end connection 172.16.3.43:51206 (5 connections now open)
2016-09-22T09:18:39.704+0000 I NETWORK [conn51751] end connection 172.16.3.43:51209 (4 connections now open)
2016-09-22T09:18:39.704+0000 I NETWORK [conn51750] end connection 172.16.3.43:51208 (3 connections now open)
2016-09-22T09:18:39.705+0000 I NETWORK [conn51749] end connection 172.16.3.43:51207 (2 connections now open)
2016-09-22T09:18:40.913+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:42.914+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:43.609+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:44.914+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:46.300+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.83:33914 #51752 (3 connections now open)
2016-09-22T09:18:46.301+0000 I COMMAND [conn51752] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.302+0000 I COMMAND [conn51752] command second-website.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.303+0000 I ACCESS [conn51752] authenticate db: second-website { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" }
2016-09-22T09:18:46.304+0000 I COMMAND [conn51752] command admin.system.users command: authenticate { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:89 locks:{ Global: { acquireCount: { r: 4 } }, MMAPV1Journal: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { R: 2 } } } protocol:op_query 0ms
2016-09-22T09:18:46.305+0000 I COMMAND [conn51752] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.319+0000 I COMMAND [conn51752] command second-website.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 11ms
2016-09-22T09:18:46.325+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.80:50873 #51753 (4 connections now open)
2016-09-22T09:18:46.326+0000 I COMMAND [conn51753] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.339+0000 I COMMAND [conn51753] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 11ms
2016-09-22T09:18:46.392+0000 I COMMAND [conn51752] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D5265674A525138304F66706E70754450736B4149787A7A7146566C62444D6130357A594A77657241354A66744D356E766C787A7879723958584D75586B...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.406+0000 I COMMAND [conn51753] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D6E397A594942696872613252764B4E4B4344417837755568747467462B3352704B592B4E744B34452B3059334F4F4D4F71795339496978693631465355...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.463+0000 I ACCESS [conn51752] Successfully authenticated as principal second-website-user on second-website
2016-09-22T09:18:46.463+0000 I COMMAND [conn51752] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.465+0000 I NETWORK [conn51752] end connection 192.168.4.83:33914 (3 connections now open)
2016-09-22T09:18:46.474+0000 I ACCESS [conn51753] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:18:46.474+0000 I COMMAND [conn51753] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:18:46.475+0000 I COMMAND [conn51753] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.512+0000 I COMMAND [conn51753] command customer-1.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 34ms
2016-09-22T09:18:46.628+0000 I COMMAND [conn51753] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D6B59617547696A444C4679557638374A36707656726A6E6F6D3146685A4869337470627078384556456C4B612B65775575504E68363976547541697854...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.629+0000 I ACCESS [conn51753] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:18:46.629+0000 I COMMAND [conn51753] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:46.631+0000 I NETWORK [conn51753] end connection 192.168.4.80:50873 (2 connections now open)
2016-09-22T09:18:46.915+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:48.610+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:48.751+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51215 #51754 (3 connections now open)
2016-09-22T09:18:48.751+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51216 #51755 (4 connections now open)
2016-09-22T09:18:48.751+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51217 #51756 (5 connections now open)
2016-09-22T09:18:48.751+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51218 #51757 (6 connections now open)
2016-09-22T09:18:48.751+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51219 #51758 (7 connections now open)
2016-09-22T09:18:48.752+0000 I COMMAND [conn51754] command system.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:48.754+0000 I COMMAND [conn51755] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:48.805+0000 I COMMAND [conn51758] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 49ms
2016-09-22T09:18:48.810+0000 I COMMAND [conn51756] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 48ms
2016-09-22T09:18:48.814+0000 I COMMAND [conn51755] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 47ms
2016-09-22T09:18:48.817+0000 I COMMAND [conn51754] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 47ms
2016-09-22T09:18:48.817+0000 I COMMAND [conn51757] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 58ms
2016-09-22T09:18:48.916+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:49.019+0000 I COMMAND [conn51758] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D536C626D704A693372694635557A4B442F47524A53724175786A7643326A633778694B54764147646339535858465371626A783042577A4E7876486A71...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.199+0000 I COMMAND [conn51756] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D414150666343554B736959677248463243414465325163616276727855344F67426B6A30516B625672646D674B6E376543785342534F517A5347443878...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.417+0000 I COMMAND [conn51755] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D3764785350467678304B5778534C644B56364F5073383436327455436F57364E3161613530464E6E56466F2B4C4B2B512F38474175575443637A364270...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.671+0000 I COMMAND [conn51754] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D464C5654484A5255763844435478456C6331784B42792B2F554F3166773568554F53493741734E4A70626567344372524B69426D76696A7A55594D5675...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.788+0000 I COMMAND [conn51757] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D337262304E38694B32646C6D4A6273504A5561747233526E4761693744786B4C515963704B476F41657754312F52313551574D4F5564422B716B684B70...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.789+0000 I ACCESS [conn51758] Successfully authenticated as principal website-user on website
2016-09-22T09:18:49.789+0000 I COMMAND [conn51758] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:18:49.789+0000 I ACCESS [conn51756] Successfully authenticated as principal website-user on website
2016-09-22T09:18:49.789+0000 I COMMAND [conn51756] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.789+0000 I ACCESS [conn51757] Successfully authenticated as principal website-user on website
2016-09-22T09:18:49.790+0000 I COMMAND [conn51757] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.790+0000 I ACCESS [conn51755] Successfully authenticated as principal website-user on website
2016-09-22T09:18:49.790+0000 I COMMAND [conn51755] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.790+0000 I ACCESS [conn51754] Successfully authenticated as principal website-user on website
2016-09-22T09:18:49.790+0000 I COMMAND [conn51754] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:49.795+0000 I NETWORK [conn51757] end connection 172.16.3.43:51218 (6 connections now open)
2016-09-22T09:18:49.795+0000 I NETWORK [conn51756] end connection 172.16.3.43:51217 (5 connections now open)
2016-09-22T09:18:49.795+0000 I NETWORK [conn51758] end connection 172.16.3.43:51219 (4 connections now open)
2016-09-22T09:18:49.795+0000 I NETWORK [conn51755] end connection 172.16.3.43:51216 (3 connections now open)
2016-09-22T09:18:49.796+0000 I NETWORK [conn51754] end connection 172.16.3.43:51215 (2 connections now open)
2016-09-22T09:18:50.918+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:52.919+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:53.611+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:54.919+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:56.301+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.83:33916 #51759 (3 connections now open)
2016-09-22T09:18:56.302+0000 I COMMAND [conn51759] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.304+0000 I COMMAND [conn51759] command second-website.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.306+0000 I ACCESS [conn51759] authenticate db: second-website { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" }
2016-09-22T09:18:56.306+0000 I COMMAND [conn51759] command admin.system.users command: authenticate { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:89 locks:{ Global: { acquireCount: { r: 4 } }, MMAPV1Journal: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { R: 2 } } } protocol:op_query 0ms
2016-09-22T09:18:56.307+0000 I COMMAND [conn51759] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.320+0000 I COMMAND [conn51759] command second-website.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 11ms
2016-09-22T09:18:56.327+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.80:50875 #51760 (4 connections now open)
2016-09-22T09:18:56.328+0000 I COMMAND [conn51760] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.342+0000 I COMMAND [conn51760] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 12ms
2016-09-22T09:18:56.406+0000 I COMMAND [conn51759] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D347339664A314B4948666C2F6773764C5248726D753468452B6F7773574859426F4962426744376A397A35354B6276345338464A74496D595748637845...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.413+0000 I COMMAND [conn51760] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D353177686231464B6E415A79436E3236386435476630446872485774383147574530735032743145616E476C4B57735063374757537747752F69666150...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.480+0000 I ACCESS [conn51760] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:18:56.480+0000 I COMMAND [conn51760] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:18:56.481+0000 I COMMAND [conn51760] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.490+0000 I ACCESS [conn51759] Successfully authenticated as principal second-website-user on second-website
2016-09-22T09:18:56.490+0000 I COMMAND [conn51759] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.492+0000 I NETWORK [conn51759] end connection 192.168.4.83:33916 (3 connections now open)
2016-09-22T09:18:56.497+0000 I COMMAND [conn51760] command customer-1.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 13ms
2016-09-22T09:18:56.633+0000 I COMMAND [conn51760] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D634D4266637835684D716131385241694974574D79577531794E6D5959795A507130524D54506E32644F6378633755653745645A75446E30552B436272...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.635+0000 I ACCESS [conn51760] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:18:56.635+0000 I COMMAND [conn51760] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:56.636+0000 I NETWORK [conn51760] end connection 192.168.4.80:50875 (2 connections now open)
2016-09-22T09:18:56.921+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:58.612+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:58.753+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51225 #51761 (3 connections now open)
2016-09-22T09:18:58.753+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51226 #51762 (4 connections now open)
2016-09-22T09:18:58.753+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51227 #51763 (5 connections now open)
2016-09-22T09:18:58.753+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51228 #51764 (6 connections now open)
2016-09-22T09:18:58.753+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51229 #51765 (7 connections now open)
2016-09-22T09:18:58.754+0000 I COMMAND [conn51761] command system.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:58.755+0000 I COMMAND [conn51762] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:18:58.838+0000 I COMMAND [conn51765] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 77ms
2016-09-22T09:18:58.846+0000 I COMMAND [conn51764] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 83ms
2016-09-22T09:18:58.848+0000 I COMMAND [conn51763] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 84ms
2016-09-22T09:18:58.850+0000 I COMMAND [conn51762] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 83ms
2016-09-22T09:18:58.852+0000 I COMMAND [conn51761] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 79ms
2016-09-22T09:18:58.922+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:18:59.343+0000 I COMMAND [conn51765] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D4D4F446B784E527A4E712F334E4F59676E744976426B3258532F54314A467642686D46766535344846464B587A356C71497A6656746554476A726E3272...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.426+0000 I COMMAND [conn51764] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D4B5737706C306B73784B44494454426473366C5234676A644A6C436F316A596A7A537A785365755569387432624E39522F344D6378756C30305A69316B...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.527+0000 I COMMAND [conn51763] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D61674C706D68785651616C62355A59414932344C43395038564F77355A32345543387A716B455254754B64496D436F6A7455686E687965554678494338...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.644+0000 I COMMAND [conn51762] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D4356507436474C6D306152754D6B4F4353397562354F6D52595756746370447546636576534D74615079414B7477522F7164554755574D6C543568544D...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.725+0000 I COMMAND [conn51761] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D544C2B646B4133357A705836757934642B6F6A4F4D37642B4D395166744275726272425A75596B726944367862675977456C51784A7237445473683955...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.727+0000 I ACCESS [conn51765] Successfully authenticated as principal website-user on website
2016-09-22T09:18:59.727+0000 I COMMAND [conn51765] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:18:59.727+0000 I ACCESS [conn51764] Successfully authenticated as principal website-user on website
2016-09-22T09:18:59.727+0000 I COMMAND [conn51764] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.727+0000 I ACCESS [conn51763] Successfully authenticated as principal website-user on website
2016-09-22T09:18:59.727+0000 I COMMAND [conn51763] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.727+0000 I ACCESS [conn51762] Successfully authenticated as principal website-user on website
2016-09-22T09:18:59.727+0000 I COMMAND [conn51762] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.728+0000 I ACCESS [conn51761] Successfully authenticated as principal website-user on website
2016-09-22T09:18:59.728+0000 I COMMAND [conn51761] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:18:59.732+0000 I NETWORK [conn51764] end connection 172.16.3.43:51228 (6 connections now open)
2016-09-22T09:18:59.733+0000 I NETWORK [conn51763] end connection 172.16.3.43:51227 (5 connections now open)
2016-09-22T09:18:59.733+0000 I NETWORK [conn51762] end connection 172.16.3.43:51226 (4 connections now open)
2016-09-22T09:18:59.733+0000 I NETWORK [conn51761] end connection 172.16.3.43:51225 (3 connections now open)
2016-09-22T09:18:59.733+0000 I NETWORK [conn51765] end connection 172.16.3.43:51229 (2 connections now open)
2016-09-22T09:19:00.923+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:02.925+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:03.613+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:04.811+0000 I STORAGE [DataFileSync] flushing mmaps took 0ms for 34 files
2016-09-22T09:19:04.925+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:06.302+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.83:33918 #51766 (3 connections now open)
2016-09-22T09:19:06.303+0000 I COMMAND [conn51766] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.305+0000 I COMMAND [conn51766] command second-website.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.306+0000 I ACCESS [conn51766] authenticate db: second-website { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" }
2016-09-22T09:19:06.307+0000 I COMMAND [conn51766] command admin.system.users command: authenticate { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:89 locks:{ Global: { acquireCount: { r: 4 } }, MMAPV1Journal: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { R: 2 } } } protocol:op_query 0ms
2016-09-22T09:19:06.307+0000 I COMMAND [conn51766] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.321+0000 I COMMAND [conn51766] command second-website.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 11ms
2016-09-22T09:19:06.330+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.80:50877 #51767 (4 connections now open)
2016-09-22T09:19:06.331+0000 I COMMAND [conn51767] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.344+0000 I COMMAND [conn51767] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 12ms
2016-09-22T09:19:06.406+0000 I COMMAND [conn51766] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D646B44647A43614455524D39544C78772B7341546B37396752416F32624D506D667474314B63736446395A3757316362454635702F3431597267304961...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.411+0000 I COMMAND [conn51767] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D78395841506F336A353641754C6147517A617631717A77702F2F364831575169447533797862376B7A477945446D4B393872655A494150395A61727942...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.477+0000 I ACCESS [conn51767] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:19:06.477+0000 I COMMAND [conn51767] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:19:06.478+0000 I COMMAND [conn51767] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.490+0000 I ACCESS [conn51766] Successfully authenticated as principal second-website-user on second-website
2016-09-22T09:19:06.490+0000 I COMMAND [conn51766] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.492+0000 I NETWORK [conn51766] end connection 192.168.4.83:33918 (3 connections now open)
2016-09-22T09:19:06.495+0000 I COMMAND [conn51767] command customer-1.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 14ms
2016-09-22T09:19:06.631+0000 I COMMAND [conn51767] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D5050676C46685567324D776763536564517472384D7776426166357237416977627236396D31534E30794F73633968574B4D7569587432355273723574...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.632+0000 I ACCESS [conn51767] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:19:06.632+0000 I COMMAND [conn51767] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:06.633+0000 I NETWORK [conn51767] end connection 192.168.4.80:50877 (2 connections now open)
2016-09-22T09:19:06.926+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:08.615+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:08.756+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51235 #51768 (3 connections now open)
2016-09-22T09:19:08.756+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51236 #51769 (4 connections now open)
2016-09-22T09:19:08.756+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51237 #51770 (5 connections now open)
2016-09-22T09:19:08.756+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51238 #51771 (6 connections now open)
2016-09-22T09:19:08.756+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51239 #51772 (7 connections now open)
2016-09-22T09:19:08.757+0000 I COMMAND [conn51768] command system.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:08.759+0000 I COMMAND [conn51769] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:08.827+0000 I COMMAND [conn51772] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 65ms
2016-09-22T09:19:08.828+0000 I COMMAND [conn51771] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 62ms
2016-09-22T09:19:08.829+0000 I COMMAND [conn51770] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 63ms
2016-09-22T09:19:08.830+0000 I COMMAND [conn51769] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 55ms
2016-09-22T09:19:08.831+0000 I COMMAND [conn51768] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 54ms
2016-09-22T09:19:08.928+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:09.391+0000 I COMMAND [conn51772] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D422B4949773848557871445559567A556870386A2B484C764D6F7538595572717953554E775077354E33724C466C7945484D656D784E6E643072764F4C...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.481+0000 I COMMAND [conn51771] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D583846456F4C657A76304B67576257714E4358744C552F45562F4456346C454B6E696B34455854424D496647714167494B7762677954645A58616F3659...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.604+0000 I COMMAND [conn51770] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D6673644E3856496D72356933774F535A784C327268444673665763482B746476794C524A70746F5776773141436765356F524F67614F6F544A61724946...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.689+0000 I COMMAND [conn51769] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D5379423276317233474C526551553035514F532F346374757A6B2F584135633036305A342F7755704B532B2F514F7148706E6A445241627363384E4448...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.771+0000 I COMMAND [conn51768] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D74484954456F7166616845475239466E454A445032577A64424A39492F42774D625670593334394A356F626C5963686B76304559424C31333146756C4D...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.772+0000 I ACCESS [conn51772] Successfully authenticated as principal website-user on website
2016-09-22T09:19:09.772+0000 I COMMAND [conn51772] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:19:09.773+0000 I ACCESS [conn51771] Successfully authenticated as principal website-user on website
2016-09-22T09:19:09.773+0000 I COMMAND [conn51771] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.773+0000 I ACCESS [conn51770] Successfully authenticated as principal website-user on website
2016-09-22T09:19:09.773+0000 I COMMAND [conn51770] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.773+0000 I ACCESS [conn51769] Successfully authenticated as principal website-user on website
2016-09-22T09:19:09.773+0000 I COMMAND [conn51769] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.773+0000 I ACCESS [conn51768] Successfully authenticated as principal website-user on website
2016-09-22T09:19:09.774+0000 I COMMAND [conn51768] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:09.778+0000 I NETWORK [conn51768] end connection 172.16.3.43:51235 (6 connections now open)
2016-09-22T09:19:09.778+0000 I NETWORK [conn51769] end connection 172.16.3.43:51236 (5 connections now open)
2016-09-22T09:19:09.779+0000 I NETWORK [conn51770] end connection 172.16.3.43:51237 (4 connections now open)
2016-09-22T09:19:09.779+0000 I NETWORK [conn51771] end connection 172.16.3.43:51238 (3 connections now open)
2016-09-22T09:19:09.779+0000 I NETWORK [conn51772] end connection 172.16.3.43:51239 (2 connections now open)
2016-09-22T09:19:10.929+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:12.931+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:13.616+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:14.457+0000 I REPL [ReplicationExecutor] syncing from: 192.168.4.71:27017
2016-09-22T09:19:14.457+0000 D COMMAND [ConnectBG] BackgroundJob starting: ConnectBG
2016-09-22T09:19:14.459+0000 D NETWORK [rsBackgroundSync] connected to server 192.168.4.71:27017 (192.168.4.71)
2016-09-22T09:19:14.500+0000 W REPL [rsBackgroundSync] we are too stale to use 192.168.4.71:27017 as a sync source
2016-09-22T09:19:14.500+0000 I REPL [ReplicationExecutor] could not find member to sync from
2016-09-22T09:19:14.500+0000 E REPL [rsBackgroundSync] too stale to catch up -- entering maintenance mode
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] our last optime : (term: 2614, timestamp: Sep 20 09:11:05:3595)
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] oldest available is (term: 2614, timestamp: Sep 20 09:11:05:83c6)
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] See http://dochub.mongodb.org/core/resyncingaverystalereplicasetmember
2016-09-22T09:19:14.501+0000 I REPL [ReplicationExecutor] going into maintenance mode with 1115 other maintenance mode tasks in progress
2016-09-22T09:19:14.933+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:16.304+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.83:33920 #51773 (3 connections now open)
2016-09-22T09:19:16.305+0000 I COMMAND [conn51773] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.306+0000 I COMMAND [conn51773] command second-website.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.307+0000 I ACCESS [conn51773] authenticate db: second-website { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" }
2016-09-22T09:19:16.308+0000 I COMMAND [conn51773] command admin.system.users command: authenticate { authenticate: 1, user: "second-website-user", nonce: "xxx", key: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:89 locks:{ Global: { acquireCount: { r: 4 } }, MMAPV1Journal: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { R: 2 } } } protocol:op_query 0ms
2016-09-22T09:19:16.309+0000 I COMMAND [conn51773] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.322+0000 I COMMAND [conn51773] command second-website.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 11ms
2016-09-22T09:19:16.333+0000 I NETWORK [initandlisten] connection accepted from 192.168.4.80:50879 #51774 (4 connections now open)
2016-09-22T09:19:16.333+0000 I COMMAND [conn51774] command admin.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.347+0000 I COMMAND [conn51774] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 12ms
2016-09-22T09:19:16.407+0000 I COMMAND [conn51773] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D3154597850337036546B6B4D384F704C6E5A4F6D5933657130306836774E786E726C744C475976614D33786B76454C726A467533725350483738524D41...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.408+0000 I ACCESS [conn51773] Successfully authenticated as principal second-website-user on second-website
2016-09-22T09:19:16.408+0000 I COMMAND [conn51773] command second-website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.421+0000 I COMMAND [conn51774] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D41315962524E744D6B446D4631776C5265626B4A50424C3749444F31662F625A7A335149507A777933783645744575397343566C6C485157356D717253...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.488+0000 I ACCESS [conn51774] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:19:16.488+0000 I COMMAND [conn51774] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:19:16.489+0000 I COMMAND [conn51774] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.494+0000 I NETWORK [conn51773] end connection 192.168.4.83:33920 (3 connections now open)
2016-09-22T09:19:16.503+0000 I COMMAND [conn51774] command customer-1.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} protocol:op_query 12ms
2016-09-22T09:19:16.569+0000 I COMMAND [conn51774] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D61472F3870476F7A54713244474C78676A3157576274576F456950344462376855306A786D783865504D596370342B44705164786A41355533472F4455...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.639+0000 I ACCESS [conn51774] Successfully authenticated as principal hafnermuschler-user on customer-1
2016-09-22T09:19:16.639+0000 I COMMAND [conn51774] command customer-1.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:16.640+0000 I NETWORK [conn51774] end connection 192.168.4.80:50879 (2 connections now open)
2016-09-22T09:19:16.934+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:18.617+0000 I COMMAND [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.73:27017", fromId: 2, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:18.758+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51245 #51775 (3 connections now open)
2016-09-22T09:19:18.758+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51246 #51776 (4 connections now open)
2016-09-22T09:19:18.759+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51247 #51777 (5 connections now open)
2016-09-22T09:19:18.759+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51248 #51778 (6 connections now open)
2016-09-22T09:19:18.759+0000 I NETWORK [initandlisten] connection accepted from 172.16.3.43:51249 #51779 (7 connections now open)
2016-09-22T09:19:18.759+0000 I COMMAND [conn51775] command system.$cmd command: isMaster { ismaster: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:18.761+0000 I COMMAND [conn51776] command system.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:376 locks:{} protocol:op_query 0ms
2016-09-22T09:19:18.829+0000 I COMMAND [conn51779] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 54ms
2016-09-22T09:19:18.832+0000 I COMMAND [conn51776] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 65ms
2016-09-22T09:19:18.832+0000 I COMMAND [conn51778] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 61ms
2016-09-22T09:19:18.833+0000 I COMMAND [conn51777] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 64ms
2016-09-22T09:19:18.833+0000 I COMMAND [conn51775] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx", autoAuthorize: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 58ms
2016-09-22T09:19:18.934+0000 I COMMAND [conn39401] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rSet", configVersion: 5, from: "192.168.4.71:27017", fromId: 0, term: 2836 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:387 locks:{} protocol:op_command 0ms
2016-09-22T09:19:19.379+0000 I COMMAND [conn51779] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D36513836624757593769676D386339496957684A6C4D37706E4E75487264347242427565386C33526D5837497A766B4B6F3766326974612B617037594B...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.460+0000 I COMMAND [conn51776] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D6545644D6A6D363049344356386F51576374467458643077564E6E36515A754D6254674A6867432B2F58795A5756694B486E6858794733346152794C50...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.543+0000 I COMMAND [conn51778] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D4F504F32645A756B2F54576864616D544D48446C4174636F594A6351547A6B64664C75313844683762424E373434522F38766C414846477239536E5235...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.624+0000 I COMMAND [conn51777] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D466B7938383641475577774562673049514D625643724E694F32462B31625269744B632F514C3743575A746463366261475535792B343470617A494759...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.708+0000 I COMMAND [conn51775] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, 633D626977732C723D6737765573587478343577357252654A7A7164546E337133504C356A53764578446575756F63515A426F6E5A6E7372796E535973667A685855367A4959...) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:108 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.709+0000 I ACCESS [conn51778] Successfully authenticated as principal website-user on website
2016-09-22T09:19:19.709+0000 I COMMAND [conn51778] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_query 0ms
2016-09-22T09:19:19.709+0000 I ACCESS [conn51777] Successfully authenticated as principal website-user on website
2016-09-22T09:19:19.709+0000 I COMMAND [conn51777] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.710+0000 I ACCESS [conn51776] Successfully authenticated as principal website-user on website
2016-09-22T09:19:19.710+0000 I COMMAND [conn51776] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.710+0000 I ACCESS [conn51775] Successfully authenticated as principal website-user on website
2016-09-22T09:19:19.710+0000 I COMMAND [conn51775] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
2016-09-22T09:19:19.710+0000 I ACCESS [conn51779] Successfully authenticated as principal website-user on website
2016-09-22T09:19:19.710+0000 I COMMAND [conn51779] command website.$cmd command: saslContinue { saslContinue: 1, conversationId: 1, payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{} protocol:op_query 0ms
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user...@googlegroups.com.
Lukas Lehner
Sep 23, 2016, 6:19:03 AM9/23/16
to mongod...@googlegroups.com
how big is your OpLog window? What options did you configure for mongod?
you need to delete data files (rm -rf) and restart mongod. He will do a initial sync from primary
here the relevant log entries from your posting
2016-09-22T09:19:14.459+0000 D NETWORK [rsBackgroundSync] connected to server 192.168.4.71:27017 (192.168.4.71)
2016-09-22T09:19:14.500+0000 W REPL [rsBackgroundSync] we are too stale to use 192.168.4.71:27017 as a sync source
2016-09-22T09:19:14.500+0000 I REPL [ReplicationExecutor] could not find member to sync from
2016-09-22T09:19:14.500+0000 E REPL [rsBackgroundSync] too stale to catch up -- entering maintenance mode
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] our last optime : (term: 2614, timestamp: Sep 20 09:11:05:3595)
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] oldest available is (term: 2614, timestamp: Sep 20 09:11:05:83c6)
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] See http://dochub.mongodb.org/core/resyncingaverystalereplicasetmember
2016-09-22T09:19:14.501+0000 I REPL [ReplicationExecutor] going into maintenance mode with 1115 other maintenance mode tasks in progress
2016-09-22T09:19:14.500+0000 W REPL [rsBackgroundSync] we are too stale to use 192.168.4.71:27017 as a sync source
2016-09-22T09:19:14.500+0000 I REPL [ReplicationExecutor] could not find member to sync from
2016-09-22T09:19:14.500+0000 E REPL [rsBackgroundSync] too stale to catch up -- entering maintenance mode
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] our last optime : (term: 2614, timestamp: Sep 20 09:11:05:3595)
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] oldest available is (term: 2614, timestamp: Sep 20 09:11:05:83c6)
2016-09-22T09:19:14.500+0000 I REPL [rsBackgroundSync] See http://dochub.mongodb.org/core/resyncingaverystalereplicasetmember
2016-09-22T09:19:14.501+0000 I REPL [ReplicationExecutor] going into maintenance mode with 1115 other maintenance mode tasks in progress
A replica set member becomes “stale” when its replication process falls so far behind that the primaryoverwrites oplog entries the member has not yet replicated. The member cannot catch up and becomes “stale.” When this occurs, you must completely resynchronize the member by removing its data and performing an initial sync.
This tutorial addresses both resyncing a stale member and to creating a new member using seed data from another member. When syncing a member, choose a time when the system has the bandwidth to move a large amount of data. Schedule the synchronization during a time of low usage or during a maintenance window.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user+unsubscribe@googlegroups.com.
To post to this group, send email to mongod...@googlegroups.com.
Visit this group at https://groups.google.com/group/mongodb-user.
To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/94fcf532-b943-4405-890a-a175eb4229a9%40googlegroups.com.
Lukas Lehner
Sep 23, 2016, 6:20:14 AM9/23/16
to mongod...@googlegroups.com
I guess you need to increase the OpLog Window, because you have lots of writes during resync
Reply all
Reply to author
Forward
0 new messages