can't create the admin user on a fresh install

[jakimowicz]

When using user_management to create the admin user on a fresh install, it fails to add the admin user because the mongodb server is not started yet.

If you run the recipe again against the same server, it will pass on the second time.

I think it can be quickly solved by using retries / delay in order to let the mongodb server starts properly.

Recipe: mongodb::default
  * template[/etc/default/mongodb] action create
    - update content in file /etc/default/mongodb from a35762 to 91c827
        --- /etc/default/mongodb    2014-08-13 16:59:40.409554000 +0000
        +++ /tmp/chef-rendered-template20140813-2196-4zvqhw 2014-08-13 17:00:14.837554000 +0000
        @@ -1,2 +1,13 @@
        -ENABLE_MONGODB=no
        +#
        +# Automatically Generated by Chef, do not edit directly!
        +#
        +
        +CONFIGFILE="/etc/mongodb.conf"
        +DAEMON="/usr/bin/$NAME"
        +DAEMONUSER="mongodb"
        +DAEMON_OPTS="--config /etc/mongodb.conf"
        +DAEMON_USER="mongodb"
        +ENABLE_MONGO="yes"
        +ENABLE_MONGOD="yes"
        +ENABLE_MONGODB="yes"

  * template[/etc/mongodb.conf] action create (up to date)
  * directory[/var/log/mongodb] action create (up to date)
  * directory[/var/lib/mongodb] action create (up to date)
  * template[/etc/init/mongodb.conf] action create (up to date)
  * service[mongodb] action enable (up to date)
  * service[mongodb] action start
    - start service service[mongodb]

Recipe: mongodb::user_management
  * chef_gem[mongo] action install (up to date)
  * mongodb_user[admin] action add      ** Notice: The native BSON extension was not loaded. **

      For optimal performance, use of the BSON extension is recommended.

      To enable the extension make sure ENV['BSON_EXT_DISABLED'] is not set
      and run the following command:

        gem install bson_ext

      If you continue to receive this message after installing, make sure that
      the bson_ext gem is in your load path.


================================================================================
Error executing action `add` on resource 'mongodb_user[admin]'
================================================================================


Mongo::ConnectionFailure
------------------------
Failed to connect to a master node at localhost:27017


Cookbook Trace:
---------------
/home/cloud/chef-solo/cookbooks-2/mongodb/providers/user.rb:52:in `new'
/home/cloud/chef-solo/cookbooks-2/mongodb/providers/user.rb:52:in `retrieve_db'
/home/cloud/chef-solo/cookbooks-2/mongodb/providers/user.rb:9:in `add_user'
/home/cloud/chef-solo/cookbooks-2/mongodb/providers/user.rb:61:in `block in class_from_file'


Resource Declaration:
---------------------
# In /home/cloud/chef-solo/cookbooks-2/mongodb/recipes/user_management.rb

 17:   mongodb_user user['username'] do
 18:     password user['password']
 19:     roles user['roles']
 20:     database user['database']
 21:     connection node['mongodb']
 22:     action :add
 23:   end
 24: end



Compiled Resource:
------------------
# Declared in /home/cloud/chef-solo/cookbooks-2/mongodb/recipes/user_management.rb:17:in `block in from_file'

