Merge pull request #598 from vossen-adobe/log_sync_progress

Add logging for user actions and umapi progress

Author: adorton-adobe

examples/config files - basic/user-sync-config.yml

@@ -285,6 +285,13 @@ logging:
   # See the description of file_log_level for details of the allowed values.
   console_log_level: info
 
+  # (optional) log_progress (default value True)
+  # Includes an indication of progress for user actions on the umapi
+  # Useful for tracking sync progress for pulling down, creating,
+  # or updating large numbers of users
+  # eg: 71/100 (71.0%) match output from console
+  log_progress: True
+
 # The invocation_defaults section controls the default values used
 # for command-line arguments.  (Of course, these cannot be used to
 # change defaults for how the configuration files are read.)  This

user_sync/app.py

@@ -310,12 +310,24 @@ def init_log(logging_config):
     """
     :type logging_config: user_sync.config.DictConfig
     """
+
+    def progress(self, count, total, message="", *args, **kws):
+        if self.show_progress:
+            count = int(count)
+            total = int(total)
+            percent_done = round(100*count/total, 1) if total > 0 else 0
+            message = "{0}/{1} ({2}%) {3}".format(count, total, percent_done, message)
+        if message:
+            self._log(logging.INFO, message, args, **kws)
+    logging.Logger.progress = progress
+
     builder = user_sync.config.OptionsBuilder(logging_config)
     builder.set_bool_value('log_to_file', False)
     builder.set_string_value('file_log_directory', 'logs')
     builder.set_string_value('file_log_name_format', '{:%Y-%m-%d}.log')
     builder.set_string_value('file_log_level', 'info')
     builder.set_string_value('console_log_level', 'info')
+    builder.set_bool_value('log_progress', True)
     options = builder.get_options()
 
     level_lookup = {
@@ -326,6 +338,7 @@ def init_log(logging_config):
         'critical': logging.CRITICAL
     }
 
+    logging.Logger.show_progress = bool(options['log_progress'])
     console_log_level = level_lookup.get(options['console_log_level'])
     if console_log_level is None:
         console_log_level = logging.INFO

user_sync/connector/umapi.py

@@ -21,6 +21,7 @@
 import json
 import logging
 # import helper
+import math
 
 import jwt
 import six
@@ -113,16 +114,23 @@ def get_users(self):
 
     def iter_users(self, in_group=None):
         users = {}
+        total_count = 0
+        page_count = 0
+        page_size = 0
+        page_number = 0
         try:
-            if in_group:
-                u_query = umapi_client.UsersQuery(self.connection, in_group=in_group)
-            else:
-                u_query = umapi_client.UsersQuery(self.connection)
-            for u in u_query:
+            u_query = umapi_client.UsersQuery(self.connection, in_group=in_group)
+            for i, u in enumerate(u_query):
+                total_count, page_count, page_size, page_number = u_query.stats()
                 email = u['email']
                 if not (email in users):
                     users[email] = u
                     yield u
+
+                if (i + 1) % page_size == 0:
+                    self.logger.progress(len(users), total_count)
+            self.logger.progress(total_count, total_count)
+
         except umapi_client.UnavailableError as e:
             raise AssertionException("Error contacting UMAPI server: %s" % e)
 

user_sync/post_sync/manager.py

@@ -83,7 +83,7 @@ def remove_umapi_user_groups(self, org_id, user_key):
 
     def remove_umapi_user(self, org_id, user_key):
         umapi_data = self.umapi_data.get(org_id)
-        if user_key not in umapi_data:
+        if not umapi_data or user_key not in umapi_data:
             return
         del umapi_data[user_key]
 

user_sync/rules.py

@@ -485,11 +485,19 @@ def sync_umapi_users(self, umapi_connectors):
         else:
             primary_adds_by_user_key = self.update_umapi_users_for_connector(umapi_info, umapi_connector)
         # save groups for new users
+
+        total_users = len(primary_adds_by_user_key)
+
+        user_count = 0
         for user_key, groups_to_add in six.iteritems(primary_adds_by_user_key):
+            user_count += 1
             if exclude_unmapped_users and not groups_to_add:
                 # If user is not part of any group and ignore outcast is enabled. Do not create user.
                 continue
             # We always create every user in the primary umapi, because it's believed to own the directories.
+            if user_count % 10 == 0:
+                self.logger.progress(user_count, total_users, 'actions completed')
+            self.primary_users_created.add(user_key)
             self.create_umapi_user(user_key, groups_to_add, umapi_info, umapi_connector)
 
         # then sync the secondary connectors
@@ -502,9 +510,13 @@ def sync_umapi_users(self, umapi_connectors):
                 secondary_adds_by_user_key = umapi_info.get_desired_groups_by_user_key()
             else:
                 secondary_adds_by_user_key = self.update_umapi_users_for_connector(umapi_info, umapi_connector)
+            total_users = len(secondary_adds_by_user_key)
             for user_key, groups_to_add in six.iteritems(secondary_adds_by_user_key):
                 # We only create users who have group mappings in the secondary umapi
                 if groups_to_add:
+                    self.logger.progress(user_count, total_users,
+                                         'Adding user to umapi {0} with user key: {1}'.format(umapi_name, user_key))
+                    self.secondary_users_created.add(user_key)
                     if user_key not in self.primary_users_created:
                         # We pushed an existing user to a secondary in order to update his groups
                         self.updated_user_keys.add(user_key)
@@ -617,7 +629,7 @@ def manage_strays(self, umapi_connectors):
 
         # all our processing is controlled by the strays in the primary organization
         primary_strays = self.get_stray_keys()
-        self.action_summary['primary_strays_processed'] = len(primary_strays)
+        self.action_summary['primary_strays_processed'] = total_strays = len(primary_strays)
 
         # convenience function to get umapi Commands given a user key
         def get_commands(key):
@@ -661,15 +673,16 @@ def get_commands(key):
 
         # finish with the primary umapi
         primary_connector = umapi_connectors.get_primary_connector()
-        for user_key in primary_strays:
+        for i, user_key in enumerate(primary_strays):
+            per = round(100*(float(i)/float(total_strays)),3)
             commands = get_commands(user_key)
             if disentitle_strays:
                 self.logger.info('Removing all adobe groups for Adobe-only user: %s', user_key)
                 self.post_sync_data.remove_umapi_user_groups(None, user_key)
                 commands.remove_all_groups()
             elif remove_strays or delete_strays:
                 action = "Deleting" if delete_strays else "Removing"
-                self.logger.info('%s Adobe-only user: %s', action, user_key)
+                self.logger.info('(%s/%s)(%s%%) %s Adobe-only user: %s', i, total_strays, per, action, user_key)
                 self.post_sync_data.remove_umapi_user(None, user_key)
                 commands.remove_from_org(True if delete_strays else False)
             elif manage_stray_groups: