Merge ~freyes/charm-mongodb:status-fix into ~mongodb-charmers/charm-mongodb:master

[Felipe Reyes]

Hello,

I'm adding the missing pieces on top of Mario's branch[0] as he delegated on me this functionality, because he's not able to keep working on it.

The most relevant changes I made are:

f52c8db Add functional test to check workload status
2ef8834 Log replSetGetStatus only when status not found for self
eca7ebd update-status: check replica set status when relation is made
669bf19 Set workload status before returning in update_status()

Thanks,

[0] https://code.launchpad.net/~mariosplivalo/mongodb-charm/+git/mongodb-charm/+merge/341289

[Stuart Bishop (stub)]

This looks good. Some comments inline, mostly trivial things to fix before landing. Adding a timeout when adding a secondary probably requires more thought, and likely best deferred until later.

Pre-approved from me, or I can rereview if you feel it is necessary.

review: Approve

[Felipe Reyes (freyes)]

Hi Stuart,

I addressed your comments, except some of the changes to the messages printed to the users, mostly because those were chosen by Mario and some of them align better with what we see in other charms (e.g. "Unit is ready...")

The functional tests log can be reviewed at http://paste.ubuntu.com/p/bn6hbtDw4g/

Best,

PS: I don't have merge privileges, so if you are OK with this MP would be great if you could merge it and publish the charm into the charmstore.

[Stuart Bishop (stub)]

Landed and released as cs:~mongodb-charmers/mongodb-6 / cs:mongodb-48

[Felipe Reyes (freyes)]

On Mon, May 28, 2018 at 07:32:00AM -0000, Stuart Bishop wrote:
> Landed and released as cs:~mongodb-charmers/mongodb-6 / cs:mongodb-48

thank you so much :-)

