diff --git a/python-modules/cis_publisher/cis_publisher/hris.py b/python-modules/cis_publisher/cis_publisher/hris.py index e4f3de06..e9f3938a 100644 --- a/python-modules/cis_publisher/cis_publisher/hris.py +++ b/python-modules/cis_publisher/cis_publisher/hris.py @@ -1,14 +1,14 @@ -import cis_profile -import cis_publisher -import boto3 -import botocore import os import logging import json import time -import requests from datetime import datetime, timezone, timedelta from traceback import format_exc +import cis_profile +import cis_publisher +import boto3 +import botocore +import requests logger = logging.getLogger(__name__) @@ -43,7 +43,7 @@ def get_s3_cache(self): response = s3.get_object(Bucket=bucket, Key="cache.json") data = response["Body"].read() except botocore.exceptions.ClientError as e: - logger.error("Could not find S3 cache file: {}".format(e)) + logger.error("Could not find S3 cache file: %s", e) return None logger.info("Using S3 cache") return json.loads(data) @@ -70,7 +70,7 @@ def publish(self, user_ids=None, chunk_size=30): le = "All" else: le = len(user_ids) - logger.info("Starting HRIS Publisher [{} users]".format(le)) + logger.info("Starting HRIS Publisher [%s users]", le) cache = self.get_s3_cache() # Get access to the known_users function first @@ -117,7 +117,7 @@ def deactivate_users(self, publisher, profiles, report): current_user_id = publisher.known_cis_users_by_email[hruser_work_email] except KeyError: logger.critical( - "Repeated: There is no user_id in CIS Person API for HRIS User:{}".format(hruser_work_email) + "Repeated: There is no user_id in CIS Person API for HRIS User:%s", hruser_work_email ) continue user_ids_in_hris.append(current_user_id) @@ -136,9 +136,8 @@ def deactivate_users(self, publisher, profiles, report): profile = profile.as_dict() except (TypeError, AttributeError) as e: logger.debug( - "Failed dictionary conversion for user {} (ignoring, using raw profile) error: {}".format( + "Failed dictionary conversion for user %s (ignoring, using raw profile) error: %s", potential_user_id, e - ) ) # If this fail, be verbose here profile = profile["profile"] @@ -150,7 +149,7 @@ def deactivate_users(self, publisher, profiles, report): except KeyError: logger.debug( "staff_information.staff or access_information.ldap fields are null," - " won't deactivate {}".format(potential_user_id) + " won't deactivate %s", potential_user_id ) continue @@ -161,10 +160,10 @@ def deactivate_users(self, publisher, profiles, report): if len(user_ids_to_deactivate) > 0: logger.info( - "Will deactivate {} users because they're in CIS but not in HRIS".format(user_ids_to_deactivate) + "Will deactivate %s users because they're in CIS but not in HRIS", user_ids_to_deactivate ) for user in user_ids_to_deactivate: - logger.info("User selected for deactivation: {}".format(user)) + logger.info("User selected for deactivation: %s", user) # user from cis try: p = cis_profile.User(publisher.known_profiles[self.hkey][user]["profile"]).as_dict() @@ -181,10 +180,10 @@ def deactivate_users(self, publisher, profiles, report): newp.sign_attribute("active", publisher_name="hris") except Exception as e: logger.critical( - "Profile data signing failed for user {} - skipped signing, verification " - "WILL FAIL ({})".format(newp.primary_email.value, e) + "Profile data signing failed for user %s - skipped signing, verification " + "WILL FAIL (%s)", newp.primary_email.value, e ) - logger.debug("Profile data {}".format(newp.as_dict())) + logger.debug("Profile data %s", newp.as_dict()) profiles.append(newp) return profiles @@ -202,18 +201,18 @@ def process(self, publisher, user_ids): profiles = self.deactivate_users(publisher, profiles, report_profiles) del report_profiles - logger.info("Processing {} profiles".format(len(profiles))) + logger.info("Processing %s profiles", len(profiles)) publisher.profiles = profiles failures = [] try: failures = publisher.post_all(user_ids=user_ids) except Exception as e: - logger.error("Failed to post_all() HRIS profiles. Trace: {}".format(format_exc())) + logger.error("Failed to post_all() HRIS profiles. Trace: %s", format_exc()) raise e if len(failures) > 0: - logger.error("Failed to post {} profiles: {}".format(len(failures), failures)) + logger.error("Failed to post %s profiles: %s", len(failures), failures) def fan_out(self, publisher, chunk_size): """ @@ -231,18 +230,33 @@ def fan_out(self, publisher, chunk_size): report_profiles = self.fetch_report() for u in report_profiles.get("Report_Entry"): + email_from_hris_report = u.get("PrimaryWorkEmail") try: - all_user_ids.append(publisher.known_cis_users_by_email[u.get("PrimaryWorkEmail")]) + found_user = publisher.known_cis_users_by_email[email_from_hris_report] except KeyError: - logger.critical( - "There is no user_id in CIS Person API for HRIS User {}." - "This user may not be created in HRIS yet?".format(u.get("PrimaryWorkEmail")) - ) - continue + lowered_email_from_hris_report = email_from_hris_report.lower() + try: + found_user = publisher.known_cis_users_by_email[lowered_email_from_hris_report] + except KeyError: + # Couldn't find by 'regular' or 'lowercase', we're done. + logger.critical( + "There is no user_id in CIS Person API for HRIS User %s." + "This user may not be created in HRIS yet?", email_from_hris_report + ) + continue + else: + # Found by 'lowercase'. + logger.warning( + "There is no user_id in CIS for HRIS User %s, but we " + "found a match by match by lowercasing their email. " + "Take this up with HR Ops for cleanliness." + ) + # Fallthrough since the 'except' saved us. + all_user_ids.append(found_user) sliced = [all_user_ids[i : i + chunk_size] for i in range(0, len(all_user_ids), chunk_size)] logger.info( - "No user_id selected. Creating slices of work, chunck size: {}, slices: {}, total users: {} and " - "faning-out work to self".format(chunk_size, len(sliced), len(all_user_ids)) + "No user_id selected. Creating slices of work, chunck size: %s, slices: %s, total users: %s and " + "faning-out work to self", chunk_size, len(sliced), len(all_user_ids) ) lambda_client = boto3.client("lambda") for s in sliced: @@ -264,8 +278,8 @@ def fetch_report(self): hris_username = self.secret_manager.secret("hris_user") hris_password = self.secret_manager.secret("hris_password") - logger.info("Fetching HRIS report from {}".format(hris_url)) - params = dict(format="json") + logger.info("Fetching HRIS report from %s", hris_url) + params = {"format": "json"} if os.environ.get("CIS_ENVIRONMENT") == "development": logger.debug("Dev environment, not using credentials") @@ -278,9 +292,8 @@ def fetch_report(self): if not res.ok: logger.error( - "Error fetching the HRIS report, status_code: {}, reason: {}, text: {}".format( + "Error fetching the HRIS report, status_code: %s, reason: %s, text: %s", res.status_code, res.reason, res.text - ) ) raise ValueError("Could not fetch HRIS report") self.report = res.json() @@ -362,7 +375,7 @@ def tz_convert(hris_tz): tzmap[hris_tz] except KeyError: logger.warning( - "Unknown timezone in workday, defaulting to UTC. Timezone from HRIS was" " {}.".format(hris_tz) + "Unknown timezone in workday, defaulting to UTC. Timezone from HRIS was %s.", hris_tz ) return "UTC+0000 Europe/London" return tzmap[hris_tz] @@ -381,7 +394,7 @@ def strbool_convert(v): user_array = [] for hruser in hris_data.get("Report_Entry"): hruser_work_email = hruser.get("PrimaryWorkEmail").lower() - logger.debug("filtering fields for user email {}".format(hruser_work_email)) + logger.debug("filtering fields for user email %s", hruser_work_email) # NOTE: # The HRIS setup will DELETE users when they need to be deactivated and removed. It will set INACTIVE when @@ -390,9 +403,8 @@ def strbool_convert(v): hruser_active_state = int(hruser.get("CurrentlyActive")) if hruser_active_state == 0: logger.debug( - "User {} is currently set to inactive in HRIS Report, skipping integration".format( + "User %s is currently set to inactive in HRIS Report, skipping integration", hruser_work_email - ) ) continue @@ -401,15 +413,15 @@ def strbool_convert(v): current_user_id = cis_users_by_email[hruser_work_email] except KeyError: logger.critical( - "There is no user_id in CIS Person API for HRIS User {}." - " This user may not be created by HRIS yet?".format(hruser_work_email) + "There is no user_id in CIS Person API for HRIS User %s." + " This user may not be created by HRIS yet?", hruser_work_email ) continue user_ids_lower_case = [x.lower() for x in user_ids] if current_user_id.lower() not in user_ids_lower_case: # Skip this user, it's not in the list requested to convert - logger.debug("skipping user {}, not in requested conversion list".format(current_user_id)) + logger.debug("skipping user %s, not in requested conversion list", current_user_id) continue p = cis_profile.User() @@ -496,28 +508,28 @@ def strbool_convert(v): p.sign_all(publisher_name="hris") except Exception as e: logger.critical( - "Profile data signing failed for user {} - skipped signing, verification " - "WILL FAIL ({})".format(p.primary_email.value, e) + "Profile data signing failed for user %s - skipped signing, verification " + "WILL FAIL (%s)", p.primary_email.value, e ) - logger.debug("Profile data {}".format(p.as_dict())) + logger.debug("Profile data %s", p.as_dict()) try: p.validate() except Exception as e: logger.critical( - "Profile schema validation failed for user {} - skipped validation, verification " - "WILL FAIL({})".format(p.primary_email.value, e) + "Profile schema validation failed for user %s - skipped validation, verification " + "WILL FAIL(%s)", p.primary_email.value, e ) - logger.debug("Profile data {}".format(p.as_dict())) + logger.debug("Profile data %s", p.as_dict()) try: p.verify_all_publishers(cis_profile.User()) except Exception as e: logger.critical( - "Profile publisher verification failed for user {} - skipped signing, verification " - "WILL FAIL ({})".format(p.primary_email.value, e) + "Profile publisher verification failed for user %s - skipped signing, verification " + "WILL FAIL (%s)", p.primary_email.value, e ) - logger.debug("Profile data {}".format(p.as_dict())) + logger.debug("Profile data %s", p.as_dict()) - logger.info("Processed (signed and verified) HRIS report's user {}".format(p.primary_email.value)) + logger.info("Processed (signed and verified) HRIS report's user %s", p.primary_email.value) user_array.append(p) return user_array