diff --git a/services/managers/discord_manager.py b/services/managers/discord_manager.py index 1f4d3f29..03509c6c 100644 --- a/services/managers/discord_manager.py +++ b/services/managers/discord_manager.py @@ -14,29 +14,12 @@ DISCORD_URL = "https://discordapp.com/api" class DiscordAPIManager: def __init__(self, server_id, email, password): -# data = { -# "email" : email, -# "password": password, -# } -# custom_headers = {'content-type':'application/json'} -# path = DISCORD_URL + "/auth/login" -# r = requests.post(path, headers=custom_headers, data=json.dumps(data)) -# r.raise_for_status() self.token = DiscordAPIManager.get_token_by_user(email, password) self.email = email self.password = password self.server_id = server_id logger.debug("Initialized DiscordAPIManager with server id %s" % self.server_id) - def __del__(self): - if hasattr(self, 'token'): - if self.token and self.token != "": - data = {'token': self.token} - path = DISCORD_URL + "/auth/logout" - custom_headers = {'content-type':'application/json'} - r = requests.post(path, headers=custom_headers, data=json.dumps(data)) - r.raise_for_status() - @staticmethod def validate_token(token): custom_headers = {'accept': 'application/json', 'authorization': token} @@ -102,6 +85,7 @@ class DiscordAPIManager: custom_headers = {'authorization': self.token} path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/bans/" + str(user_id) + "?delete-message-days=" + str(delete_message_age) r = requests.put(path, headers=custom_headers) + logger.debug("Received status code %s after banning user %s" % (r.status_code, user_id)) r.raise_for_status() def unban_user(self, user_id): @@ -345,7 +329,7 @@ class DiscordManager: except: logger.debug("Group id retrieval generated exception - generating new group on discord server.", exc_info=True) group_ids.append(DiscordManager.create_group(g)) - logger.debug("Setting groups for user %s to %s" % (user_id, group_ids)) + logger.info("Setting discord groups for user %s to %s" % (user_id, group_ids)) api.set_roles(user_id, group_ids) @staticmethod @@ -356,6 +340,7 @@ class DiscordManager: logger.debug("Created new role on server with id %s: %s" % (new_group['id'], new_group)) named_group = api.edit_role(new_group['id'], groupname) logger.debug("Renamed group id %s to %s" % (new_group['id'], groupname)) + logger.info("Created new group on discord server with name %s" % groupname) return named_group['id'] @staticmethod @@ -402,7 +387,7 @@ class DiscordManager: token = DiscordAPIManager.get_token_by_user(email, password) logger.debug("Got auth token for supplied credentials beginning with %s" % token[0:5]) DiscordAPIManager.accept_invite(invite_code, token) - logger.debug("Added user to server with id %s" % user_id) + logger.info("Added user to discord server %s with id %s" % (settings.DISCORD_SERVER_ID, user_id)) return user_id except: logger.exception("An unhandled exception has occured.", exc_info=True) @@ -411,9 +396,11 @@ class DiscordManager: @staticmethod def delete_user(user_id): try: + logger.debug("Deleting user with id %s from discord server." % user_id) api = DiscordAPIManager(settings.DISCORD_SERVER_ID, settings.DISCORD_USER_EMAIL, settings.DISCORD_USER_PASSWORD) DiscordManager.update_groups(user_id, []) api.ban_user(user_id) + logger.info("Deleted user with id %s from discord server id %s" % (user_id, settings.DISCORD_SERVER_ID)) return True except: return False diff --git a/services/managers/eve_api_manager.py b/services/managers/eve_api_manager.py index 498feea1..455494fe 100644 --- a/services/managers/eve_api_manager.py +++ b/services/managers/eve_api_manager.py @@ -4,6 +4,9 @@ import evelink.eve from django.conf import settings +import logging + +logger = logging.getLogger(__name__) class EveApiManager(): def __init__(self): @@ -12,44 +15,51 @@ class EveApiManager(): @staticmethod def get_characters_from_api(api_id, api_key): chars = [] + logger.debug("Getting characters from api id %s" % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) # Should get characters account = evelink.account.Account(api=api) chars = account.characters() except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.info("Retrieved characters %s from api id %s" % (chars, api_id)) return chars @staticmethod def get_corporation_ticker_from_id(corp_id): + logger.debug("Getting ticker for corp id %s" % corp_id) ticker = "" try: api = evelink.api.API() corp = evelink.corp.Corp(api) response = corp.corporation_sheet(corp_id) + logger.debug("Retrieved corp sheet for id %s: %s" % (corp_id, response)) ticker = response[0]['ticker'] except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.info("Determined corp id %s ticker: %s" % (corp_id, ticker)) return ticker @staticmethod def get_alliance_information(alliance_id): results = {} + logger.debug("Getting info for alliance with id %s" % alliance_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) alliance = eve.alliances() results = alliance[0][int(alliance_id)] except evelink.api.APIError as error: - print error - + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Got alliance info %s" % results) return results @staticmethod def get_corporation_information(corp_id): + logger.debug("Getting info for corp with id %s" % corp_id) results = {} try: api = evelink.api.API() @@ -57,171 +67,205 @@ class EveApiManager(): corpinfo = corp.corporation_sheet(corp_id=int(corp_id)) results = corpinfo[0] except evelink.api.APIError as error: - print error - + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Got corp info %s" % results) return results @staticmethod def check_api_is_type_account(api_id, api_key): + logger.debug("Checking if api id %s is account." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() + logger.debug("API id %s is type %s" % (api_id, info[0]['type'])) return info[0]['type'] == "account" except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False @staticmethod def check_api_is_full(api_id, api_key): + logger.debug("Checking if api id %s meets member requirements." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() - return info[0]['access_mask'] & settings.MEMBER_API_MASK == int(settings.MEMBER_API_MASK) + logger.debug("API has mask %s, required is %s." % (info[0]['access_mask'], settings.MEMBER_API_MASK) + return info[0]['access_mask'] & int(settings.MEMBER_API_MASK) == int(settings.MEMBER_API_MASK)) except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False @staticmethod def check_blue_api_is_full(api_id, api_key): + logger.debug("Checking if api id %s meets blue requirements." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() - return info[0]['access_mask'] & settings.BLUE_API_MASK == int(settings.BLUE_API_MASK) + logger.debug("API has mask %s, required is %s." % (info[0]['access_mask'], settings.BLUE_API_MASK) + return info[0]['access_mask'] & int(settings.BLUE_API_MASK) == int(settings.BLUE_API_MASK) except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) @staticmethod def get_api_info(api_id, api_key): + logger.debug("Getting api info for key id %s" % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() + logger.debug("Got info for api id %s: %s" % (api_id, info)) return info except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False @staticmethod def api_key_is_valid(api_id, api_key): + logger.debug("Checking if api id %s is valid." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() + logger.info("Verified api id %s is still valid." % api_id) return True except evelink.api.APIError as error: - return False + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.info("API id %s is invalid." % api_id) return False @staticmethod def check_if_api_server_online(): + logger.debug("Checkin if API server online.") try: api = evelink.api.API() server = evelink.server.Server(api=api) info = server.server_status() + logger.info("Verified API server is online and reachable.") return True except evelink.api.APIError as error: - return False + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.warn("Unable to reach API server.") return False @staticmethod def check_if_id_is_corp(corp_id): + logger.debug("Checking if id %s is a corp." % corp_id) try: api = evelink.api.API() corp = evelink.corp.Corp(api=api) corpinfo = corp.corporation_sheet(corp_id=int(corp_id)) results = corpinfo[0] + logger.info("Confirmed id %s is a corp." % corp_id) return True except evelink.api.APIError as error: - return False + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Unable to verify id %s is corp." % corp_id) return False @staticmethod def get_corp_standings(): if settings.CORP_API_ID != "": try: + logger.debug("Getting corp standings with api id %s" % settings.CORP_API_ID) api = evelink.api.API(api_key=(settings.CORP_API_ID, settings.CORP_API_VCODE)) corp = evelink.corp.Corp(api=api) corpinfo = corp.contacts() results = corpinfo[0] + logger.info("Got corp standings from settings: %s" % results) return results except evelink.api.APIError as error: - pass - + logger.exception("Unhandled APIError occured.", exc_info=True) + else: + logger.error("No corp API key supplied in settings. Unable to get standings.") return {} @staticmethod def check_if_id_is_alliance(alliance_id): + logger.debug("Checking if id %s is an alliance." % alliance_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) alliance = eve.alliances() results = alliance[0][int(alliance_id)] if results: + logger.info("Confirmed id %s is an alliance." % alliance_id) return True except evelink.api.APIError as error: - return False + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.info("Unable to verify id %s is an alliance." % alliance_id) return False @staticmethod def check_if_id_is_character(character_id): + logger.debug("Checking if id %s is a character." % character_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) results = eve.character_info_from_id(character_id) if results: + logger.info("Confirmed id %s is a character." % character_id) return True except evelink.api.APIError as error: - return False + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.info("Unable to verify id %s is a character." % character_id) return False @staticmethod def check_if_alliance_exists(alliance_id): + logger.debug("Checking if alliance id %s exists." % alliance_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) alliances = eve.alliances() if int(alliance_id) in alliances[0]: + logger.info("Verified alliance id %s exists." % alliance_id) return True else: + logger.info("Verified alliance id %s does not exist." % alliance_id) return False except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False except ValueError as error: #attempts to catch error resulting from checking alliance_of nonetype models - print error + logger.exception("Unhandled ValueError occured. Possible nonetype alliance model.", exc_info=True) return False + logger.warn("Exception prevented verification of alliance id %s existance. Assuming false." % alliance_id) return False @staticmethod def check_if_corp_exists(corp_id): + logger.debug("Checking if corp id %s exists." % corp_id) try: api = evelink.api.API() corp = evelink.corp.Corp(api=api) corpinfo = corp.corporation_sheet(corp_id=corp_id) if corpinfo[0]['members']['current'] > 0: + logger.info("Verified corp id %s exists with member count %s" % (corp_id, corpinfo[0]['members']['current'])) return True else: + logger.info("Verified corp id %s has closed. Member count %s" % (corp_id, corpinfo[0]['members']['current'])) return False except evelink.api.APIError as error: #could be smart and check for error code523 to verify error due to no corp instead of catch-all - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False + logger.warn("Exception prevented verification of corp id %s existance. Assuming false." % corp_id) return False diff --git a/services/managers/ipboard_manager.py b/services/managers/ipboard_manager.py index a85a146a..0ae66105 100755 --- a/services/managers/ipboard_manager.py +++ b/services/managers/ipboard_manager.py @@ -4,6 +4,9 @@ from hashlib import md5 from django.conf import settings +import logging + +logger = logging.getLogger(__name__) class IPBoardManager: def __init__(self): @@ -39,29 +42,35 @@ class IPBoardManager: def add_user(username, email): """ Add user to service """ sanatized = str(IPBoardManager.__santatize_username(username)) + logger.debug("Adding user to IPBoard with username %s" % sanatized) plain_password = IPBoardManager.__generate_random_pass() password = md5(plain_password).hexdigest() ret = IPBoardManager.exec_xmlrpc('createUser', username=sanatized, email=str(email), display_name=sanatized, md5_passwordHash=password) + logger.info("Added IPBoard user with username %s" % sanatized) return sanatized, plain_password @staticmethod def delete_user(username): """ Delete user """ ret = IPBoardManager.exec_xmlrpc('deleteUser', username=username) + logger.info("Deleted IPBoard user with username %s" % username) return username @staticmethod def disable_user(username): """ Disable user """ ret = IPBoardManager.exec_xmlrpc('disableUser', username=username) + logger.info("Disabled IPBoard user with username %s" % username) return username @staticmethod def update_user(username, email, password): """ Add user to service """ password = md5(password).hexdigest() + logger.debug("Updating IPBoard username %s with email %s and password hash starting with %s" % (username, email, password[0:5])) ret = IPBoardManager.exec_xmlrpc('updateUser', username=username, email=email, md5_passwordHash=password) + logger.info("Updated IPBoard user with username %s" % username) return username @staticmethod @@ -70,6 +79,7 @@ class IPBoardManager: ret = IPBoardManager.exec_xmlrpc('getAllGroups') for group in ret: groups.append(group["g_title"]) + logger.info("Retrieved group list from IPBoard: %s" % groups) return groups @staticmethod @@ -79,21 +89,25 @@ class IPBoardManager: if type(ret) is list: for group in ret: groups.append(group["g_title"]) + logger.info("Got user %s IPBoard groups %s" % username, groups) return groups @staticmethod def add_group(group): ret = IPBoardManager.exec_xmlrpc('addGroup', group=group) + logger.info("Added IPBoard group %s, response %s" % (group, ret)) return ret @staticmethod def add_user_to_group(username, group): ret = IPBoardManager.exec_xmlrpc('addUserToGroup', username=username, group=group) + logger.info("Added IPBoard user %s to group %s, response %s" % (username, group, ret)) return ret @staticmethod def remove_user_from_group(username, group): ret = IPBoardManager.exec_xmlrpc('removeUserFromGroup', username=username, group=group) + logger.info("Removed IPBoard user %s from group %s, reponse %s" % (username, group, ret)) return ret @staticmethod @@ -104,27 +118,27 @@ class IPBoardManager: @staticmethod def update_groups(username, groups): - + logger.debug("Updating IPBoard user %s with groups %s" % (username, groups)) forum_groups = IPBoardManager.get_all_groups() user_groups = set(IPBoardManager.get_user_groups(username)) act_groups = set([g.replace(' ', '-') for g in groups]) addgroups = act_groups - user_groups remgroups = user_groups - act_groups - print addgroups - print remgroups + logger.info("Updating IPBoard groups for user %s - adding %s, removing %s" % (username, addgroups, remgroups)) for g in addgroups: if not g in forum_groups: IPBoardManager.add_group(g) - print username - print g + logger.debug("Adding user %s to IPBoard group %s" % (username, g)) IPBoardManager.add_user_to_group(username, g) for g in remgroups: + logger.debug("Removing user %s from IPBoard group %s" % (username, g)) IPBoardManager.remove_user_from_group(username, g) @staticmethod def update_user_password(username, email): + logger.debug("Settings new IPBoard password for user %s" % username)) plain_password = IPBoardManager.__generate_random_pass() IPBoardManager.update_user(username, email, plain_password) - return plain_password \ No newline at end of file + return plain_password diff --git a/services/managers/mumble_manager.py b/services/managers/mumble_manager.py index 5ad28163..d40ac249 100755 --- a/services/managers/mumble_manager.py +++ b/services/managers/mumble_manager.py @@ -6,6 +6,9 @@ import django from django.db import connections from django.conf import settings +import logging + +logger = logging.getLogger(__name__) class MumbleManager: SQL_SELECT_USER_MAX_ID = r"SELECT max(user_id)+1 as next_id from murmur_users" @@ -76,30 +79,38 @@ class MumbleManager: for row in rows: out[row[1]] = row[0] + logger.debug("Got mumble groups %s" % out) return out @staticmethod def _get_group(name): + logger.debug("Looking for group name %s in mumble." % name) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_GET_GROUP_FROM_NAME, [settings.MUMBLE_SERVER_ID, name]) row = dbcursor.fetchone() if row: + logger.debug("Found group %s in mumble - %s" % (name, row[0])) return row[0] @staticmethod def _get_user_groups(name): + logger.debug("Getting mumble groups for username %s" % name) dbcursor = connections['mumble'].cursor() user_id = MumbleManager.get_user_id_by_name(name) dbcursor.execute(MumbleManager.SQL_GET_USER_GROUPS, [user_id]) - return [row[0] for row in dbcursor.fetchall()] + out = [row[0] for row in dbcursor.fetchall()] + logger.debug("Got user %s mumble groups %s" % (name, out)) + return out @staticmethod def _add_group(name): + logger.debug("Adding group %s to mumble server." % name) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_SELECT_GROUP_MAX_ID) row = dbcursor.fetchone() groupid = row[0] dbcursor.execute(MumbleManager.SQL_ADD_GROUP, [groupid, settings.MUMBLE_SERVER_ID, name]) + logger.info("Created group %s on mumble server with id %s" % (name, groupid) return groupid @staticmethod @@ -107,124 +118,142 @@ class MumbleManager: if userid != None: dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_ADD_USER_TO_GROUP, [groupid, settings.MUMBLE_SERVER_ID, userid]) + logger.info("Added user id %s to mumble group id %s" % (userid, groupid)) @staticmethod def _del_user_from_group(userid, groupid): dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_DELETE_USER_FROM_GROUP, [groupid, settings.MUMBLE_SERVER_ID, userid]) + logger.info("Removed user id %s from mumble group id %s" % (userid, groupid)) @staticmethod def get_user_id_by_name(name): + logger.debug("Getting mumble user id for user with name %s" % name) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_SELECT_GET_USER_ID_BY_NAME, [name, settings.MUMBLE_SERVER_ID]) row = dbcursor.fetchone() if row: + logger.debug("Got mumble user id %s for name %s" % (row[0], name)) return row[0] @staticmethod def create_user(corp_ticker, username): + logger.debug("Creating mumble user with username %s and ticker %s" % (username, corp_ticker)) dbcursor = connections['mumble'].cursor() username_clean = MumbleManager.__santatize_username(MumbleManager.__generate_username(username, corp_ticker)) password = MumbleManager.__generate_random_pass() pwhash = MumbleManager._gen_pwhash(password) - + logger.debug("Proceeding with mumble user creation: clean username %s, pwhash starts with %s" % (username_clean, pwhash[0:5])) try: dbcursor.execute(MumbleManager.SQL_SELECT_USER_MAX_ID) user_id = dbcursor.fetchone()[0] dbcursor.execute(MumbleManager.SQL_CREATE_USER, [settings.MUMBLE_SERVER_ID, user_id, username_clean, pwhash]) - + logger.info("Added user to mumble with username %s" % username_clean) return username_clean, password except django.db.utils.IntegrityError as error: - print error + logger.exception("IntegrityError during mumble create_user occured.", exc_info=True) except: - print "Unexpected error:", sys.exc_info()[0] - + logger.exception("Unhandled exception occured.", exc_info=True) + logger.error("Exception prevented creation of mumble user. Returning blank for username, password.") return "", "" @staticmethod def create_blue_user(corp_ticker, username): + logger.debug("Creating mumble blue user with username %s and ticker %s" % (username, corp_ticker)) dbcursor = connections['mumble'].cursor() username_clean = MumbleManager.__santatize_username(MumbleManager.__generate_username_blue(username, corp_ticker)) password = MumbleManager.__generate_random_pass() pwhash = MumbleManager._gen_pwhash(password) - + logger.debug("Proceeding with mumble user creation: clean username %s, pwhash starts with %s" % (username_clean, pwhash[0:5])) try: dbcursor.execute(MumbleManager.SQL_SELECT_USER_MAX_ID) user_id = dbcursor.fetchone()[0] dbcursor.execute(MumbleManager.SQL_CREATE_USER, [settings.MUMBLE_SERVER_ID, user_id, username_clean, pwhash]) - + logger.info("Added blue user to mumble with username %s" % username_clean) return username_clean, password except: - print "Unexpected error:", sys.exc_info()[0] - + logger.exception("Unhandled exception occured.", exc_info=True) + logger.error("Exception prevented creation of mumble blue user. Returning blank for username, password.") return "", "" @staticmethod def check_user_exist(username): + logger.debug("Checking if username %s exists on mumble." % username) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_CHECK_USER_EXIST, [username, settings.MUMBLE_SERVER_ID]) row = dbcursor.fetchone() if row and row[0].lower() == username.lower(): + logger.debug("Found username %s on mumble." % username) return True + logger.debug("Unable to find username %s on mumble." % username) return False @staticmethod def delete_user(username): + logger.debug("Deleting user %s from mumble." % username) dbcursor = connections['mumble'].cursor() if MumbleManager.check_user_exist(username): try: dbcursor.execute(MumbleManager.SQL_DELETE_USER, [username, settings.MUMBLE_SERVER_ID]) + logger.info("Deleted user %s from mumble." % username) return True except: + logger.exception("Exception prevented deletion of user %s from mumble." % username, exc_info=True) return False - + logger.error("User %s not found on mumble. Unable to delete." % username) return False @staticmethod def update_user_password(username): + logger.debug("Updating mumble user %s password." % username) dbcursor = connections['mumble'].cursor() password = MumbleManager.__generate_random_pass() pwhash = MumbleManager._gen_pwhash(password) - + logger.debug("Proceeding with mumble user %s password update - pwhash starts with %s" % (username, pwhash[0:5])) if MumbleManager.check_user_exist(username): try: dbcursor.execute(MumbleManager.SQL_UPDATE_USER_PASSWORD, [pwhash, username, settings.MUMBLE_SERVER_ID]) + logger.info("Updated mumble user %s password." % username) return password except: + logger.exception("Exception prevented updating of mumble user %s password." % username, exc_info=True) return "" - + logger.error("User %s not found on mumble. Unable to update password." % username) return "" @staticmethod def update_groups(username, groups): + logger.debug("Updating mumble user %s groups %s" % (username, groups)) userid = MumbleManager.get_user_id_by_name(username) mumble_groups = MumbleManager._get_groups() user_groups = set(MumbleManager._get_user_groups(username)) act_groups = set([g.replace(' ', '-') for g in groups]) addgroups = act_groups - user_groups remgroups = user_groups - act_groups - + logger.info("Updating mumble user %s groups - adding %s, removing %s" % (username, addgroups, remgroups)) for g in addgroups: if not g in mumble_groups: mumble_groups[g] = MumbleManager._add_group(g) try: + logger.debug("Adding mumble user %s to group %s" % (userid, mumble_groups[g])) MumbleManager._add_user_to_group(userid, mumble_groups[g]) except: - print "Error occurred while adding a mumble to a group" + logger.exception("Exception occured while adding mumble user %s with id %s to group %s with id %s" % (username, userid, g, mumble_groups[g]), exc_info=True) for g in remgroups: try: + logger.debug("Deleting mumble user %s from group %s" % (userid, mumble_groups[g])) MumbleManager._del_user_from_group(userid, mumble_groups[g]) except: - print "Error occurred while removing a mumble user from group" + logger.exception("Exception occured whule removing mumble user %s with id %s from group %s with id %s" % (username, userid, g, mumble_groups[g]), exc_info=True)) diff --git a/services/managers/openfire_manager.py b/services/managers/openfire_manager.py index aea8bdf2..73022d52 100755 --- a/services/managers/openfire_manager.py +++ b/services/managers/openfire_manager.py @@ -9,6 +9,9 @@ import threading from ofrestapi.users import Users as ofUsers from ofrestapi import exception +import logging + +logger = logging.getLogger(__name__) class OpenfireManager: def __init__(self): @@ -16,6 +19,7 @@ class OpenfireManager: @staticmethod def send_broadcast_threaded(group_name, broadcast_message): + logger.info("Starting broadcast to %s with message %s" % (group_name, broadcast_message)) broadcast_thread = XmppThread(1, "XMPP Broadcast Thread", 1, group_name, broadcast_message) broadcast_thread.start() @@ -37,55 +41,68 @@ class OpenfireManager: @staticmethod def add_user(username): - + logger.debug("Adding username %s to openfire." % username) try: sanatized_username = OpenfireManager.__santatize_username(username) password = OpenfireManager.__generate_random_pass() api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.add_user(sanatized_username, password) - + logger.info("Added openfire user %s" % username) except exception.UserAlreadyExistsException: # User exist + logger.warn("Attempting to add a user %s to openfire which already exists on server." % username) return "", "" return sanatized_username, password @staticmethod def delete_user(username): + logger.debug("Deleting user %s from openfire." % username) try: api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.delete_user(username) + logger.info("Deleted user %s from openfire." % username) return True except exception.UserNotFoundException: + logger.warn("Attempting to delete a user %s from openfire which was not found on server." % username) return False @staticmethod def lock_user(username): + logger.debug("Locking openfire user %s" % username) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.lock_user(username) + logger.info("Locked openfire user %s" % username) @staticmethod def unlock_user(username): + logger.debug("Unlocking openfire user %s" % username) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.unlock_user(username) + logger.info("Unlocked openfire user %s" % username) @staticmethod def update_user_pass(username): + logger.debug("Updating openfire user %s password." % username) try: password = OpenfireManager.__generate_random_pass() api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.update_user(username, password=password) + logger.info("Updated openfire user %s password." % username) return password except exception.UserNotFoundException: + logger.error("Unable to update openfire user %s password - user not found on server." % username) return "" @staticmethod def update_user_groups(username, password, groups): + logger.debug("Updating openfire user %s groups %s" % (username, groups)) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) response = api.get_user_groups(username) remote_groups = [] if response: remote_groups = response['groupname'] + logger.debug("Openfire user %s has groups %s" % (username, remote_groups)) add_groups = [] del_groups = [] for g in groups: @@ -94,6 +111,7 @@ class OpenfireManager: for g in remote_groups: if not g in groups: del_groups.append(g) + logger.info("Updating openfire groups for user %s - adding %s, removing %s" % (username, add_groups, del_groups)) if add_groups: api.add_user_groups(username, add_groups) if del_groups: @@ -101,24 +119,28 @@ class OpenfireManager: @staticmethod def delete_user_groups(username, groups): - + logger.debug("Deleting openfire groups %s from user %s" % (groups, username)) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.delete_user_groups(username, groups) + logger.info("Deleted groups %s from openfire user %s" % (groups, username)) @staticmethod def send_broadcast_message(group_name, broadcast_message): + logger.debug("Sending jabber ping to group %s with message %s" % (group_name, broadcast_message)) # create to address client = xmpp.Client(settings.JABBER_URL) client.connect(server=(settings.JABBER_SERVER, settings.JABBER_PORT)) client.auth(settings.BROADCAST_USER, settings.BROADCAST_USER_PASSWORD, 'broadcast') to_address = group_name + '@' + settings.BROADCAST_SERVICE_NAME + '.' + settings.JABBER_URL + logger.debug("Determined ping to address: %s" % to_address) message = xmpp.Message(to_address, broadcast_message) message.setAttr('type', 'chat') client.send(message) client.Process(1) client.disconnect() + logger.info("Sent jabber ping to group %s" % group_name) class XmppThread (threading.Thread): def __init__(self, threadID, name, counter, group, message,): diff --git a/services/managers/phpbb3_manager.py b/services/managers/phpbb3_manager.py index 26ffea4d..1ee0a1cb 100755 --- a/services/managers/phpbb3_manager.py +++ b/services/managers/phpbb3_manager.py @@ -5,6 +5,9 @@ from datetime import datetime from passlib.apps import phpbb3_context from django.db import connections +import logging + +logger = logging.getLogger(__name__) class Phpbb3Manager: SQL_ADD_USER = r"INSERT INTO phpbb_users (username, username_clean, " \ @@ -39,6 +42,7 @@ class Phpbb3Manager: @staticmethod def __add_avatar(username, characterid): + logger.debug("Adding EVE character id %s portrait as phpbb avater for user %s" % (characterid, username)) avatar_url = "http://image.eveonline.com/Character/" + characterid + "_64.jpg" cursor = connections['phpbb3'].cursor() userid = Phpbb3Manager.__get_user_id(username) @@ -63,7 +67,7 @@ class Phpbb3Manager: cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_GET_GROUP_ID, [groupname]) row = cursor.fetchone() - + logger.debug("Got phpbb group id %s for groupname %s" % (row[0], groupname)) return row[0] @staticmethod @@ -72,8 +76,10 @@ class Phpbb3Manager: cursor.execute(Phpbb3Manager.SQL_USER_ID_FROM_USERNAME, [username]) row = cursor.fetchone() if row is not None: + logger.debug("Got phpbb user id %s for username %s" % (row[0], username)) return row[0] else: + logger.warn("Username %s not found on phpbb." % username) return None @staticmethod @@ -84,14 +90,16 @@ class Phpbb3Manager: out = {} for row in rows: out[row[1]] = row[0] - + logger.debug("Got phpbb groups %s" % out) return out @staticmethod def __get_user_groups(userid): cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_GET_USER_GROUPS, [userid]) - return [row[0] for row in cursor.fetchall()] + out = [row[0] for row in cursor.fetchall()] + logger.debug("Got user %s phpbb groups %s" % (userid, out)) + return out @staticmethod def __get_current_utc_date(): @@ -103,6 +111,7 @@ class Phpbb3Manager: def __create_group(groupname): cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_ADD_GROUP, [groupname, groupname]) + logger.info("Created phpbb group %s" % groupname) return Phpbb3Manager.__get_group_id(groupname) @staticmethod @@ -110,7 +119,9 @@ class Phpbb3Manager: try: cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_ADD_USER_GROUP, [groupid, userid, 0]) + logger.info("Added phpbb user id to group id %s" % (userid, groupid)) except: + logger.exception("Unable to add phpbb user id %s to group id %s" % (userid, groupid), exc_info=True) pass @staticmethod @@ -118,19 +129,23 @@ class Phpbb3Manager: cursor = connections['phpbb3'].cursor() try: cursor.execute(Phpbb3Manager.SQL_REMOVE_USER_GROUP, [userid, groupid]) + logger.info("Removed phpbb user id %s from group id %s" % (userid, groupid)) except: + logger.exception("Unable to remove phpbb user id %s from group id %s" % (userid, groupid), exc_info=True) pass @staticmethod def add_user(username, email, groups, characterid): + logger.debug("Adding phpbb user with username %s, email %s, groups %s, characterid %s" % (username, email, groups, characterid)) cursor = connections['phpbb3'].cursor() username_clean = Phpbb3Manager.__santatize_username(username) password = Phpbb3Manager.__generate_random_pass() pwhash = Phpbb3Manager.__gen_hash(password) - + logger.debug("Proceeding to add phpbb user %s and pwhash starting with %s" % (username_clean, pwhash[0:5])) # check if the username was simply revoked if Phpbb3Manager.check_user(username_clean): + logger.warn("Unable to add phpbb user with username %s - already exists. Updating user instead." % username) Phpbb3Manager.__update_user_info(username_clean, email, pwhash) else: try: @@ -140,13 +155,16 @@ class Phpbb3Manager: "", ""]) Phpbb3Manager.update_groups(username_clean, groups) Phpbb3Manager.__add_avatar(username_clean, characterid) + logger.info("Added phpbb user %s" % username) except: + logger.exception("Unable to add phpbb user %s" % username, exc_info=True) pass return username_clean, password @staticmethod def disable_user(username): + logger.debug("Disabling phpbb user %s" % username) cursor = connections['phpbb3'].cursor() password = Phpbb3Manager.__gen_hash(Phpbb3Manager.__generate_random_pass()) @@ -154,32 +172,35 @@ class Phpbb3Manager: try: pwhash = Phpbb3Manager.__gen_hash(password) cursor.execute(Phpbb3Manager.SQL_DIS_USER, [revoke_email, pwhash, username]) + logger.info("Disabled phpbb user %s" % username) return True except TypeError as e: - print e + logger.exception("TypeError occured while disabling user %s - failed to disable." % username, exc_info=True) return False @staticmethod def delete_user(username): + logger.debug("Deleting phpbb user %s" % username) cursor = connections['phpbb3'].cursor() if Phpbb3Manager.check_user(username): cursor.execute(Phpbb3Manager.SQL_DEL_USER, [username]) + logger.info("Deleted phpbb user %s" % username) return True + logger.warn("Unable to delete phpbb user %s - user not found on phpbb." % username) return False @staticmethod def update_groups(username, groups): userid = Phpbb3Manager.__get_user_id(username) + logger.debug("Updating phpbb user %s with id %s groups %s" % (username, userid, groups)) if userid is not None: forum_groups = Phpbb3Manager.__get_all_groups() user_groups = set(Phpbb3Manager.__get_user_groups(userid)) act_groups = set([g.replace(' ', '-') for g in groups]) addgroups = act_groups - user_groups remgroups = user_groups - act_groups - print username - print addgroups - print remgroups + logger.info("Updating phpbb user %s groups - adding %s, removing %s" % (username, addgroups, remgroups)) for g in addgroups: if not g in forum_groups: forum_groups[g] = Phpbb3Manager.__create_group(g) @@ -190,6 +211,7 @@ class Phpbb3Manager: @staticmethod def remove_group(username, group): + logger.debug("Removing phpbb user %s from group %s" % (username, group)) cursor = connections['phpbb3'].cursor() userid = Phpbb3Manager.__get_user_id(username) if userid is not None: @@ -199,35 +221,46 @@ class Phpbb3Manager: if groupid: try: cursor.execute(Phpbb3Manager.SQL_REMOVE_USER_GROUP, [userid, groupid]) + logger.info("Removed phpbb user %s from group %s" % (username, group)) except: + logger.exception("Exception prevented removal of phpbb user %s with id %s from group %s with id %s" % (username, userid, group, groupid), exc_info=True) pass @staticmethod def check_user(username): + logger.debug("Checking phpbb username %s" % username) cursor = connections['phpbb3'].cursor() """ Check if the username exists """ cursor.execute(Phpbb3Manager.SQL_USER_ID_FROM_USERNAME, [Phpbb3Manager.__santatize_username(username)]) row = cursor.fetchone() if row: + logger.debug("Found user %s on phpbb" % username) return True + logger.debug("User %s not found on phpbb" % username) return False @staticmethod def update_user_password(username, characterid): + logger.debug("Updating phpbb user %s password" % username) cursor = connections['phpbb3'].cursor() password = Phpbb3Manager.__generate_random_pass() if Phpbb3Manager.check_user(username): pwhash = Phpbb3Manager.__gen_hash(password) + logger.debug("Proceeding to update phpbb user %s password with pwhash starting with %s" % (username, pwhash[0:5])) cursor.execute(Phpbb3Manager.SQL_UPDATE_USER_PASSWORD, [pwhash, username]) Phpbb3Manager.__add_avatar(username, characterid) + logger.info("Updated phpbb user %s password." % username) return password - + logger.error("Unable to update phpbb user %s password - user not found on phpbb." % username) return "" @staticmethod def __update_user_info(username, email, password): + logger.debug("Updating phpbb user %s info: username %s password of length %s" % (username, email, len(password))) cursor = connections['phpbb3'].cursor() try: cursor.execute(Phpbb3Manager.SQL_DIS_USER, [email, password, username]) + logger.info("Updated phpbb user %s info" % username) except: + logger.exception("Unable to update phpbb user %s info." % username, exc_info=True pass diff --git a/services/managers/teamspeak3_manager.py b/services/managers/teamspeak3_manager.py index 349e6cfb..700bef61 100755 --- a/services/managers/teamspeak3_manager.py +++ b/services/managers/teamspeak3_manager.py @@ -74,7 +74,7 @@ class Teamspeak3Manager: server.send_command('servergroupaddperm', {'sgid': sgid, 'permsid': 'i_group_needed_member_remove_power', 'permvalue': 100, 'permnegated': 0, 'permskip': 0}) - logger.debug("Returning group id %s" % sqid) + logger.info("Created group on TS3 server with name %s and id %s" % (groupname, sqid)) return sgid @staticmethod @@ -109,7 +109,7 @@ class Teamspeak3Manager: logger.debug("Assigning name/id dict: %s = %s" % (group['keys']['name'], group['keys']['sgid'])) outlist[group['keys']['name']] = group['keys']['sgid'] else: - logger.debug("Received empty group cache. 1024 error.") + logger.error("Received empty group cache while retrieving group cache from TS3 server. 1024 error.", exc_info=True) print '1024 error' logger.debug("Returning name/id pairing: %s" % outlist) return outlist @@ -125,6 +125,7 @@ class Teamspeak3Manager: logger.debug("User does not have group already. Issuing command to add.") server.send_command('servergroupaddclient', {'sgid': str(groupid), 'cldbid': uid}) + logger.info("Added user id %s to group id %s on TS3 server." % (uid, groupid)) @staticmethod def _remove_user_from_group(uid, groupid): @@ -137,6 +138,7 @@ class Teamspeak3Manager: logger.debug("User is in group. Issuing command to remove.") server.send_command('servergroupdelclient', {'sgid': str(groupid), 'cldbid': uid}) + logger.info("Removed user id %s from group id %s on TS3 server." % (uid, groupid)) @staticmethod def _sync_ts_group_db(): @@ -170,7 +172,7 @@ class Teamspeak3Manager: corp_ticker)) server = Teamspeak3Manager.__get_created_server() token = "" - + logger.debug("Adding user to TS3 server with cleaned username %s" % username_clean) server_groups = Teamspeak3Manager._group_list() if not settings.DEFAULT_AUTH_GROUP in server_groups: @@ -188,6 +190,7 @@ class Teamspeak3Manager: token = ret['keys']['token'] except: pass + logger.info("Created user %s on TS3 server, got token %s" % (username_clean, token)) return username_clean, token @@ -197,7 +200,7 @@ class Teamspeak3Manager: corp_ticker)) server = Teamspeak3Manager.__get_created_server() token = "" - + logger.debug("Adding user to TS3 server with cleaned username %s" % username_clean) server_groups = Teamspeak3Manager._group_list() if not settings.DEFAULT_BLUE_GROUP in server_groups: Teamspeak3Manager._create_group(settings.DEFAULT_BLUE_GROUP) @@ -215,6 +218,7 @@ class Teamspeak3Manager: except: pass + logger.info("Created blue user %s on TS3 server, got token %s" % (username_clean, token)) return username_clean, token @@ -222,16 +226,20 @@ class Teamspeak3Manager: def delete_user(uid): server = Teamspeak3Manager.__get_created_server() user = Teamspeak3Manager._get_userid(uid) + logger.debug("Deleting user %s with id %s from TS3 server." % (user, uid)) if user: for client in server.send_command('clientlist'): if client['keys']['client_database_id'] == user: + logger.debug("Found user %s on TS3 server - issuing deletion command." % user) server.send_command('clientkick', {'clid': client['keys']['clid'], 'reasonid': 5, 'reasonmsg': 'Auth service deleted'}) ret = server.send_command('clientdbdelete', {'cldbid': user}) if ret == '0': + logger.info("Deleted user with id %s from TS3 server." % uid) return True else: + logger.warn("User with id %s not found on TS3 server. Assuming succesful deletion." % uid) return True @staticmethod @@ -243,37 +251,42 @@ class Teamspeak3Manager: @staticmethod def generate_new_permissionkey(uid, username, corpticker): + logger.debug("Re-issuing permission key for user id %s." % uid) Teamspeak3Manager.delete_user(uid) return Teamspeak3Manager.add_user(username, corpticker) @staticmethod def generate_new_blue_permissionkey(uid, username, corpticker): + logger.debug("Re-issuing blue permission key for user id %s" % uid) Teamspeak3Manager.delete_user(uid) return Teamspeak3Manager.add_blue_user(username, corpticker) @staticmethod def update_groups(uid, ts_groups): + logger.debug("Updating uid %s groups %s" % (uid, ts_groups)) userid = Teamspeak3Manager._get_userid(uid) addgroups = [] remgroups = [] if userid is not None: user_ts_groups = Teamspeak3Manager._user_group_list(userid) + logger.debug("User has groups on TS3 server: %s" % user_ts_groups) for key in user_ts_groups: user_ts_groups[key] = int(user_ts_groups[key]) for ts_group_key in ts_groups: + logger.debug("Checking if user has group %s on TS3 server." % ts_group_key) if ts_groups[ts_group_key] not in user_ts_groups.values(): addgroups.append(ts_groups[ts_group_key]) for user_ts_group_key in user_ts_groups: if user_ts_groups[user_ts_group_key] not in ts_groups.values(): remgroups.append(user_ts_groups[user_ts_group_key]) - print userid - print addgroups - print remgroups + logger.info("Finished checking user id %s groups. Adding %s, removing %s." % (uid, addgroups, remgroups)) for g in addgroups: + logger.debug("Issuing add command for group %s" % g) Teamspeak3Manager._add_user_to_group(userid, g) for g in remgroups: + logger.debug("Issuing remove command for group %s" % g) Teamspeak3Manager._remove_user_from_group(userid, g)