rs.initiate() fails due to duplicated replicaset alive members

[marcusphi]

Affected Puppet, Ruby, OS and module versions/distributions

• Puppet: 6.11.0
• Ruby: ruby 2.0.0p648 (2015-12-16) [x86_64-linux]
• Distribution: CentOS Linux release 7.6.1810 (Core)
• Module version: 'puppet-mongodb', '3.0.0'

How to reproduce (e.g Puppet code you use)

Trying to set up a replica set.

Code

  $replset = 'azaset'
  $replset_members: ['devxx01.dev.aza.nu', 'devxx02.dev.aza.nu', 'devxx03.dev.aza.nu']
  $replset_arbiter: 'devxx03.dev.aza.nu'

  class {'::mongodb::server':
    storage_engine => 'wiredTiger',
    replset        => $replset,
    replset_config => {
      $replset => {
        ensure  => present,
        members => $replset_members,
        arbiter => $replset_arbiter,
      }
    },
    dbpath         => '/opt/mongodatafiles',
    dbpath_fix     => true,
    auth           => false,
    create_admin   => false,
    admin_username => admin,
    admin_password => 'secret123',
    store_creds    => true,
    handle_creds   => true,
  }

What's a bit special is that the first of the 3 hosts have already had mongo installed in stndalone mode. But I don't see why this would be a problem.

Also, shutting it down does not help. Then you get Error: /Stage[main]/Mongodb::Replset/Mongodb_replset[azaset]: Could not evaluate: Can't connect to any member of replicaset azaset.

Also, the first used to have authentication activated (which I know wont work) but I have deactivated it in config (security.authorization: disabled) and since restarted mongo to make it take effect.

What are you seeing

First host running puppet on (devxx01) is duplicated in alive members, which make rs.initiate() fail.

Excerpt from logs:

Alive members: [{"host"=>"devxx01.dev.aza.nu"}, {"host"=>"devxx01.dev.aza.nu"}]
...
rs.initiate() failed for replicaset azaset: 
  Found two member configurations with same _id field, members.0._id == members.1._id == 1

It seems this line of code does not work as intended:

puppet-mongodb/lib/puppet/provider/mongodb_replset/mongo.rb

Line 186 in 041bd39

alive.uniq!

The reason that the same host appears twice in the first place should maybe be fixed as well. It is pushed to alive array 2 times because both status['errmsg'].include?('no replset config has been received') and status.key?('info') is true. Maybe an if should be an elif?

What behaviour did you expect instead

Replica set to be installed.

Output log

Debug: Executing: '/bin/rpm -q mongodb-org-3.2.19 --nosignature --nodigest --qf %{NAME} %|EPOCH?{%{EPOCH}}:{0}| %{VERSION} %{RELEASE} %{ARCH}\n'
Debug: /Stage[main]/Mongodb::Server::Config/File[/opt/mongodatafiles]/seluser: SELinux bindings not found. Ignoring parameter.
Debug: /Stage[main]/Mongodb::Server::Config/File[/opt/mongodatafiles]/selrole: SELinux bindings not found. Ignoring parameter.
Debug: /Stage[main]/Mongodb::Server::Config/File[/opt/mongodatafiles]/seltype: SELinux bindings not found. Ignoring parameter.
Debug: /Stage[main]/Mongodb::Server::Config/File[/opt/mongodatafiles]/selrange: SELinux bindings not found. Ignoring parameter.
Debug: Exec[fix dbpath permissions](provider=posix): Executing check 'find /opt/mongodatafiles -not -user mongod -o -not -group mongod -print -quit | grep -q '.*''
Debug: Executing: 'find /opt/mongodatafiles -not -user mongod -o -not -group mongod -print -quit | grep -q '.*''
Debug: /Stage[main]/Mongodb::Server::Config/Exec[fix dbpath permissions]: 'chown -R mongod:mongod /opt/mongodatafiles' won't be executed because of failed check 'onlyif'
Debug: /Stage[main]/Mongodb::Server::Config/File[/root/.mongorc.js]: Nothing to manage: no ensure and the resource doesn't exist
Debug: Prefetching mongo resources for mongodb_replset
Debug: Executing: '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())' returned 252: 2019-11-25T16:08:42.088+0100 E QUERY    [thread1] Error: Could not retrieve replica set config: {
	"info" : "run rs.initiate(...) if not yet done for the set",
	"ok" : 0,
	"errmsg" : "no replset config has been received",
	"code" : 94
} :
rs.conf@src/mongo/shell/utils.js:1217:11
@(shell eval):1:11' Retry: '1'
Debug: Executing: '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())' returned 252: 2019-11-25T16:08:45.151+0100 E QUERY    [thread1] Error: Could not retrieve replica set config: {
	"info" : "run rs.initiate(...) if not yet done for the set",
	"ok" : 0,
	"errmsg" : "no replset config has been received",
	"code" : 94
} :
rs.conf@src/mongo/shell/utils.js:1217:11
@(shell eval):1:11' Retry: '2'
Debug: Executing: '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())' returned 252: 2019-11-25T16:08:48.207+0100 E QUERY    [thread1] Error: Could not retrieve replica set config: {
	"info" : "run rs.initiate(...) if not yet done for the set",
	"ok" : 0,
	"errmsg" : "no replset config has been received",
	"code" : 94
} :
rs.conf@src/mongo/shell/utils.js:1217:11
@(shell eval):1:11' Retry: '3'
Debug: Executing: '/bin/mongo admin --quiet --host 127.0.0.1:27017 --eval printjson(rs.conf())'
Debug: Got an exception: Could not evaluate MongoDB shell command: printjson(rs.conf())
Notice: /Stage[main]/Mongodb::Replset/Mongodb_replset[azaset]/ensure: created (corrective)
Debug: Checking for dead and alive members
Debug: Checking replicaset member devxx01.dev.aza.nu ...
Debug: Executing: '/bin/mongo admin --quiet --host devxx01.dev.aza.nu --eval printjson(rs.status())'
Debug: Mongo v4 rs.status() RS not initialized output
Debug: Host devxx01.dev.aza.nu is alive but unconfigured: run rs.... if not yet done for the set
Debug: Checking replicaset member devxx02.dev.aza.nu ...
Debug: Executing: '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())' returned 1: 2019-11-25T16:08:51.398+0100 W NETWORK  [thread1] Failed to connect to 10.86.8.14:27017, in(checking socket for error after poll), reason: errno:111 Connection refused
2019-11-25T16:08:51.399+0100 E QUERY    [thread1] Error: couldn't connect to server devxx02.dev.aza.nu:27017, connection attempt failed :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:21

