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

Secondary can't join if w:0 is in getLastErrorDefaults

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 2.8.0-rc0
    • Affects Version/s: None
    • Component/s: Replication
    • Minor Change
    • ALL
    • Hide

      Start a 2.6.4 single-member RS:

      > db.serverBuildInfo().version
      2.6.4
      > rs.initiate({
        _id: 'rs',
        members:[{_id: 0, host: 'localhost:27017'}],
        settings: {getLastErrorDefaults: {w:0}}
      })
      {
      	"info" : "Config now saved locally.  Should come online in about a minute.",
      	"ok" : 1
      }
      rs:OTHER> rs.status().members[0].stateStr
      PRIMARY
      

      Now start a member running the latest code from master (I have 4bea2a90) with the option "-vvvv". Try to add it from the shell connected to the 2.6.4 primary:

      rs:PRIMARY> rs.add('localhost:27018')
      { "ok" : 1 }
      

      The primary thinks the member was added. However:

      rs:PRIMARY> rs.status()
      {
      	"set" : "rs",
      	"date" : ISODate("2014-10-14T16:27:05Z"),
      	"myState" : 1,
      	"members" : [
      		{
      			"_id" : 0,
      			"name" : "localhost:27017",
      			"health" : 1,
      			"state" : 1,
      			"stateStr" : "PRIMARY",
      			"uptime" : 436,
      			"optime" : Timestamp(1413303922, 1),
      			"optimeDate" : ISODate("2014-10-14T16:25:22Z"),
      			"electionTime" : Timestamp(1413303652, 2),
      			"electionDate" : ISODate("2014-10-14T16:20:52Z"),
      			"self" : true
      		},
      		{
      			"_id" : 1,
      			"name" : "localhost:27018",
      			"health" : 1,
      			"state" : 6,
      			"stateStr" : "UNKNOWN",
      			"uptime" : 103,
      			"optime" : Timestamp(0, 0),
      			"optimeDate" : ISODate("1970-01-01T00:00:00Z"),
      			"lastHeartbeat" : ISODate("2014-10-14T16:27:04Z"),
      			"lastHeartbeatRecv" : ISODate("1970-01-01T00:00:00Z"),
      			"pingMs" : 0,
      			"lastHeartbeatMessage" : "still initializing"
      		}
      	],
      	"ok" : 1
      }
      

      The member we tried to add logs "User Assertion: 17505:replSet illegal config: getLastErrorDefaults w:0":

      2014-10-14T12:25:22.093-0400 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62519 #1 (1 connection now open)
      2014-10-14T12:25:22.093-0400 D COMMANDS [conn1] run command admin.$cmd { _isSelf: 1 }
      2014-10-14T12:25:22.093-0400 I QUERY    [conn1] command admin.$cmd command: _isSelf { _isSelf: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:53 0ms
      2014-10-14T12:25:22.093-0400 D NETWORK  [conn1] Socket recv() conn closed? 127.0.0.1:62519
      2014-10-14T12:25:22.093-0400 D NETWORK  [conn1] SocketException: remote: 127.0.0.1:62519 error: 9001 socket exception [CLOSED] server [127.0.0.1:62519]
      2014-10-14T12:25:22.093-0400 I NETWORK  [conn1] end connection 127.0.0.1:62519 (0 connections now open)
      2014-10-14T12:25:22.093-0400 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62520 #2 (2 connections now open)
      2014-10-14T12:25:22.093-0400 D COMMANDS [conn2] run command admin.$cmd { replSetHeartbeat: "rs", v: -1, pv: 1, checkEmpty: false, from: "", fromId: 0 }
      2014-10-14T12:25:22.093-0400 D COMMANDS [conn2] command: { replSetHeartbeat: "rs", v: -1, pv: 1, checkEmpty: false, from: "", fromId: 0 }
      2014-10-14T12:25:22.093-0400 I QUERY    [conn2] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rs", v: -1, pv: 1, checkEmpty: false, from: "", fromId: 0 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:72 0ms
      2014-10-14T12:25:22.094-0400 D COMMANDS [conn2] run command admin.$cmd { replSetHeartbeat: "rs", v: 2, pv: 1, checkEmpty: false, from: "localhost:27017", fromId: 0 }
      2014-10-14T12:25:22.094-0400 D COMMANDS [conn2] command: { replSetHeartbeat: "rs", v: 2, pv: 1, checkEmpty: false, from: "localhost:27017", fromId: 0 }
      2014-10-14T12:25:22.094-0400 I QUERY    [conn2] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rs", v: 2, pv: 1, checkEmpty: false, from: "localhost:27017", fromId: 0 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:72 0ms
      2014-10-14T12:25:22.408-0400 D QUERY    [rsStart] Running query: query: {} sort: {} projection: {} skip: 0 limit: 1
      2014-10-14T12:25:22.408-0400 D QUERY    [rsStart] Collection local.system.replset does not exist. Using EOF stage: query: {} sort: {} projection: {} skip: 0 limit: 1
      2014-10-14T12:25:22.408-0400 I QUERY    [rsStart] query local.system.replset planSummary: EOF ntoreturn:1 ntoskip:0 nscanned:0 nscannedObjects:0 keyUpdates:0 numYields:0  nreturned:0 reslen:20 0ms
      2014-10-14T12:25:22.408-0400 D REPLSETS [rsStart] ReplSetConfig load localhost:27017
      2014-10-14T12:25:22.409-0400 D COMMANDS [ConnectBG] BackgroundJob starting: ConnectBG
      2014-10-14T12:25:22.409-0400 D NETWORK  [rsStart] connected to server localhost:27017 (127.0.0.1)
      2014-10-14T12:25:22.409-0400 I REPLSETS [rsStart] trying to contact localhost:27017
      2014-10-14T12:25:22.409-0400 D COMMANDS [ConnectBG] BackgroundJob starting: ConnectBG
      2014-10-14T12:25:22.409-0400 D NETWORK  [rsStart] connected to server localhost:27017 (127.0.0.1)
      2014-10-14T12:25:22.410-0400 D -        [rsStart] User Assertion: 17505:replSet illegal config: getLastErrorDefaults w:0
      2014-10-14T12:25:22.410-0400 D REPLSETS [rsStart] replSet exception trying to load config from discovered seed localhost:27017
      2014-10-14T12:25:22.410-0400 I REPLSETS [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
      2014-10-14T12:25:22.410-0400 D REPLSETS [rsStart] replSet info no seed hosts were specified on the --replSet command line
      
      Show
      Start a 2.6.4 single-member RS: > db.serverBuildInfo().version 2.6.4 > rs.initiate({ _id: 'rs' , members:[{_id: 0, host: 'localhost:27017' }], settings: {getLastErrorDefaults: {w:0}} }) { "info" : "Config now saved locally. Should come online in about a minute." , "ok" : 1 } rs:OTHER> rs.status().members[0].stateStr PRIMARY Now start a member running the latest code from master (I have 4bea2a90) with the option "-vvvv". Try to add it from the shell connected to the 2.6.4 primary: rs:PRIMARY> rs.add( 'localhost:27018' ) { "ok" : 1 } The primary thinks the member was added. However: rs:PRIMARY> rs.status() { "set" : "rs" , "date" : ISODate( "2014-10-14T16:27:05Z" ), "myState" : 1, "members" : [ { "_id" : 0, "name" : "localhost:27017" , "health" : 1, "state" : 1, "stateStr" : "PRIMARY" , "uptime" : 436, "optime" : Timestamp(1413303922, 1), "optimeDate" : ISODate( "2014-10-14T16:25:22Z" ), "electionTime" : Timestamp(1413303652, 2), "electionDate" : ISODate( "2014-10-14T16:20:52Z" ), "self" : true }, { "_id" : 1, "name" : "localhost:27018" , "health" : 1, "state" : 6, "stateStr" : "UNKNOWN" , "uptime" : 103, "optime" : Timestamp(0, 0), "optimeDate" : ISODate( "1970-01-01T00:00:00Z" ), "lastHeartbeat" : ISODate( "2014-10-14T16:27:04Z" ), "lastHeartbeatRecv" : ISODate( "1970-01-01T00:00:00Z" ), "pingMs" : 0, "lastHeartbeatMessage" : "still initializing" } ], "ok" : 1 } The member we tried to add logs "User Assertion: 17505:replSet illegal config: getLastErrorDefaults w:0": 2014-10-14T12:25:22.093-0400 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62519 #1 (1 connection now open) 2014-10-14T12:25:22.093-0400 D COMMANDS [conn1] run command admin.$cmd { _isSelf: 1 } 2014-10-14T12:25:22.093-0400 I QUERY [conn1] command admin.$cmd command: _isSelf { _isSelf: 1 } ntoreturn:1 keyUpdates:0 numYields:0 reslen:53 0ms 2014-10-14T12:25:22.093-0400 D NETWORK [conn1] Socket recv() conn closed? 127.0.0.1:62519 2014-10-14T12:25:22.093-0400 D NETWORK [conn1] SocketException: remote: 127.0.0.1:62519 error: 9001 socket exception [CLOSED] server [127.0.0.1:62519] 2014-10-14T12:25:22.093-0400 I NETWORK [conn1] end connection 127.0.0.1:62519 (0 connections now open) 2014-10-14T12:25:22.093-0400 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62520 #2 (2 connections now open) 2014-10-14T12:25:22.093-0400 D COMMANDS [conn2] run command admin.$cmd { replSetHeartbeat: "rs" , v: -1, pv: 1, checkEmpty: false , from: "", fromId: 0 } 2014-10-14T12:25:22.093-0400 D COMMANDS [conn2] command: { replSetHeartbeat: "rs" , v: -1, pv: 1, checkEmpty: false , from: "", fromId: 0 } 2014-10-14T12:25:22.093-0400 I QUERY [conn2] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rs" , v: -1, pv: 1, checkEmpty: false , from: "", fromId: 0 } ntoreturn:1 keyUpdates:0 numYields:0 reslen:72 0ms 2014-10-14T12:25:22.094-0400 D COMMANDS [conn2] run command admin.$cmd { replSetHeartbeat: "rs" , v: 2, pv: 1, checkEmpty: false , from: "localhost:27017" , fromId: 0 } 2014-10-14T12:25:22.094-0400 D COMMANDS [conn2] command: { replSetHeartbeat: "rs" , v: 2, pv: 1, checkEmpty: false , from: "localhost:27017" , fromId: 0 } 2014-10-14T12:25:22.094-0400 I QUERY [conn2] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "rs" , v: 2, pv: 1, checkEmpty: false , from: "localhost:27017" , fromId: 0 } ntoreturn:1 keyUpdates:0 numYields:0 reslen:72 0ms 2014-10-14T12:25:22.408-0400 D QUERY [rsStart] Running query: query: {} sort: {} projection: {} skip: 0 limit: 1 2014-10-14T12:25:22.408-0400 D QUERY [rsStart] Collection local.system.replset does not exist. Using EOF stage: query: {} sort: {} projection: {} skip: 0 limit: 1 2014-10-14T12:25:22.408-0400 I QUERY [rsStart] query local.system.replset planSummary: EOF ntoreturn:1 ntoskip:0 nscanned:0 nscannedObjects:0 keyUpdates:0 numYields:0 nreturned:0 reslen:20 0ms 2014-10-14T12:25:22.408-0400 D REPLSETS [rsStart] ReplSetConfig load localhost:27017 2014-10-14T12:25:22.409-0400 D COMMANDS [ConnectBG] BackgroundJob starting: ConnectBG 2014-10-14T12:25:22.409-0400 D NETWORK [rsStart] connected to server localhost:27017 (127.0.0.1) 2014-10-14T12:25:22.409-0400 I REPLSETS [rsStart] trying to contact localhost:27017 2014-10-14T12:25:22.409-0400 D COMMANDS [ConnectBG] BackgroundJob starting: ConnectBG 2014-10-14T12:25:22.409-0400 D NETWORK [rsStart] connected to server localhost:27017 (127.0.0.1) 2014-10-14T12:25:22.410-0400 D - [rsStart] User Assertion: 17505:replSet illegal config: getLastErrorDefaults w:0 2014-10-14T12:25:22.410-0400 D REPLSETS [rsStart] replSet exception trying to load config from discovered seed localhost:27017 2014-10-14T12:25:22.410-0400 I REPLSETS [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG) 2014-10-14T12:25:22.410-0400 D REPLSETS [rsStart] replSet info no seed hosts were specified on the --replSet command line

      Two bugs:

      1. If you try to add a member running 2.8 to a replica set configured with {getLastErrorDefaults: {w:0}}, it stays in state UNKNOWN. It should be REMOVED.

      2. The member doesn't log the problem at the default log level. We shouldn't have to increase verbosity to see what the problem is.

            Assignee:
            spencer@mongodb.com Spencer Brody (Inactive)
            Reporter:
            jesse@mongodb.com A. Jesse Jiryu Davis
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated:
              Resolved: