fix #2: implement logging on all keystone actions

deNBI · Sep 4, 2018 · ef22674 · ef22674
1 parent a9ead09
commit ef22674
Show file tree

Hide file tree

Showing 4 changed files with 41 additions and 7 deletions.
diff --git a/denbi/bielefeld/perun/endpoint.py b/denbi/bielefeld/perun/endpoint.py
@@ -1,6 +1,10 @@
 import json
+import logging
+
 from denbi.bielefeld.perun.keystone import KeyStone
 
+log = logging.getLogger(__name__)
+
 
 def import_json(path):
     with open(path, 'r') as json_file:
@@ -45,6 +49,7 @@ def import_data(self, users_path, groups_path):
         :return:
         '''
 
+        log.info("Importing data mode=%s users_path=%s groups_path=%s", self.mode, users_path, groups_path)
         if self.mode == "scim":
             self.__import_scim_userdata__(import_json(users_path))
             self.__import_scim_projectdata__(import_json(groups_path))
@@ -86,10 +91,12 @@ def __import_scim_userdata__(self, json_obj):
                             user['email'] == email and
                             user['enabled'] == enabled):
                         # update user
+                        log.info("Updating user %s elixir_id=%s email=%s enabled=%s", perun_id, elixir_id, email, enabled)
                         self.keystone.users_update(perun_id, elixir_id=elixir_id, email=email, enabled=enabled)
 
                 else:
                     # register user in keystone
+                    log.info("Creating user %s elixir_id=%s email=%s, enabled=%s", perun_id, elixir_id, email, enabled)
                     self.keystone.users_create(elixir_id, perun_id, email=email, enabled=enabled)
 
                 # add perun_id to temporary list
@@ -103,6 +110,7 @@ def __import_scim_userdata__(self, json_obj):
         del_users = set(user_ids) ^ set(user_map.keys())
 
         for id in del_users:
+            log.info("Deleting user %s", id)
             self.keystone.users_delete(id)
 
     def __import_scim_projectdata__(self, json_obj):
@@ -127,8 +135,10 @@ def __import_scim_projectdata__(self, json_obj):
                     project = project_map[perun_id]
 
                     if set(project['members']) != set(members):
+                        log.info("Updating project %s with {%s}", perun_id, ','.join(members))
                         self.keystone.projects_update(perun_id, members)
                 else:
+                    log.info("Creating project %s with name=%s members={%s}", perun_id, name, ','.join(members))
                     self.keystone.projects_create(perun_id, name=name, members=members)
 
                 project_ids.append(perun_id)
@@ -140,6 +150,7 @@ def __import_scim_projectdata__(self, json_obj):
         del_projects = set(project_ids) ^ set(project_map.keys())
 
         for id in del_projects:
+            log.info("Deleting project %s", id)
             self.keystone.projects_delete(id)
 
     def __import_dpcc_userdata__(self, json_obj):
@@ -168,9 +179,11 @@ def __import_dpcc_userdata__(self, json_obj):
                             user['email'] == email and
                             user['enabled'] == enabled):
                         # update user
+                        log.info("Updating user %s elixir_id=%s email=%s enabled=%s", perun_id, elixir_id, email, enabled)
                         self.keystone.users_update(perun_id, elixir_id, email, enabled)
                 else:
                     # register user in keystone
+                    log.info("Creating user %s elixir_id=%s email=%s, enabled=%s", perun_id, elixir_id, email, enabled)
                     self.keystone.users_create(elixir_id, perun_id, email=email, enabled=enabled)
 
                 # add perun_id to temporary list
@@ -183,6 +196,7 @@ def __import_dpcc_userdata__(self, json_obj):
         del_users = set(user_ids) ^ set(user_map.keys())
 
         for id in del_users:
+            log.info("Deleting user %s", id)
             self.keystone.users_delete(id)
 
     def __import_dpcc_projectdata__(self, json_obj):
@@ -217,6 +231,7 @@ def __import_dpcc_projectdata__(self, json_obj):
                     if set(project['members']) != set(members) or \
                             project['name'] != name or \
                             'description' in project and project['description'] != description:
+                        log.info("Updating project %s with {%s}", perun_id, ','.join(members))
                         self.keystone.projects_update(perun_id, members)
 
                     # check for quotas and update it if possible
@@ -231,15 +246,20 @@ def __import_dpcc_projectdata__(self, json_obj):
                         )
 
                         if any(modified):
+                            log.info("Updating quota vms=%s disk=%s hardware=%s ram=%s os=%s", number_of_vms, disk_space, special_purpose_hardware, ram_per_vm, object_storage)
                             self.keystone.project_quota(number_of_vms=number_of_vms,
                                                         disk_space=disk_space,
                                                         special_purpose_hardware=special_purpose_hardware,
                                                         ram_per_vm=ram_per_vm,
                                                         object_storage=object_storage)
+                        else:
+                            log.debug("Quota unchanged")
 
                 else:
+                    log.info("Creating project %s with name=%s members={%s}", perun_id, name, ','.join(members))
                     self.keystone.projects_create(perun_id, name=name, description=description, members=members)
                     if self.support_quotas:
+                        log.info("Setting quota vms=%s disk=%s hardware=%s ram=%s os=%s", number_of_vms, disk_space, special_purpose_hardware, ram_per_vm, object_storage)
                         self.keystone.project_quota(number_of_vms=number_of_vms,
                                                     disk_space=disk_space,
                                                     special_purpose_hardware=special_purpose_hardware,
@@ -254,4 +274,5 @@ def __import_dpcc_projectdata__(self, json_obj):
         del_projects = set(project_ids) ^ set(project_map.keys())
 
         for id in del_projects:
+            log.info("Deleting project %s", id)
             self.keystone.projects_delete(id)
diff --git a/denbi/scripts/perun_propagation.py b/denbi/scripts/perun_propagation.py
@@ -1,26 +1,29 @@
 #!/usr/bin/env python
-import tarfile
 import argparse
+import logging
+import tarfile
 import tempfile
 
 from denbi.bielefeld.perun.endpoint import Endpoint
 from denbi.bielefeld.perun.keystone import KeyStone
 
+logging.basicConfig(level=logging.WARN)
+
 
 def process_tarball(tarball_path, read_only=False):
     directory = tempfile.TemporaryDirectory()
 
     # extract tar file
     tar = tarfile.open(tarball_path, "r:gz")
-    tar.extractall(path=directory)
+    tar.extractall(path=directory.name)
     tar.close()
 
     # import into keystone
     keystone = KeyStone(default_role="user", create_default_role=True,
                         support_quotas=False, target_domain_name='elixir', read_only=read_only)
     endpoint = Endpoint(keystone=keystone, mode="denbi_portal_compute_center",
                         support_quotas=False)
-    endpoint.import_data(directory + '/users.scim', directory + '/groups.scim')
+    endpoint.import_data(directory.name + '/users.scim', directory.name + '/groups.scim')
 
     # Cleanup
     directory.cleanup()
@@ -30,9 +33,15 @@ def main():
     parser = argparse.ArgumentParser(description='Process perun tarball')
     parser.add_argument('tarball', type=argparse.FileType('r'), help="Input tarball from perun")
     parser.add_argument('--read-only', action='store_true', help="Do not make any modifications to keystone")
+    parser.add_argument("-v", "--verbose", dest="verbose_count",
+                        action="count", default=0, help="increases log verbosity for each occurence.")
     args = parser.parse_args()
 
-    process_tarball(args.tarball, read_only=args.read_only)
+    # Defaults to WARN, with every added -v it goes to INFO then DEBUG
+    log_level = max(3 - args.verbose_count, 1) * 10
+    logging.getLogger('denbi').setLevel(log_level)
+
+    process_tarball(args.tarball.name, read_only=args.read_only)
 
 
 if __name__ == '__main__':

diff --git a/denbi/scripts/perun_propagation_service.py b/denbi/scripts/perun_propagation_service.py
@@ -20,15 +20,15 @@ def process_tarball(tarball_path, read_only=False):
 
     # extract tar file
     tar = tarfile.open(tarball_path, "r:gz")
-    tar.extractall(path=directory)
+    tar.extractall(path=directory.name)
     tar.close()
 
     # import into keystone
     keystone = KeyStone(default_role="user", create_default_role=True,
                         support_quotas=False, target_domain_name='elixir', read_only=read_only)
     endpoint = Endpoint(keystone=keystone, mode="denbi_portal_compute_center",
                         support_quotas=False)
-    endpoint.import_data(directory + '/users.scim', directory + '/groups.scim')
+    endpoint.import_data(directory.name + '/users.scim', directory.name + '/groups.scim')
     app.logging.info("Finished processing %s", tarball_path)
 
     # Cleanup
@@ -48,7 +48,7 @@ def upload():
     file.close()
 
     # parse propagated data in separate thread
-    t = Thread(target=_perun_propagation, args=(file,), kwargs={'read_only': app.config.get('keystone_read_only', False)})
+    t = Thread(target=_perun_propagation, args=(file.name,), kwargs={'read_only': app.config.get('keystone_read_only', False)})
     t.start()
 
     # return immediately

diff --git a/test/test_keystone.py b/test/test_keystone.py
@@ -1,8 +1,12 @@
 import unittest
 import uuid
+import logging  # NOQA
 
 from denbi.bielefeld.perun.keystone import KeyStone
 
+# If you want detailed logs of what is going on, uncomment this.
+# logging.basicConfig(level=logging.INFO)
+
 
 class TestKeystone(unittest.TestCase):
     """