exception: connect failed' Retry: '1'
Debug: Executing: '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())' returned 1: 2019-11-25T16:08:54.478+0100 W NETWORK  [thread1] Failed to connect to 10.86.8.14:27017, in(checking socket for error after poll), reason: errno:111 Connection refused
2019-11-25T16:08:54.478+0100 E QUERY    [thread1] Error: couldn't connect to server devxx02.dev.aza.nu:27017, connection attempt failed :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:21

exception: connect failed' Retry: '2'
Debug: Executing: '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())' returned 1: 2019-11-25T16:08:57.547+0100 W NETWORK  [thread1] Failed to connect to 10.86.8.14:27017, in(checking socket for error after poll), reason: errno:111 Connection refused
2019-11-25T16:08:57.548+0100 E QUERY    [thread1] Error: couldn't connect to server devxx02.dev.aza.nu:27017, connection attempt failed :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:21

exception: connect failed' Retry: '3'
Debug: Executing: '/bin/mongo admin --quiet --host devxx02.dev.aza.nu --eval printjson(rs.status())'
Debug: Got an exception: Could not evaluate MongoDB shell command: printjson(rs.status())
Warning: Can't connect to replicaset member devxx02.dev.aza.nu.
Debug: Checking replicaset member devxx03.dev.aza.nu ...
Debug: Executing: '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())' returned 1: 2019-11-25T16:09:00.663+0100 W NETWORK  [thread1] Failed to connect to 10.86.8.11:27017, in(checking socket for error after poll), reason: errno:111 Connection refused
2019-11-25T16:09:00.664+0100 E QUERY    [thread1] Error: couldn't connect to server devxx03.dev.aza.nu:27017, connection attempt failed :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:21

exception: connect failed' Retry: '1'
Debug: Executing: '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())' returned 1: 2019-11-25T16:09:03.725+0100 W NETWORK  [thread1] Failed to connect to 10.86.8.11:27017, in(checking socket for error after poll), reason: errno:111 Connection refused
2019-11-25T16:09:03.725+0100 E QUERY    [thread1] Error: couldn't connect to server devxx03.dev.aza.nu:27017, connection attempt failed :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:21

exception: connect failed' Retry: '2'
Debug: Executing: '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())'
Debug: Request failed: 'Execution of '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())' returned 1: 2019-11-25T16:09:06.783+0100 W NETWORK  [thread1] Failed to connect to 10.86.8.11:27017, in(checking socket for error after poll), reason: errno:111 Connection refused
2019-11-25T16:09:06.783+0100 E QUERY    [thread1] Error: couldn't connect to server devxx03.dev.aza.nu:27017, connection attempt failed :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:21

exception: connect failed' Retry: '3'
Debug: Executing: '/bin/mongo admin --quiet --host devxx03.dev.aza.nu --eval printjson(rs.status())'
Debug: Got an exception: Could not evaluate MongoDB shell command: printjson(rs.status())
Warning: Can't connect to replicaset member devxx03.dev.aza.nu.
Debug: Alive members: [{"host"=>"devxx01.dev.aza.nu"}, {"host"=>"devxx01.dev.aza.nu"}]
Debug: Dead members: [{"host"=>"devxx02.dev.aza.nu"}, {"host"=>"devxx03.dev.aza.nu"}]
Debug: Checking for new replset
Debug: Executing: '/bin/mongo admin --quiet --host devxx01.dev.aza.nu --eval printjson(db.isMaster())'
Debug: Executing: '/bin/mongo admin --quiet --host devxx01.dev.aza.nu --eval printjson(db.isMaster())'
Debug: Initializing the replset azaset
Debug: Starting replset config is "{\"_id\":\"azaset\",\"members\":[{\"host\":\"devxx01.dev.aza.nu\",\"_id\":1},{\"host\":\"devxx01.dev.aza.nu\",\"_id\":1}],\"settings\":{}}"
Debug: Executing: '/bin/mongo admin --quiet --host devxx01.dev.aza.nu --eval printjson(rs.initiate({"_id":"azaset","members":[{"host":"devxx01.dev.aza.nu","_id":1},{"host":"devxx01.dev.aza.nu","_id":1}],"settings":{}}))'
Error: /Stage[main]/Mongodb::Replset/Mongodb_replset[azaset]: Could not evaluate: rs.initiate() failed for replicaset azaset: Found two member configurations with same _id field, members.0._id == members.1._id == 1
Debug: Class[Mongodb::Replset]: Resource is being skipped, unscheduling all events

[marcusphi]

Ha, it seems this is fixed in latest code, but in latest release 3.0.0, that I have, it is broken:
https://github.com/voxpupuli/puppet-mongodb/blob/v3.0.0/lib/puppet/provider/mongodb_replset/mongo.rb#L149

This was the fix: 25d2486

So fix is to do a new release.

[witjoh]

This is solved by #703. This can be closed