diff --git a/hooks/hooks.py b/hooks/hooks.py
index d3774a7..9de334d 100755
--- a/hooks/hooks.py
+++ b/hooks/hooks.py
@@ -6,7 +6,9 @@ Created on Aug 1, 2012
 '''
 
 import commands
+import json
 import os
+import pprint
 import re
 import signal
 import socket
@@ -30,14 +32,15 @@ from string import Template
 from textwrap import dedent
 from yaml.constructor import ConstructorError
 
+from charmhelpers.core.decorators import retry_on_exception
+from charmhelpers.payload.execd import execd_preinstall
+
 from charmhelpers.fetch import (
     add_source,
     apt_update,
     apt_install
 )
 
-import json
-
 from charmhelpers.core.host import (
     service,
     lsb_release,
@@ -47,6 +50,7 @@ from charmhelpers.core.hookenv import (
     close_port,
     config,
     is_relation_made,
+    log as juju_log,
     open_port,
     unit_get,
     relation_get,
@@ -58,15 +62,12 @@ from charmhelpers.core.hookenv import (
     Hooks,
     DEBUG,
     WARNING,
-    is_leader
+    is_leader,
+    status_set,
+    application_version_set,
 )
 
-from charmhelpers.core.hookenv import log as juju_log
-
-from charmhelpers.payload.execd import execd_preinstall
-
 from charmhelpers.contrib.hahelpers.cluster import (
-    oldest_peer,
     peer_units
 )
 
@@ -586,8 +587,8 @@ def remove_replset_from_upstart():
     """
     try:
         mongodb_init_config = open(default_mongodb_init_config).read()
-         
-        if re.search(' --replSet', mongodb_init_config, 
+
+        if re.search(' --replSet', mongodb_init_config,
                      re.MULTILINE) is not None:
             mongodb_init_config = re.sub(' --replSet .\w+', '',
                                          mongodb_init_config)
@@ -921,6 +922,7 @@ def arm64_trusty_quirk():
 def install_hook():
     juju_log('Begin install hook.')
     execd_preinstall()
+    status_set('maintenance', 'Installing packages')
     juju_log("Installing mongodb")
     add_source(config('source'), config('key'))
 
@@ -935,9 +937,9 @@ def install_hook():
 @hooks.hook('config-changed')
 def config_changed():
     juju_log("Entering config_changed")
-    print "Entering config_changed"
+    status_set('maintenance', 'Configuring unit')
     config_data = config()
-    print "config_data: ", config_data
+    juju_log("config_data: {}".format(config_data), level=DEBUG)
     mongodb_config = open(default_mongodb_config).read()
 
     # Trigger volume initialization logic for permanent storage
@@ -976,11 +978,12 @@ def config_changed():
     current_web_admin_ui_port = int(current_mongodb_port) + 1000
     new_web_admin_ui_port = int(config_data['port']) + 1000
 
-    print "current_mongodb_port: ", current_mongodb_port
+    juju_log("Configured mongodb port: {}".format(current_mongodb_port),
+             level=DEBUG)
     public_address = unit_get('public-address')
-    print "public_address: ", public_address
+    juju_log("unit's public_address: {}".format(public_address), level=DEBUG)
     private_address = unit_get('private-address')
-    print "private_address: ", private_address
+    juju_log("unit's private_address: {}".format(private_address), level=DEBUG)
 
     # Update mongodb configuration file
     mongodb_config = mongodb_conf(config_data)
@@ -1009,6 +1012,7 @@ def config_changed():
     write_logrotate_config(config_data)
 
     # restart mongodb
+    status_set('maintenance', 'Restarting mongod')
     restart_mongod()
 
     # attach to replSet ( if needed )
@@ -1069,8 +1073,10 @@ def config_changed():
         open_port(config_data['mongos_port'])
 
     update_nrpe_config()
+    application_version_set(get_mongod_version())
+    update_status()
 
-    print "About to leave config_changed"
+    juju_log("About to leave config_changed", level=DEBUG)
     return(True)
 
 
@@ -1148,6 +1154,7 @@ def replica_set_relation_joined():
     if enable_replset(my_replset):
         juju_log('Restarting mongodb after config change (enable replset)',
                  level=DEBUG)
+        status_set('maintenance', 'Restarting mongod to enable replicaset')
         restart_mongod()
 
     relation_set(relation_id(), {
@@ -1157,6 +1164,8 @@ def replica_set_relation_joined():
         'install-order': my_install_order,
         'type': 'replset',
         })
+
+    update_status()
     juju_log("replica_set_relation_joined-finish")
 
 
@@ -1165,7 +1174,8 @@ def am_i_primary():
     for i in xrange(10):
         try:
             r = run_admin_command(c, 'replSetGetStatus')
-            juju_log('am_i_primary: replSetGetStatus returned: %s' % str(r),
+            pretty_r = pprint.pformat(r)
+            juju_log('am_i_primary: replSetGetStatus returned: %s' % pretty_r,
                      level=DEBUG)
             return r['myState'] == MONGO_PRIMARY
         except OperationFailure as e:
@@ -1180,7 +1190,7 @@ def am_i_primary():
                 # replication not initialized yet (Mongo3.4+)
                 return False
             elif 'not running with --replSet' in str(e):
-                # replicaset not configured 
+                # replicaset not configured
                 return False
             else:
                 raise
@@ -1191,6 +1201,56 @@ def am_i_primary():
     raise TimeoutException('Unable to determine if local unit is primary')
 
 
+def get_replicaset_status():
+    """Connect to mongod and get the status of replicaset
+    This function is used mainly within update_status() to display
+    replicaset status in 'juju status' output
+
+    :returns string: can be any of replicaset states
+        (https://docs.mongodb.com/manual/reference/replica-states/)
+        or can be the string of an exception while getting the status
+    """
+
+    c = MongoClient('localhost')
+    try:
+        r = run_admin_command(c, 'replSetGetStatus')
+        for member in r['members']:
+            if 'self' in member:
+                return member['stateStr']
+
+        # if 'self' was not found in the output, then log a warning and print
+        # the output given by replSetGetStatus
+        r_pretty = pprint.pformat(r)
+        juju_log('get_replicaset_status() failed to get replicaset state:' +
+                 r_pretty, level=WARNING)
+        return 'Unknown replica set state'
+
+    except OperationFailure as e:
+        juju_log('get_replicaset_status() exception: %s' % str(e), DEBUG)
+        if 'not running with --replSet' in str(e):
+            return 'not in replicaset'
+        else:
+            return str(e)
+
+def get_mongod_version():
+    """ Connects to mongod and get the db.version() output
+    Mainly used for application_set_version in config-changed hook
+    """
+
+    c = MongoClient('localhost')
+    return c.server_info()['version']
+
+
+# Retry until the replica set is in active state, retry 45 times before failing,
+# wait 1, 2, 3, 4, ... seconds between each retry, this will add 33 minutes of
+# accumulated sleep()
+@retry_on_exception(num_retries=45, base_delay=1)
+def wait_until_replset_is_active():
+    status = update_status()
+    if status != 'active':
+        raise Exception('ReplicaSet not active: {}'.format(status))
+
+
 @hooks.hook('replica-set-relation-changed')
 def replica_set_relation_changed():
     private_address = unit_get('private-address')
@@ -1208,6 +1268,7 @@ def replica_set_relation_changed():
     # Initialize the replicaset - we do this only on the leader!
     if is_leader():
         juju_log('Initializing replicaset')
+        status_set('maintenance', 'Initializing replicaset')
         init_replset()
 
     unit = "%s:%s" % (private_address, config('port'))
@@ -1218,9 +1279,11 @@ def replica_set_relation_changed():
         juju_log('Adding new secondary... %s' % unit_remote, level=DEBUG)
         join_replset(unit, unit_remote)
 
+    wait_until_replset_is_active()
     juju_log('replica_set_relation_changed-finish')
 
 
+
 @hooks.hook('replica-set-relation-departed')
 def replica_set_relation_departed():
     juju_log('replica_set_relation_departed-start')
@@ -1263,12 +1326,12 @@ def replica_set_relation_broken():
 
     c = MongoClient('localhost')
     r = c.admin.command('isMaster')
-    
+
     try:
         master_node = r['primary']
     except KeyError:
         pass
-    
+
     if 'master_node' in locals():  # unit is part of replicaset, remove it!
         unit = "%s:%s" % (unit_get('private-address'), config('port'))
         juju_log('Removing myself via %s' % (master_node), 'DEBUG')
@@ -1350,11 +1413,12 @@ def mongos_relation_changed():
     port = relation_get('port')
     rel_type = relation_get('type')
     if hostname is None or port is None or rel_type is None:
-        print("mongos_relation_changed: relation data not ready.")
+        juju_log("mongos_relation_changed: relation data not ready.",
+                 level=DEBUG)
         return
     if rel_type == 'configsvr':
         config_servers = load_config_servers(default_mongos_list)
-        print "Adding config server: %s:%s" % (hostname, port)
+        juju_log("Adding config server: %s:%s" % (hostname, port), level=DEBUG)
         if hostname is not None and \
            port is not None and \
            hostname != '' and \
@@ -1379,11 +1443,11 @@ def mongos_relation_changed():
             mongo_client(mongos_host, shard_command2)
 
     else:
-        print("mongos_relation_change: undefined rel_type: %s" %
-              rel_type)
+        juju_log("mongos_relation_change: undefined rel_type: %s" % rel_type,
+                 level=DEBUG)
         return
 
-    print("mongos_relation_changed returns: %s" % retVal)
+    juju_log("mongos_relation_changed returns: %s" % retVal, level=DEBUG)
 
 
 @hooks.hook('mongos-relation-broken')
@@ -1439,6 +1503,38 @@ def uprade_charm():
     remove_rest_from_upstart()
 
 
[e-mail]('update-status')
+def update_status():
+    """
+    Returns: workload_state (so that some hooks know they need to re-run
+    update_status if needed)
+    """
+
+    workload = 'active'
+    status = 'Unit is ready'
+
+    if is_relation_made('replica-set'):
+        # only check for replica-set state if the relation was made which means
+        # more than 1 units were deployed and peer related.
+        mongo_status = get_replicaset_status()
+        if mongo_status in ('PRIMARY', 'SECONDARY'):
+            workload = 'active'
+            status = 'Unit is ready as ' + mongo_status
+        elif mongo_status in ('not in replicaset',):
+            workload = 'active'
+            status = 'Unit is ready, ' + mongo_status
+        else:
+            workload = 'maintenance'
+            status = mongo_status
+            juju_log('mongo_status is unknown: {}'.format(status), level=DEBUG)
+
+    juju_log('Setting workload: {} - {}'.format(workload, status), level=DEBUG)
+    status_set(workload, status)
+
+    return workload
+
+
+
 def run(command, exit_on_error=True):
     '''Run a command and return the output.'''
     try:
diff --git a/hooks/update-status b/hooks/update-status
new file mode 120000
index 0000000..9416ca6
--- /dev/null
+++ b/hooks/update-status
@@ -0,0 +1 @@
+hooks.py
\ No newline at end of file
diff --git a/tests/base_deploy.py b/tests/base_deploy.py
index 8930966..b136cca 100644
--- a/tests/base_deploy.py
+++ b/tests/base_deploy.py
@@ -24,8 +24,6 @@ class BasicMongo(object):
             message = 'The environment did not setup in %d seconds.',
             self.deploy_timeout
             amulet.raise_status(amulet.SKIP, msg=message)
-        except:
-            raise
 
         self.sentry_dict = {svc: self.d.sentry[svc]
                             for svc in list(self.d.sentry.unit)}
diff --git a/tests/deploy_replicaset.py b/tests/deploy_replicaset.py
index 9506407..6fa0290 100644
--- a/tests/deploy_replicaset.py
+++ b/tests/deploy_replicaset.py
@@ -1,6 +1,8 @@
 #!/usr/bin/env python3
 
 import amulet
+import logging
+import re
 import sys
 import time
 import traceback
@@ -12,6 +14,7 @@ from base_deploy import BasicMongo
 
 # max amount of time to wait before testing for replicaset status
 wait_for_replicaset = 600
+logger = logging.getLogger(__name__)
 
 
 class Replicaset(BasicMongo):
@@ -109,6 +112,34 @@ class Replicaset(BasicMongo):
     def validate_running_services(self):
         super(Replicaset, self).validate_running_services()
 
+    def validate_workload_status(self):
+        primaries = 0
+        secondaries = 0
+        regex = re.compile('^Unit is ready as (PRIMARY|SECONDARY)$')
+        self.d.sentry.wait_for_messages({'mongodb': regex})
+
+        # count how many primaries and secondaries were reported in the
+        # workload status
+        for unit_name, unit in self.d.sentry.get_status()['mongodb'].items():
+            workload_msg = unit['workload-status']['message']
+            matched = re.match(regex, workload_msg)
+
+            if not matched:
+                msg = "'{}' does not match '{}'".format(workload_msg, regex)
+                amulet.raise_status(amulet.FAIL, msg=msg)
+            elif matched.group(1) == 'PRIMARY':
+                primaries += 1
+            elif matched.group(1) == 'SECONDARY':
+                secondaries += 1
+            else:
+                amulet.raise_status(amulet.FAIL,
+                                    msg='Unknown state: %s' % matched.group(1))
+
+        logger.debug('Secondary units found: %d' % secondaries)
+        if primaries > 1:
+            msg = "Found %d primaries, expected 1" % primaries
+            amulet.raise_status(amulet.FAIL, msg=msg)
+
     def run(self):
         self.deploy()
         self.validate_status_interface()
@@ -116,3 +147,4 @@ class Replicaset(BasicMongo):
         self.validate_replicaset_setup()
         self.validate_replicaset_relation_joined()
         self.validate_world_connectivity()
+        self.validate_workload_status()
diff --git a/unit_tests/test_hooks.py b/unit_tests/test_hooks.py
index 603b149..354d104 100644
--- a/unit_tests/test_hooks.py
+++ b/unit_tests/test_hooks.py
@@ -36,19 +36,24 @@ class MongoHooksTest(CharmTestCase):
         self.config.side_effect = self.test_config.get
         self.relation_get.side_effect = self.test_relation.get
 
+    @patch.object(hooks, 'is_relation_made')
+    @patch.object(hooks, 'get_replicaset_status')
     @patch.object(hooks, 'restart_mongod')
     @patch.object(hooks, 'enable_replset')
     # Note: patching the os.environ dictionary in-line here so there's no
     # additional parameter sent into the function
     @patch.dict('os.environ', JUJU_UNIT_NAME='fake-unit/0')
     def test_replica_set_relation_joined(self, mock_enable_replset,
-                                         mock_restart):
+                                         mock_restart, mock_get_replset_status,
+                                         mock_is_rel_made):
         self.unit_get.return_value = 'private.address'
         self.test_config.set('port', '1234')
         self.test_config.set('replicaset', 'fake-replicaset')
         self.relation_id.return_value = 'fake-relation-id'
 
         mock_enable_replset.return_value = False
+        mock_get_replset_status.return_value = 'PRIMARY'
+        mock_is_rel_made.return_value = True
 
         hooks.replica_set_relation_joined()
 
@@ -276,17 +281,24 @@ class MongoHooksTest(CharmTestCase):
         mock_subprocess.assert_called_once_with(expected_cmd, shell=True)
         self.assertFalse(rv)
 
+    @patch.object(hooks, 'is_relation_made')
+    @patch.object(hooks, 'run_admin_command')
+    @patch.object(hooks, 'is_leader')
+    @patch.object(hooks, 'get_replicaset_status')
     @patch.object(hooks, 'am_i_primary')
     @patch.object(hooks, 'init_replset')
     @patch.object(hooks, 'relation_get')
     @patch.object(hooks, 'peer_units')
-    @patch.object(hooks, 'oldest_peer')
     @patch.object(hooks, 'join_replset')
     @patch.object(hooks, 'unit_get')
     def test_replica_set_relation_changed(self, mock_unit_get,
-                                          mock_join_replset, mock_oldest_peer,
-                                          mock_peer_units, mock_relation_get,
-                                          mock_init_replset, mock_is_primary):
+                                          mock_join_replset, mock_peer_units,
+                                          mock_relation_get, mock_init_replset,
+                                          mock_is_primary,
+                                          mock_get_replset_status,
+                                          mock_is_leader,
+                                          mock_run_admin_cmd,
+                                          mock_is_rel_made):
         # set the unit_get('private-address')
         mock_unit_get.return_value = 'juju-local-unit-0.local'
         mock_relation_get.return_value = None
@@ -298,6 +310,10 @@ class MongoHooksTest(CharmTestCase):
         # Test remote hostname is valid, but master is somehow not defined
         mock_join_replset.reset_mock()
         mock_relation_get.return_value = 'juju-local-unit-0'
+        mock_is_leader.return_value = False
+        mock_run_admin_cmd.return_value = {'myState': hooks.MONGO_PRIMARY}
+        mock_get_replset_status.return_value = 'PRIMARY'
+        mock_is_rel_made.return_value = True
 
         hooks.replica_set_relation_changed()
 
@@ -306,9 +322,7 @@ class MongoHooksTest(CharmTestCase):
         # Test when not oldest peer, don't init replica set
         mock_join_replset.reset_mock()
         mock_init_replset.reset_mock()
-        mock_oldest_peer.reset_mock()
         mock_peer_units.return_value = ['mongodb/1', 'mongodb/2']
-        mock_oldest_peer.return_value = False
 
         hooks.replica_set_relation_changed()
 
@@ -317,8 +331,6 @@ class MongoHooksTest(CharmTestCase):
         # Test when its also the PRIMARY
         mock_relation_get.reset_mock()
         mock_relation_get.side_effect = ['juju-remote-unit-0', '12345']
-        mock_oldest_peer.reset_mock()
-        mock_oldest_peer.return_value = False
         mock_is_primary.reset_mock()
         mock_is_primary.return_value = True
         mock_join_replset.reset_mock()