mongodb_user("admin") do
  action [:add]
  retries 0
  retry_delay 2
  guard_interpreter :default
  cookbook_name :mongodb
  recipe_name "user_management"
  password "XXX"
  roles ["userAdminAnyDatabase", "dbAdminAnyDatabase"]
  database "admin"
  connection {"client_roles"=>[], "cluster_name"=>nil, "shard_name"=>"default", "replica_arbiter_only"=>false, "replica_build_indexes"=>true, "replica_hidden"=>false, "replica_slave_delay"=>0, "replica_priority"=>1, "replica_tags"=>{}, "replica_votes"=>1, "auto_configure"=>{"replicaset"=>true, "sharding"=>true}, "configserver_url"=>nil, "root_group"=>"root", "user"=>"mongodb", "group"=>"mongodb", "init_dir"=>"/etc/init/", "init_script_template"=>"debian-mongodb.upstart.erb", "sysconfig_file"=>"/etc/default/mongodb", "sysconfig_file_template"=>"mongodb.sysconfig.erb", "dbconfig_file_template"=>"mongodb.conf.erb", "dbconfig_file"=>"/etc/mongodb.conf", "package_name"=>"mongodb", "package_version"=>nil, "default_init_name"=>"mongodb", "instance_name"=>"mongodb", "install_method"=>"distro", "is_replicaset"=>nil, "is_shard"=>nil, "is_configserver"=>nil, "reload_action"=>"restart", "apt_repo"=>"ubuntu-upstart", "template_cookbook"=>"mongodb", "key_file_content"=>nil, "ruby_gems"=>{"mongo"=>nil, "bson_ext"=>nil}, "config"=>{"port"=>27017, "bind_ip"=>"0.0.0.0", "logpath"=>"/var/log/mongodb/mongodb.log", "logappend"=>true, "fork"=>false, "dbpath"=>"/var/lib/mongodb", "nojournal"=>false, "rest"=>false, "smallfiles"=>false, "oplogSize"=>nil, "replSet"=>nil, "auth"=>true}, "mms_agent"=>{"api_key"=>nil, "package_url"=>"https://mms.mongodb.com/download/agent/%{agent_type}/mongodb-mms-%{agent_type}-agent", "monitoring"=>{"version"=>"2.2.0.70-1", "mmsApiKey"=>nil, "mmsBaseUrl"=>"https://mms.mongodb.com", "configCollectionsEnabled"=>true, "configDatabasesEnabled"=>true, "throttlePassesShardChunkCounts"=>10, "throttlePassesDbstats"=>20, "throttlePassesOplog"=>10, "disableProfileDataCollection"=>false, "disableGetLogsDataCollection"=>false, "disableLocksAndRecordStatsDataCollection"=>false, "enableMunin"=>true, "useSslForAllConnections"=>false, "sslRequireValidServerCertificates"=>false}, "backup"=>{"version"=>"2.1.0.106-1", "mmsApiKey"=>nil, "mothership"=>"api-backup.mongodb.com", "https"=>true, "sslRequireValidServerCertificates"=>false}, "user"=>"mongodb-mms-agent", "group"=>"mongodb-mms-agent"}, "sysconfig"=>{"DAEMON"=>"/usr/bin/$NAME", "DAEMON_USER"=>"mongodb", "DAEMON_OPTS"=>"--config /etc/mongodb.conf", "CONFIGFILE"=>"/etc/mongodb.conf", "ENABLE_MONGODB"=>"yes", "DAEMONUSER"=>"mongodb", "ENABLE_MONGOD"=>"yes", "ENABLE_MONGO"=>"yes"}, "ulimit"=>{"fsize"=>"unlimited", "cpu"=>"unlimited", "as"=>"unlimited", "nofile"=>64000, "rss"=>"unlimited", "nproc"=>32000}, "admin"=>{"username"=>"admin", "password"=>"2NCDza6MLjDUm0m", "roles"=>["userAdminAnyDatabase", "dbAdminAnyDatabase"], "database"=>"admin"}, "users"=>[]}
  username "admin"
end

[cjhubert]

The recipe has tests in the kitchen.yml that run on fresh servers and the tests pass fine. And it does work for me as well. Could you give more information about the setup you have? Are you using sharding or replication? What platform / version are you trying to install it on?

[sbrinkmeyer]

i have a cloudformation, cloud init that is spinning up a single instance mongo replicaset. i have overriden the admin user and password. when it tries to apply user_management (line 17) it appears that the replicaset is not all the way up yet and as such it fails the chef run.

• mongodb_user[ADMINNAME] action add[2014-08-20T14:48:39+00:00] INFO: Processing mongodb_user[ADMINNAME] action add (mongodb::user_management line 17)
  [2014-08-20T14:48:39+00:00] WARN: Unable to authenticate as admin user. If this is a fresh install, ignore warning: Failed to authenticate user 'ADMINNAME' on db 'admin'.

Error executing action add on resource 'mongodb_user[ADMINNAME]'

Mongo::ConnectionFailure
not master

Cookbook Trace:
/var/chef/cache/cookbooks/mongodb/providers/user.rb:24:in add_user' /var/chef/cache/cookbooks/mongodb/providers/user.rb:61:inblock in class_from_file'

[cjhubert]

Just an update for you guys, I'm slightly struggling on coming up with a solution that works well with this so I'm going to have to ask for help. I've gotten it to a point where the mongod servers come up successfully, but no user is created. Re-provisioning the nodes does successfully create the user though.

The problem, I believe, is that rs.initialize() hasn't happened yet. Regardless of how long I try to delay creating the users, a primary being set could take minutes. So I'm kind of out of ideas. You can see what I've tried in this branch where I've disabled creating the users when replicasets are enabled until the replicaset has been configured and notifies the recipe. Unfortunately, like I said, it still does happen late enough (this is the log from the final mongod server that seems to always become primary, note how it says it's not master yet):

==> d2: [2014-09-12T20:29:57+00:00] INFO: Configuring replicaset with members d0, d1, d2
==> d2: [2014-09-12T20:29:57+00:00] INFO: ruby_block[config_replicaset] called
==> d2: [2014-09-12T20:29:57+00:00] INFO: ruby_block[config_replicaset] sending create action to ruby_block[create_replicaset_users] (delayed)
==> d2: [2014-09-12T20:29:57+00:00] INFO: ruby_block[create_replicaset_users] called
==> d2: [2014-09-12T20:29:57+00:00] INFO: [ruby_block[create_replicaset_users]] sending add action to mongodb_user[admin] (delayed)
==> d2: [2014-09-12T20:29:57+00:00] WARN: Default username / password detected for admin user
==> d2: [2014-09-12T20:29:57+00:00] WARN: These should be overridden to different, unique values
==> d2: [2014-09-12T20:29:57+00:00] WARN: Unable to authenticate as admin user. If this is a fresh install, ignore warning: Failed to authenticate user 'admin' on db 'admin'.
==> d2: [2014-09-12T20:29:57+00:00] WARN: Unable to add user, if this is a secondary replica, ignore: not master

I don't know the mongo ruby driver that well, if it has a method that will return the primary of a replicaset maybe we can have the recipe hold on until it returns a value?

If that wasn't enough, I don't have any leads on why the mongos server will not run with the user_management recipe. mongos just fails to start, and doesn't write out any logs. If I manually try to do sudo service mongos start it just responds with stop/waiting. If I run the command on the server manually though (mongos --configdb c0,c1,c2) it starts up without a problem.

The error that appears in the Chef run is simply that it can't connect to itself (probably because mongos failed to start... why, I'm not sure):

==> s0: [2014-09-12T20:32:09+00:00] INFO: service[mongos] sending create action to ruby_block[config_sharding] (immediate)
==> s0: [2014-09-12T20:32:09+00:00] INFO: {"rs_default"=>["d0:27017", "d1:27017", "d2:27017"]}
==> s0: [2014-09-12T20:32:09+00:00] INFO: ["rs_default/d0:27017,d1:27017,d2:27017"]
==> s0: [2014-09-12T20:32:09+00:00] WARN: Could not connect to database: 'localhost:27017', reason Failed to connect to a master node at localhost:27017

[cjhubert]

Sorry for the lack of updates guys. I figured out the reason mongos wouldn't start was because auth=true isn't a valid setting for mongos config file, d'oh. I didn't think at the time to check the upstart logs instead of the mongo logs. After I figured that out, I added retries to most of the code for configuring users.

Not my favorite way to handle things, but it looks like the recipe already was doing that for replicaset and shards. The main problem is the service restarting when it's trying to connect to the database to add users. I can't seem to reliably notify in chef after certain steps and ensure the service is currently running.

Anyways, this branch has worked for me with configuring a 3 config server, 3 mongod shard/replicaset, and 1 mongos VM with user management. You can see that working in my Vagrant example.

[thomas-riccardi]

@ceejh I believe the issue is that the mongodb service notification that runs ruby_block[config_replicaset] is not immediate (but ruby_block[config_sharding] is: :immediately).

[thomas-riccardi]

Also, I don't understand run_config_replicaset exists, but for the same reasons it should probably notify ruby_block[config_replicaset] immediately and not be delayed.

[codezomb]

Any update on getting the fix merged in? I'm running across this issue now, and the only thing I've been able to do is modify the role after the initial run.

[apalethorpe]

I've been having this problem too, I solved it by having a custom recipe get called before recipe[mongodb::user_management] is run in my chef role:

service "mongodb" do
    action :restart
end

execute "wait for mongo" do
    command "mongo"
    action :run
    retries 12
    retry_delay 10
end

This gives it a maximum of two minutes to wait for Mongo to respond before it tries to create the admin user. Seems to work fine for me :)

[joelwilson]

I have gone a similar route to @codezomb to workaround this issue, but ultimately, I hope that this bug gets fixed. 👍

[thomas-riccardi]

The replicaSet not being ready until the end should be fixed by now by PR #352.

However, the server may not be ready yet when chef sends commands (create user, but also configure replicaSet):
The first start of MongoDB server pre-allocates multiple large files (> 4GB) by default, which takes some time. During that the start service has already returned, and chef proceeds with creating the replicaSet and the users and other configs..

IMO the real issue is that the service start should not return until the server is ready to accept requests. I don't know if it's standard for services to do that, but it would simplify a lot automation, like chef.
The workaround provided by @apalethorpe emulates this behavior. However it doesn't help for #376 where it's replicaset configuration that fails, because it's executed immediately after the mongodb service start, I haven't found a way to insert a recipe there without patching chef-mongodb. Does anyone has a workaround for this case?