diff --git a/alliance_auth/settings.py.example b/alliance_auth/settings.py.example index 2de69666..e5235035 100755 --- a/alliance_auth/settings.py.example +++ b/alliance_auth/settings.py.example @@ -362,7 +362,7 @@ LOGGING = { }, 'handlers': { 'debug_file': { - 'level': 'DEBUG', + 'level': 'INFO', 'class': 'logging.FileHandler', 'filename': 'debug.log', 'formatter': 'verbose' @@ -374,14 +374,50 @@ LOGGING = { } }, 'loggers': { + 'authentication': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, 'celerytask': { 'handlers': ['debug_file', 'console'], 'level': 'DEBUG', }, + 'eveonline': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, + 'groupmanagement': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, + 'hrapplications': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, + 'portal': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, + 'registration': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, 'services': { 'handlers': ['debug_file', 'console'], 'level': 'DEBUG', }, + 'srp': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, + 'timerboard': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, + 'util': { + 'handlers': ['debug_file', 'console'], + 'level': 'DEBUG', + }, } } diff --git a/authentication/managers.py b/authentication/managers.py index 0cea7a07..dbccc4e4 100755 --- a/authentication/managers.py +++ b/authentication/managers.py @@ -2,6 +2,9 @@ from django.contrib.auth.models import User from models import AuthServicesInfo +import logging + +logger = logging.getLogger(__name__) class AuthServicesInfoManager: def __init__(self): @@ -10,10 +13,11 @@ class AuthServicesInfoManager: @staticmethod def __get_or_create(user): if AuthServicesInfo.objects.filter(user=user).exists(): + logger.debug("Returning existing authservicesinfo model for user %s" % user) return AuthServicesInfo.objects.get(user=user) else: # We have to create - print 'here' + logger.info("Creating new authservicesinfo model for user %s" % user) authserviceinfo = AuthServicesInfo() authserviceinfo.user = user authserviceinfo.save() @@ -23,66 +27,96 @@ class AuthServicesInfoManager: def get_auth_service_info(user): if User.objects.filter(username=user.username).exists(): return AuthServicesInfoManager.__get_or_create(user) + logger.error("Failed to get authservicesinfo object for user %s: user does not exist." % user) return None @staticmethod def update_main_char_Id(char_id, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s main character to id %s" % (user, char_id)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.main_char_id = char_id authserviceinfo.save(update_fields=['main_char_id']) + logger.info("Updated user %s main character to id %s" % (user, char_id)) + logger.error("Failed to update user %s main character id to %s: user does not exist." % (user, char_id)) @staticmethod def update_user_forum_info(username, password, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s forum info: username %s" % (user, username)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.forum_username = username authserviceinfo.forum_password = password authserviceinfo.save(update_fields=['forum_username', 'forum_password']) + logger.info("Updated user %s forum info in authservicesinfo model." % user) + else: + logger.error("Failed to update user %s forum info: user does not exist." % user) @staticmethod def update_user_jabber_info(username, password, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s jabber info: username %s" % (user, username)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.jabber_username = username authserviceinfo.jabber_password = password authserviceinfo.save(update_fields=['jabber_username', 'jabber_password']) + logger.info("Updated user %s jabber info in authservicesinfo model." % user) + else: + logger.error("Failed to update user %s jabber info: user does not exist." % user) @staticmethod def update_user_mumble_info(username, password, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s mumble info: username %s" % (user, username)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.mumble_username = username authserviceinfo.mumble_password = password authserviceinfo.save(update_fields=['mumble_username', 'mumble_password']) + logger.info("Updated user %s mumble info in authservicesinfo model." % user) + else: + logger.error("Failed to update user %s mumble info: user does not exist." % user) @staticmethod def update_user_ipboard_info(username, password, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s ipboard info: uername %s" % (user, username)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.ipboard_username = username authserviceinfo.ipboard_password = password authserviceinfo.save(update_fields=['ipboard_username', 'ipboard_password']) + logger.info("Updated user %s ipboard info in authservicesinfo model." % user) + else: + logger.error("Failed to update user %s ipboard info: user does not exist." % user) @staticmethod def update_user_teamspeak3_info(uid, perm_key, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s teamspeak3 info: uid %s" % (user, uid)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.teamspeak3_uid = uid authserviceinfo.teamspeak3_perm_key = perm_key authserviceinfo.save(update_fields=['teamspeak3_uid', 'teamspeak3_perm_key']) + logger.info("Updated user %s teamspeak3 info in authservicesinfo model." % user) + else: + logger.error("Failed to update user %s teamspeak3 info: user does not exist." % user) @staticmethod def update_is_blue(is_blue, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s blue status: %s" % (user, is_blue)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.is_blue = is_blue authserviceinfo.save(update_fields=['is_blue']) + logger.info("Updated user %s blue status to %s in authservicesinfo model." % (user, is_blue)) @staticmethod def update_user_discord_info(user_id, user): if User.objects.filter(username=user.username).exists(): + logger.debug("Updating user %s discord info: user_id %s" % (user, user_id)) authserviceinfo = AuthServicesInfoManager.__get_or_create(user) authserviceinfo.discord_uid = user_id authserviceinfo.save(update_fields=['discord_uid']) + logger.info("Updated user %s discord info in authservicesinfo model." % user) + else: + logger.error("Failed to update user %s discord info: user does not exist." % user) diff --git a/authentication/views.py b/authentication/views.py index aba82e89..5dc123ac 100644 --- a/authentication/views.py +++ b/authentication/views.py @@ -7,26 +7,39 @@ from django.template import RequestContext from forms import LoginForm +import logging + +logger = logging.getLogger(__name__) def login_user(request): + logger.debug("login_user called by user %s" % request.user) if request.method == 'POST': form = LoginForm(request.POST) - + logger.debug("Request of type POST, received form, valid: %s" % form.is_valid()) if form.is_valid(): user = authenticate(username=form.cleaned_data['username'], password=form.cleaned_data['password']) + logger.debug("Authentication attempt with supplied credentials. Received user %s" % user) if user is not None: if user.is_active: + logger.info("Successful login attempt from user %s" % user) login(request, user) return HttpResponseRedirect("/dashboard") + else: + logger.info("Login attempt failed for user %s: user marked inactive." % user) + else: + logger.info("Failed login attempt: provided username %s" % form.cleaned_data['username']) return render_to_response('public/login.html', {'form': form, 'error': True}, context_instance=RequestContext(request)) else: + logger.debug("Providing new login form.") form = LoginForm() return render_to_response('public/login.html', {'form': form}, context_instance=RequestContext(request)) def logout_user(request): + logger.debug("logout_user called by user %s" % request.user) logout(request) - return HttpResponseRedirect("/") \ No newline at end of file + logger.info("Successful logout for user %s" % request.user) + return HttpResponseRedirect("/") diff --git a/celerytask/tasks.py b/celerytask/tasks.py index 2986efbc..762aac53 100755 --- a/celerytask/tasks.py +++ b/celerytask/tasks.py @@ -31,82 +31,98 @@ import logging logger = logging.getLogger(__name__) def disable_alliance_member(user, char_id): + logger.debug("Disabling alliance member %s" % user) remove_member_permission(user, 'member') remove_user_from_group(user, settings.DEFAULT_AUTH_GROUP) remove_user_from_group(user, generate_corp_group_name( EveManager.get_character_by_id(char_id).corporation_name)) deactivate_services(user) + logger.info("Disabled alliance member %s" % user) def disable_expired_member(user): + logger.debug("Disabling expired member %s" % user) deactivate_services(user) user.user_permissions.clear() user.groups.clear() user.save() + logger.info("Disabled expired member %s" % user) def disable_blue_member(user): + logger.debug("Disabling blue member %s" % user) remove_member_permission(user, 'blue_member') remove_user_from_group(user, settings.DEFAULT_BLUE_GROUP) deactivate_services(user) AuthServicesInfoManager.update_is_blue(False, user) + logger.info("Disabled blue member %s" % user) def is_teamspeak3_active(): return settings.ENABLE_AUTH_TEAMSPEAK3 or settings.ENABLE_BLUE_TEAMSPEAK3 def update_jabber_groups(user): + logger.debug("Updating jabber groups for user %s" % user) syncgroups = SyncGroupCache.objects.filter(user=user) authserviceinfo = AuthServicesInfo.objects.get(user=user) groups = [] - + logger.debug("User %s has %s syncgroups." % (user, len(syncgroups))) for syncgroup in syncgroups: groups.append(str(syncgroup.groupname)) if len(groups) == 0: groups.append('empty') + logger.debug("Updating user %s jabber groups to %s" % (user, groups)) OpenfireManager.update_user_groups(authserviceinfo.jabber_username, authserviceinfo.jabber_password, groups) + logger.info("Updated user %s jabber groups." % user) def update_mumble_groups(user): + logger.debug("Updating mumble groups for user %s" % user) syncgroups = SyncGroupCache.objects.filter(user=user) authserviceinfo = AuthServicesInfo.objects.get(user=user) groups = [] + logger.debug("User %s has %s syncgroups." % (user, len(syncgroups))) for syncgroup in syncgroups: groups.append(str(syncgroup.groupname)) if len(groups) == 0: groups.append('empty') - + logger.debug("Updating user %s mumble groups to %s" % (user, groups)) MumbleManager.update_groups(authserviceinfo.mumble_username, groups) - + logger.info("Updated user %s mumble groups." % user) def update_forum_groups(user): + logger.debug("Updating forum groups for user %s" % user) syncgroups = SyncGroupCache.objects.filter(user=user) authserviceinfo = AuthServicesInfo.objects.get(user=user) groups = [] + logger.debug("User %s has %s syncgroups." % (user, len(syncgroups))) for syncgroup in syncgroups: groups.append(str(syncgroup.groupname)) if len(groups) == 0: groups.append('empty') - + logger.debug("Updating user %s forum groups to %s" % (user, groups)) Phpbb3Manager.update_groups(authserviceinfo.forum_username, groups) - + logger.info("Updated user %s forum groups." % user) def update_ipboard_groups(user): + logger.debug("Updating user %s ipboard groups." % user) syncgroups = SyncGroupCache.objects.filter(user=user) authserviceinfo = AuthServicesInfo.objects.get(user=user) groups = [] + logger.debug("User %s has %s syncgroups." % (user, len(syncgroups))) for syncgroup in syncgroups: groups.append(str(syncgroup.groupname)) if len(groups) == 0: groups.append('empty') - + logger.debug("Updating user %s ipboard groups to %s" % (user, groups)) IPBoardManager.update_groups(authserviceinfo.ipboard_username, groups) - + logger.info("Updated user %s ipboard groups." % user) def update_teamspeak3_groups(user): + logger.debug("Updating user %s teamspeak3 groups" % user) usergroups = user.groups.all() authserviceinfo = AuthServicesInfo.objects.get(user=user) groups = {} @@ -116,8 +132,9 @@ def update_teamspeak3_groups(user): for filtered_group in filtered_groups: for ts_group in filtered_group.ts_group.all(): groups[ts_group.ts_group_name] = ts_group.ts_group_id - if (is_teamspeak3_active()): - Teamspeak3Manager.update_groups(authserviceinfo.teamspeak3_uid, groups) + logger.debug("Updating user %s teamspeak3 groups to %s" % (user, groups)) + Teamspeak3Manager.update_groups(authserviceinfo.teamspeak3_uid, groups) + logger.info("Updated user %s teamspeak3 groups." % user) def update_discord_groups(user): logger.debug("Updating discord groups for user %s" % user) @@ -127,26 +144,33 @@ def update_discord_groups(user): for syncgroup in syncgroups: groups.append(str(syncgroup.groupname)) - logger.debug("Found %s syncgroups." % len(groups)) + logger.debug("User %s has %s syncgroups." % (user, len(syncgroups))) if len(groups) == 0: logger.debug("No syncgroups found for user. Adding empty group.") groups.append('empty') - + logger.debug("Updating user %s discord groups to %s" % (user, groups)) DiscordManager.update_groups(authserviceinfo.discord_uid, groups) + logger.info("Updated user %s discord groups." % user) def create_syncgroup_for_user(user, groupname, servicename): + logger.debug("Creating syncgroupcache for user %s group %s in service %s" % (user, groupname, servicename)) synccache = SyncGroupCache() synccache.groupname = groupname synccache.user = user synccache.servicename = servicename synccache.save() + logger.info("Created syncgroup for user %s group %s in service %s" % (user, groupname, servicename)) def remove_all_syncgroups_for_service(user, servicename): + logger.debug("Removing all syncgroups for user %s service %s" % (user, servicename)) syncgroups = SyncGroupCache.objects.filter(user=user) + logger.debug("User %s has %s syncgroups." % (user, len(syncgroups))) for syncgroup in syncgroups: if syncgroup.servicename == servicename: + logger.debug("Deleting syncgroups %s" % syncgroup) syncgroup.delete() + logger.info("Removed all syncgroups for user %s service %s" % (user, servicename)) def add_to_databases(user, groups, syncgroups): @@ -258,43 +282,53 @@ def run_databaseUpdate(): @periodic_task(run_every=crontab(minute=0, hour="*/3")) def run_api_refresh(): users = User.objects.all() - + logger.debug("Running api refresh on %s users." % len(users)) for user in users: # Check if the api server is online + logger.debug("Running api refresh for user %s" % user) if EveApiManager.check_if_api_server_online(): api_key_pairs = EveManager.get_api_key_pairs(user.id) + logger.debug("User %s has api key pairs %s" % (user, api_key_pairs)) if api_key_pairs: valid_key = False authserviceinfo = AuthServicesInfo.objects.get(user=user) - print 'Running update on user: ' + user.username + logger.debug("User %s has api keys. Proceeding to refresh." % user) if authserviceinfo.main_char_id: if authserviceinfo.main_char_id != "": #preserve old corp ID for corp change test on members oldcorp_id = 0 if EveManager.get_character_by_id(authserviceinfo.main_char_id): oldcorp_id = EveCharacter.objects.get(character_id=authserviceinfo.main_char_id).corporation_id + logger.debug("Determined user %s current main corp id %s" % (user, oldcorp_id)) for api_key_pair in api_key_pairs: - print 'Running on ' + api_key_pair.api_id + ':' + api_key_pair.api_key + logger.debug("Running update on api key %s" % api_key_pair.api_id) if EveApiManager.api_key_is_valid(api_key_pair.api_id, api_key_pair.api_key): #check to ensure API key meets min spec + logger.info("Determined api key %s is still active." % api_key_pair.api_id) still_valid = True if authserviceinfo.is_blue: if settings.BLUE_API_ACCOUNT: if not EveApiManager.check_api_is_type_account(api_key_pair.api_id, api_key_pair.api_key): + logger.info("Determined api key %s for blue user %s is no longer type account as requred." % (api_key_pair.api_id, user)) still_valid = False if not EveApiManager.check_blue_api_is_full(api_key_pair.api_id, api_key_pair.api_key): + logger.info("Determined api key %s for blue user %s no longer meets minimum access mask as required." % (api_key_pair.api_id, user)) still_valid = False else: if settings.MEMBER_API_ACCOUNT: if not EveApiManager.check_api_is_type_account(api_key_pair.api_id, api_key_pair.api_key): + logger.info("Determined api key %s for user %s is no longer type account as required." % (api_key_pair.api_id, user)) still_valid = False if not EveApiManager.check_api_is_full(api_key_pair.api_id, api_key_pair.api_key): + logger.info("Determined api key %s for user %s no longer meets minimum access mask as required." % (api_key_pair.api_id, user)) still_valid = False if still_valid is not True: + logger.debug("API key %s has failed validation; it and its characters will be deleted." % api_key_pair.api_id) EveManager.delete_characters_by_api_id(api_key_pair.api_id, user.id) EveManager.delete_api_key_pair(api_key_pair.api_id, user.id) - else: + else: + logger.info("Determined api key %s still meets requirements." % api_key_pair.api_id) # Update characters characters = EveApiManager.get_characters_from_api(api_key_pair.api_id, api_key_pair.api_key) @@ -304,25 +338,32 @@ def run_api_refresh(): # Ensure we have a model for all characters on key if not EveManager.check_if_character_exist(characters.result[char]['name']): new_character = True + logger.debug("API key %s has a new character on the account: %s" % (api_key_pair.api_id, characters.result[char]['name'])) if new_character: + logger.debug("Creating new character %s from api key %s" % (characters.result[char]['name'], api_key_pair.api_id)) EveManager.create_characters_from_list(characters, user, api_key_pair.api_key) valid_key = True else: + logger.debug("API key %s is no longer active; it and its characters will be deleted." % api_key_pair.api_id) EveManager.delete_characters_by_api_id(api_key_pair.api_id, user.id) EveManager.delete_api_key_pair(api_key_pair.api_id, user.id) if valid_key: # Check our main character character = EveManager.get_character_by_id(authserviceinfo.main_char_id) + logger.debug("User %s has valid api key, checking main character %s" % (user, character)) if character is not None and EveManager.check_if_corporation_exists_by_id(character.corporation_id): corp = EveManager.get_corporation_info_by_id(character.corporation_id) main_corp_id = EveManager.get_charater_corporation_id_by_id(authserviceinfo.main_char_id) main_alliance_id = EveManager.get_charater_alliance_id_by_id(authserviceinfo.main_char_id) + logger.debug("User %s main character %s has corp %s with alliance id %s" % (user, character, corp, main_alliance_id)) if (settings.IS_CORP and main_corp_id == settings.CORP_ID) or (not settings.IS_CORP and main_alliance_id == settings.ALLIANCE_ID): + logger.debug("User %s corp or alliance meets membership requirements. Ensuring has required permissions and groups." % user) if not check_if_user_has_permission(user, "member"): #transition from none or blue to member if check_if_user_has_permission(user, "blue_member"): #strip blue status + logger.debug("Removing user %s blue permission and group to prepare for member transition." % user) remove_member_permission(user, "blue_member") remove_user_from_group(user, settings.DEFAULT_BLUE_GROUP) AuthServicesInfoManager.update_is_blue(False, user) @@ -331,51 +372,65 @@ def run_api_refresh(): add_user_to_group(user, settings.DEFAULT_AUTH_GROUP) #add to required corp group add_user_to_group(user, generate_corp_group_name(character.corporation_name)) + logger.info("User %s transitioned to full member during api refresh." % user) elif corp.corporation_id != oldcorp_id: #changed corps, both corps auth'd, need to change group assignment + logger.debug("User %s main character changed corp from id %s to %s, both meet membership requirements. Updating corp group." % (user, oldcorp_id, corp.corporation_id)) oldcorp = EveCorporationInfo.objects.get(corporation_id=oldcorp_id) remove_user_from_group(user, generate_corp_group_name(oldcorp.corporation_name)) add_user_to_group(user, generate_corp_group_name(character.corporation_name)) #reset services to force new mumble names and group assignments deactivate_services(user) + logger.info("User %s transferred corps from member to member. Reassigned groups." % user) elif corp is not None: + logger.debug("User %s main corp %s does not meet membership requirements." % (user, corp)) if corp.is_blue is not True: if check_if_user_has_permission(user, "member"): #transition from member to nobody disable_alliance_member(user, authserviceinfo.main_char_id) + logger.info("User %s no longer member: main has left member corp/alliance." % user) elif check_if_user_has_permission(user, "blue_member"): #transition from blue to nobody disable_blue_member(user) + logger.info("User %s no longer blue: main has left blue entities." % user) else: #stay nobody, make sure no services deactivate_services(user) + logger.debug("Ensured non-member %s has no services." % user) else: if check_if_user_has_permission(user, "member"): #remove auth member to prepare for member to blue transition disable_alliance_member(user, authserviceinfo.main_char_id) + logger.debug("Removed user %s member group/permissions to transition to blue." % user) if not check_if_user_has_permission(user, "blue_member"): #perform nobody to blue transition add_member_permission(user, "blue_member") add_user_to_group(user, settings.DEFAULT_BLUE_GROUP) AuthServicesInfoManager.update_is_blue(True, user) + logger.info("User %s transitioned to blue member during api refresh." % user) else: # disable accounts with missing corp model (not blue or member) if check_if_user_has_permission(user, "member"): disable_alliance_member(user, authserviceinfo.main_char_id) + logger.info("User %s disabled (previously member) as unable to check missing corp model." % user) elif check_if_user_has_permission(user, "blue_member"): disable_blue_member(user) + logger.info("User %s disabled (previously blue) as unable to check missing corp model." % user) else: deactivate_services(user) + logger.debug("Ensured non-member %s has no services." % user) else: # nuke it, the hard way disable_expired_member(user) + logger.info("User %s disabled due to missing main character or corp model." % user) else: # disable accounts with invalid keys disable_expired_member(user) + logger.info("User %s has no valid api keys and has been disabled." % user) else: - print 'No main_char_id set' + logger.warn("User %s has no main character id, unable to validate membership.") # Run Every 2 hours @@ -383,36 +438,48 @@ def run_api_refresh(): def run_corp_update(): # I am not proud of this block of code if EveApiManager.check_if_api_server_online(): - + logger.debug("API server online and reachable. Proceeding with corp update.") if settings.IS_CORP: # Create the corp + logger.debug("Ensuring corp model exists for owning corp id %s due to settings.IS_CORP %s" % (settings.CORP_ID, settings.IS_CORP)) ownercorpinfo = EveApiManager.get_corporation_information(settings.CORP_ID) + logger.debug("Determined ownercorp info: %s" % ownercorpinfo) if not EveManager.check_if_corporation_exists_by_id(ownercorpinfo['id']): + logger.debug("Owning corp id %s does not have a model. Creating." % ownercorpinfo['id']) if ownercorpinfo['alliance']['id'] is None: + logger.debug("Owning corp does not have an alliance. Creating model with alliance=None") EveManager.create_corporation_info(ownercorpinfo['id'], ownercorpinfo['name'], ownercorpinfo['ticker'], ownercorpinfo['members']['current'], False, None) else: alliance_info = EveApiManager.get_alliance_information(ownercorpinfo['alliance']['id']) - if not EveManager.check_if_alliance_exists_by_id(settings.ALLIANCE_ID): - EveManager.create_alliance_info(settings.ALLIANCE_ID, alliance_info['name'], alliance_info['ticker'], + logger.debug("Owning corp has an alliance, got info: %s" % alliance_info) + if not EveManager.check_if_alliance_exists_by_id(ownercorpinfo['alliance']['id']): + logger.debug("Owning corp missing alliance model. Creating for id %s" % ownercorpinfo['alliance']['id']) + EveManager.create_alliance_info(ownercorpinfo['alliance']['id'], alliance_info['name'], alliance_info['ticker'], alliance_info['executor_id'], alliance_info['member_count'], False) alliance = EveManager.get_alliance_info_by_id(ownercorpinfo['alliance']['id']) + logger.debug("Got alliance model %s for owning corp. Creating corp model." % alliance) EveManager.create_corporation_info(ownercorpinfo['id'], ownercorpinfo['name'], ownercorpinfo['ticker'], ownercorpinfo['members']['current'], False, alliance) else: # Updated alliance info + logger.debug("Getting info for owning alliance %s" % settings.ALLIANCE_ID) alliance_info = EveApiManager.get_alliance_information(settings.ALLIANCE_ID) - + logger.debug("Owning alliance info: %s" % alliance_info) # Populate alliance info if not EveManager.check_if_alliance_exists_by_id(settings.ALLIANCE_ID): + logger.debug("Missing alliance model for owning alliance. Creating with id %s" % settings.ALLIANCE_ID) EveManager.create_alliance_info(settings.ALLIANCE_ID, alliance_info['name'], alliance_info['ticker'], alliance_info['executor_id'], alliance_info['member_count'], False) alliance = EveManager.get_alliance_info_by_id(settings.ALLIANCE_ID) + logger.debug("Got owning alliance model %s" % alliance) # Create the corps in the alliance for alliance_corp in alliance_info['member_corps']: corpinfo = EveApiManager.get_corporation_information(alliance_corp) + logger.debug("Got corpinfo for alliance member corp: %s" % corpinfo) if not EveManager.check_if_corporation_exists_by_id(corpinfo['id']): + logger.debug("Alliance member corp id %s missing model - creating." % corpinfo['id']) EveManager.create_corporation_info(corpinfo['id'], corpinfo['name'], corpinfo['ticker'], corpinfo['members']['current'], False, alliance) @@ -420,129 +487,167 @@ def run_corp_update(): #refer to https://github.com/eve-val/evelink/blob/master/evelink/parsing/contact_list.py#L43 standing_level = 'alliance' if settings.IS_CORP: + logger.debug("Switching statings check to corp level.") standing_level = 'corp' # Create the corps in the standings corp_standings = EveApiManager.get_corp_standings() + logger.debug("Got %s corp standings." % len(corp_standings)) if corp_standings: for standing_id in EveApiManager.get_corp_standings()[standing_level]: + logger.debug("Processing standing id %s" % standing_id) if int(corp_standings[standing_level][standing_id]['standing']) >= settings.BLUE_STANDING: + logger.debug("Standing %s meets or exceeds blue threshold." % standing_id) if EveApiManager.check_if_id_is_character(standing_id): + logger.debug("Standing id %s is a character. Not creating model.") pass elif EveApiManager.check_if_id_is_corp(standing_id): corpinfo = EveApiManager.get_corporation_information(standing_id) + logger.debug("Standing id %s is a corp. Got corpinfo: %s" % (standing_id, corpinfo)) if not EveManager.check_if_corporation_exists_by_id(standing_id): + logger.debug("Corp model for standing id %s does not exist. Creating" % standing_id) EveManager.create_corporation_info(corpinfo['id'], corpinfo['name'], corpinfo['ticker'], corpinfo['members']['current'], True, None) else: # Alliance id create corps blue_alliance_info = EveApiManager.get_alliance_information(standing_id) - + logger.debug("Standing id %s is alliance. Got alliance info: %s" % (standing_id, blue_alliance_info)) if not EveManager.check_if_alliance_exists_by_id(standing_id): + logger.debug("Alliance model for standing id %s does not exist. Creating" % standing_id) EveManager.create_alliance_info(standing_id, blue_alliance_info['name'], blue_alliance_info['ticker'], blue_alliance_info['executor_id'], blue_alliance_info['member_count'], True) blue_alliance = EveManager.get_alliance_info_by_id(standing_id) - + logger.debug("Got alliance model %s for standing id %s" % (blue_alliance, standing_id)) for blue_alliance_corp in blue_alliance_info['member_corps']: blue_info = EveApiManager.get_corporation_information(blue_alliance_corp) + logger.debug("Got corpinfo for member corp id %s of blue alliance %s: %s" % (blue_info['id'], blue_alliance, blue_info)) if not EveManager.check_if_corporation_exists_by_id(blue_info['id']): + logger.debug("Blue alliance %s member corp id %s missing model. Creating." % (blue_alliance, blue_info['id'])) EveManager.create_corporation_info(blue_info['id'], blue_info['name'], blue_info['ticker'], blue_info['members']['current'], True, blue_alliance) # Update all allinace info's for all_alliance_info in EveManager.get_all_alliance_info(): + logger.debug("Validating alliance model %s" % all_alliance_info) if EveApiManager.check_if_alliance_exists(all_alliance_info.alliance_id): all_alliance_api_info = EveApiManager.get_alliance_information(all_alliance_info.alliance_id) + logger.debug("Got alliance %s alliance info: %s" % (all_alliance_info, all_alliance_api_info)) if (not settings.IS_CORP and all_alliance_info.alliance_id == settings.ALLIANCE_ID): + logger.debug("Alliance %s is owning alliance. Updating info." % all_alliance_info) EveManager.update_alliance_info(all_alliance_api_info['id'], all_alliance_api_info['executor_id'], all_alliance_api_info['member_count'], False) elif standing_level in corp_standings: if int(all_alliance_info.alliance_id) in corp_standings[standing_level]: if int(corp_standings[standing_level][int(all_alliance_info.alliance_id)][ 'standing']) >= settings.BLUE_STANDING: + logger.debug("Alliance %s is blue. Updating." % all_alliance_info) EveManager.update_alliance_info(all_alliance_api_info['id'], all_alliance_api_info['executor_id'], all_alliance_api_info['member_count'], True) else: + logger.debug("Alliance %s does not meet blue standing threshold. Updating as non-blue." % all_alliance_info) EveManager.update_alliance_info(all_alliance_api_info['id'], all_alliance_api_info['executor_id'], all_alliance_api_info['member_count'], False) else: + logger.debug("Alliance %s not in standings. Updating as non-blue." % all_alliance_info) EveManager.update_alliance_info(all_alliance_api_info['id'], all_alliance_api_info['executor_id'], all_alliance_api_info['member_count'], False) else: + logger.debug("No standings found. Updating alliance %s as non-blue." % all_alliance_info) EveManager.update_alliance_info(all_alliance_api_info['id'], all_alliance_api_info['executor_id'], all_alliance_api_info['member_count'], False) else: + logger.info("Alliance %s has closed. Deleting model." % all_alliance_info) #alliance no longer exists all_alliance_info.delete() # Update corp infos for all_corp_info in EveManager.get_all_corporation_info(): + logger.debug("Validating corp model %s" % all_corp_info) if EveApiManager.check_if_corp_exists(all_corp_info.corporation_id): alliance = None corpinfo = EveApiManager.get_corporation_information(all_corp_info.corporation_id) if corpinfo['alliance']['id'] is not None: alliance = EveManager.get_alliance_info_by_id(corpinfo['alliance']['id']) + logger.debug("Got corpinfo %s and allianceinfo %s" % (corpinfo, alliance)) - if alliance is not None and all_corp_info.alliance is not None: - + if (settings.IS_CORP and all_corp_info.corporation_id == settings.CORP_ID): + logger.debug("Corp %s is owning corp. Updating." % all_corp_info) + EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, False) + elif int(all_corp_info.corporation_id) in corp_standings[standing_level]: + if int(corp_standings[standing_level][int(all_corp_info.corporation_id)][ + 'standing']) >= settings.BLUE_STANDING: + logger.debug("Corp %s is blue. Updating." % all_corp_info) + EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, True) + else: + logger.debug("Corp %s does not meet blue standing threshold. Updating as non-blue." % all_corp_info) + EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, False) + elif alliance is not None and all_corp_info.alliance is not None: + logger.debug("Corp %s not in standings - checking alliance with model %s" % (all_corp_info, alliance)) if (not settings.IS_CORP) and (all_corp_info.alliance.alliance_id == settings.ALLIANCE_ID): + logger.debug("Corp %s is member of owning alliance. Updating." % all_corp_info) EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], alliance, False) elif int(alliance.alliance_id) in corp_standings[standing_level]: if int(corp_standings[standing_level][int(alliance.alliance_id)][ 'standing']) >= settings.BLUE_STANDING: + logger.debug("Corp %s alliance %s is blue. Updating." % (all_corp_info, alliance)) EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], alliance, True) else: + logger.debug("Corp %s alliance %s does not meet blue standing threshold. Updating as non-blue." % (all_corp_info, alliance)) EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], alliance, False) else: + logger.debug("Corp %s alliance %s not found in standings. Updating as non-blue." % (all_corp_info, alliance)) EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], alliance, False) else: - if int(all_corp_info.corporation_id) in corp_standings[standing_level]: - if int(corp_standings[standing_level][int(all_corp_info.corporation_id)][ - 'standing']) >= settings.BLUE_STANDING: - EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, True) - else: - EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, False) - else: - EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, False) + logger.info("Corp model %s is not owning, member of owning alliance, or in standings. Updating as non-blue." % all_corp_info) + EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, False) else: #corp has closed + logger.info("Corp %s has closed. Deleting model." % all_corp_info) all_corp_info.delete() # Remove irrelevent corp and alliance models # Check the corps for all_corp_info in EveManager.get_all_corporation_info(): + logger.debug("Checking to delete corp model %s" % all_corp_info) if settings.IS_CORP: if all_corp_info.corporation_id != settings.CORP_ID: if not all_corp_info.is_blue: + logger.info("Corp model %s is not owning corp nor blue. Deleting." % all_corp_info) all_corp_info.delete() else: if all_corp_info.alliance is not None: if all_corp_info.alliance.alliance_id != settings.ALLIANCE_ID: if not all_corp_info.is_blue: + logger.info("Corp model %s not in owning alliance nor blue. Deleting." % all_corp_info) all_corp_info.delete() elif not all_corp_info.is_blue: + logger.info("Corp model %s has no alliance and is not blue. Deleting." % all_corp_info) all_corp_info.delete() # Check the alliances for all_alliance_info in EveManager.get_all_alliance_info(): + logger.debug("Checking to delete alliance model %s" % all_alliance_info) if settings.IS_CORP: if all_alliance_info.is_blue is not True: if ownercorpinfo['alliance']['id'] is not None: if int(all_alliance_info.alliance_id) != ownercorpinfo['alliance']['id']: + logger.info("Alliance model %s not owning corp alliance nor blue. Deleting." % all_alliance_info) all_alliance_info.delete() else: + logger.info("Alliance model %s not blue to alliance-less owning corp. Deleting." % all_alliance_info) all_alliance_info.delete() elif all_alliance_info.alliance_id != settings.ALLIANCE_ID: if all_alliance_info.is_blue is not True: + logger.info("Alliance model %s not owning alliance nor blue. Deleting." % all_alliance_info) all_alliance_info.delete() diff --git a/eveonline/forms.py b/eveonline/forms.py index 547862b9..5eddf39f 100644 --- a/eveonline/forms.py +++ b/eveonline/forms.py @@ -4,6 +4,9 @@ from django.conf import settings from services.managers.eve_api_manager import EveApiManager from eveonline.managers import EveManager +import logging + +logger = logging.getLogger(__name__) class UpdateKeyForm(forms.Form): api_id = forms.CharField(max_length=254, required=True, label="Key ID") @@ -12,6 +15,7 @@ class UpdateKeyForm(forms.Form): def clean(self): if EveManager.check_if_api_key_pair_exist(self.cleaned_data['api_id']): + logger.debug("UpdateKeyForm failed cleaning as API id %s already exists." % self.cleaned_data['api_id']) raise forms.ValidationError(u'API key already exist') check_blue = False @@ -24,20 +28,24 @@ class UpdateKeyForm(forms.Form): if settings.BLUE_API_ACCOUNT: if not EveApiManager.check_api_is_type_account(self.cleaned_data['api_id'], self.cleaned_data['api_key']): + logger.debug("UpdateKeyForm failed cleaning as API id %s does not meet blue api key account requirement." % self.cleaned_data['api_id']) raise forms.ValidationError(u'API not of type account') if not EveApiManager.check_blue_api_is_full(self.cleaned_data['api_id'], self.cleaned_data['api_key']): + logger.debug("UpdateKeyForm failed cleaning as API id %s does not meet minimum blue api access mask requirement." % self.cleaned_data['api_id']) raise forms.ValidationError(u'API supplied is too restricted. Minimum access mask is ' + str(settings.BLUE_API_MASK)) else: if settings.MEMBER_API_ACCOUNT: if not EveApiManager.check_api_is_type_account(self.cleaned_data['api_id'], self.cleaned_data['api_key']): + logger.debug("UpdateKeyForm failed cleaning as API id %s does not meet member api key account requirement." % self.cleaned_data['api_id']) raise forms.ValidationError(u'API not of type account') if not EveApiManager.check_api_is_full(self.cleaned_data['api_id'], self.cleaned_data['api_key']): + logger.debug("UpdateKeyForm failed cleaning as API id %s does not meet minimum member api access mask requirement." % self.cleaned_data['api_id']) raise forms.ValidationError(u'API supplied is too restricted. Minimum access mask is ' + str(settings.MEMBER_API_MASK)) return self.cleaned_data diff --git a/eveonline/managers.py b/eveonline/managers.py index b604b1c5..9b972c99 100644 --- a/eveonline/managers.py +++ b/eveonline/managers.py @@ -4,7 +4,9 @@ from models import EveAllianceInfo from models import EveCorporationInfo from services.managers.eve_api_manager import EveApiManager +import logging +logger = logging.getLogger(__name__) class EveManager: def __init__(self): @@ -14,7 +16,7 @@ class EveManager: def create_character(character_id, character_name, corporation_id, corporation_name, corporation_ticker, alliance_id, alliance_name, user, api_id): - + logger.debug("Creating model for character %s id %s" % (character_name, character_id)) if not EveCharacter.objects.filter(character_id=character_id).exists(): eve_char = EveCharacter() eve_char.character_id = character_id @@ -27,10 +29,13 @@ class EveManager: eve_char.user = user eve_char.api_id = api_id eve_char.save() + logger.info("Created new character model %s for user" % (eve_char, user)) + else: + logger.warn("Attempting to create existing character model with id %s" % character_id) @staticmethod def create_characters_from_list(chars, user, api_id): - + logger.debug("Creating characters from batch: %s" % chars) for char in chars.result: if not EveManager.check_if_character_exist(chars.result[char]['name']): EveManager.create_character(chars.result[char]['id'], @@ -45,9 +50,11 @@ class EveManager: @staticmethod def update_characters_from_list(chars): + logger.debug("Updating characters from list: %s" % chars.result) for char in chars.result: if EveManager.check_if_character_exist(chars.result[char]['name']): eve_char = EveManager.get_character_by_character_name(chars.result[char]['name']) + logger.debug("Got existing character model %s" % eve_char) eve_char.corporation_id = chars.result[char]['corp']['id'] eve_char.corporation_name = chars.result[char]['corp']['name'] eve_char.corporation_ticker = EveApiManager.get_corporation_ticker_from_id( @@ -55,20 +62,28 @@ class EveManager: eve_char.alliance_id = chars.result[char]['alliance']['id'] eve_char.alliance_name = chars.result[char]['alliance']['name'] eve_char.save() + logger.info("Updated character model %s" % eve_char) + else: + logger.warn("Attempting to update non-existing character model with name %s" % char['name']) @staticmethod def create_api_keypair(api_id, api_key, user_id): + logger.debug("Creating api keypair id %s for user_id %s" % (api_id, user_id)) if not EveApiKeyPair.objects.filter(api_id=api_id).exists(): api_pair = EveApiKeyPair() api_pair.api_id = api_id api_pair.api_key = api_key api_pair.user = user_id api_pair.save() + logger.info("Created api keypair id %s for user %s" % (api_id, user_id)) + else: + logger.warn("Attempting to create existing api keypair with id %s" % api_id) @staticmethod def create_alliance_info(alliance_id, alliance_name, alliance_ticker, alliance_executor_corp_id, alliance_member_count, is_blue): + logger.debug("Creating alliance info for alliance %s id %s" % (alliance_name, alliance_id)) if not EveManager.check_if_alliance_exists_by_id(alliance_id): alliance_info = EveAllianceInfo() alliance_info.alliance_id = alliance_id @@ -78,18 +93,26 @@ class EveManager: alliance_info.member_count = alliance_member_count alliance_info.is_blue = is_blue alliance_info.save() + logger.info("Created alliance model for %s" % alliance_info) + else: + logger.warn("Attempting to create existing alliance model with id %s" % alliance_id) @staticmethod def update_alliance_info(alliance_id, alliance_executor_corp_id, alliance_member_count, is_blue): + logger.debug("Updating alliance model with id %s" % alliance_id) if EveManager.check_if_alliance_exists_by_id(alliance_id): alliance_info = EveAllianceInfo.objects.get(alliance_id=alliance_id) alliance_info.executor_corp_id = alliance_executor_corp_id alliance_info.member_count = alliance_member_count alliance_info.is_blue = is_blue alliance_info.save() + logger.info("Updated alliance model %s" % alliance_info) + else: + logger.warn("Attempting to update non-existing alliance model with id %s" % alliance_id) @staticmethod def create_corporation_info(corp_id, corp_name, corp_ticker, corp_member_count, is_blue, alliance): + logger.debug("Creating corp info for corp %s id %s" % (corp_name, corp_id)) if not EveManager.check_if_corporation_exists_by_id(corp_id): corp_info = EveCorporationInfo() corp_info.corporation_id = corp_id @@ -100,45 +123,67 @@ class EveManager: if alliance: corp_info.alliance = alliance corp_info.save() + logger.info("Created corp model for %s" % corp) + else: + logger.warn("Attempting to create existing corp model with id %s" % corp_id) @staticmethod def update_corporation_info(corp_id, corp_member_count, alliance, is_blue): + logger.debug("Updating corp model with id %s" % corp_id) if EveManager.check_if_corporation_exists_by_id(corp_id): corp_info = EveCorporationInfo.objects.get(corporation_id=corp_id) corp_info.member_count = corp_member_count corp_info.alliance = alliance corp_info.is_blue = is_blue corp_info.save() + logger.info("Updated corp model %s" % corp_info) + else: + logger.warn("Attempting to update non-existant corp model with id %s" % corp_id) @staticmethod def get_api_key_pairs(user): if EveApiKeyPair.objects.filter(user=user).exists(): + logger.debug("Returning api keypairs for user %s" % user) return EveApiKeyPair.objects.filter(user=user) + else: + logger.debug("No api keypairs found for user %s" % user) @staticmethod def check_if_api_key_pair_exist(api_id): if EveApiKeyPair.objects.filter(api_id=api_id).exists(): + logger.debug("Determined api id %s exists." % api_id) return True else: + logger.debug("Determined api id %s does not exist." % api_id) return False @staticmethod def delete_api_key_pair(api_id, user_id): + logger.debug("Deleting api id %s" % api_id) if EveApiKeyPair.objects.filter(api_id=api_id).exists(): # Check that its owned by our user_id apikeypair = EveApiKeyPair.objects.get(api_id=api_id) if apikeypair.user.id == user_id: + logger.info("Deleted user %s api key id %s" % (user_id, api_id)) apikeypair.delete() + else: + logger.error("Unable to delete api: user mismatch: key id %s not owned by %s" % (api_id, user_id)) + else: + logger.warn("Unable to locate api id %s - cannot delete." % api_id) @staticmethod def delete_characters_by_api_id(api_id, user_id): + logger.debug("Deleting all characters associated with api id %s" % api_id) if EveCharacter.objects.filter(api_id=api_id).exists(): # Check that its owned by our user_id characters = EveCharacter.objects.filter(api_id=api_id) - + logger.debug("Got user %s characters %s from api %s" % (user_id, characters, api_id)) for char in characters: if char.user.id == user_id: + logger.info("Deleting user %s character %s from api %s" % (user_id, char, api_id)) char.delete() + else: + logger.error("Unable to delete character %s by api %s: user mismatch: character not owned by %s" % (char, api_id, user_id)) @staticmethod def check_if_character_exist(char_name): diff --git a/eveonline/views.py b/eveonline/views.py index e6da28a0..725b2bc7 100755 --- a/eveonline/views.py +++ b/eveonline/views.py @@ -21,27 +21,34 @@ from eveonline.models import EveCharacter from eveonline.models import EveApiKeyPair from authentication.models import AuthServicesInfo +import logging + +logger = logging.getLogger(__name__) def disable_member(user, char_id): + logger.debug("Disabling user %s with character id %s" % (user, char_id)) remove_member_permission(user, 'member') remove_user_from_group(user, settings.DEFAULT_AUTH_GROUP) remove_user_from_group(user, generate_corp_group_name( EveManager.get_character_by_id(char_id).corporation_name)) deactivate_services(user) + logger.info("Disabled member %s" % user) def disable_blue_member(user): + logger.debug("Disabling blue user %s" % user) remove_member_permission(user, 'blue_member') remove_user_from_group(user, settings.DEFAULT_BLUE_GROUP) deactivate_services(user) - + logger.info("Disabled blue user %s" % user) @login_required def add_api_key(request): + logger.debug("add_api_key called by user %s" % request.user) if request.method == 'POST': form = UpdateKeyForm(request.POST) - + logger.debug("Request type POST with form valid: %s" % form.is_valid()) if form.is_valid(): EveManager.create_api_keypair(form.cleaned_data['api_id'], form.cleaned_data['api_key'], @@ -51,8 +58,12 @@ def add_api_key(request): characters = EveApiManager.get_characters_from_api(form.cleaned_data['api_id'], form.cleaned_data['api_key']) EveManager.create_characters_from_list(characters, request.user, form.cleaned_data['api_id']) + logger.info("Successfully processed api add form for user %s" % request.user) return HttpResponseRedirect("/api_key_management/") + else: + logger.debug("Form invalid: returning to form.") else: + logger.debug("Providing empty update key form for user %s" % request.user) form = UpdateKeyForm() context = {'form': form, 'apikeypairs': EveManager.get_api_key_pairs(request.user.id)} return render_to_response('registered/addapikey.html', context, @@ -61,6 +72,7 @@ def add_api_key(request): @login_required def api_key_management_view(request): + logger.debug("api_key_management_view called by user %s" % request.user) context = {'apikeypairs': EveManager.get_api_key_pairs(request.user.id)} return render_to_response('registered/apikeymanagment.html', context, @@ -69,6 +81,7 @@ def api_key_management_view(request): @login_required def api_key_removal(request, api_id): + logger.debug("api_key_removal called by user %s for api id %s" % (request.user, api_id)) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) # Check if our users main id is in the to be deleted characters characters = EveManager.get_characters_by_owner_id(request.user.id) @@ -76,20 +89,23 @@ def api_key_removal(request, api_id): for character in characters: if character.character_id == authinfo.main_char_id: if character.api_id == api_id: - # TODO: Remove servies also + # TODO: Remove services also if authinfo.is_blue: + logger.debug("Blue user %s deleting api for main character. Disabling." % request.user) disable_blue_member(request.user) else: + logger.debug("User %s deleting api for main character. Disabling." % request.user) disable_member(request.user, authinfo.main_char_id) EveManager.delete_api_key_pair(api_id, request.user.id) EveManager.delete_characters_by_api_id(api_id, request.user.id) - + logger.info("Succesfully processed api delete request by user %s for api %s" % (request.user, api_id)) return HttpResponseRedirect("/api_key_management/") @login_required def characters_view(request): + logger.debug("characters_view called by user %s" % request.user) render_items = {'characters': EveManager.get_characters_by_owner_id(request.user.id), 'authinfo': AuthServicesInfoManager.get_auth_service_info(request.user)} return render_to_response('registered/characters.html', render_items, context_instance=RequestContext(request)) @@ -97,30 +113,34 @@ def characters_view(request): @login_required def main_character_change(request, char_id): + logger.debug("main_character_change called by user %s for character id %s" % (request.user, char_id)) if EveManager.check_if_character_owned_by_user(char_id, request.user): previousmainid = AuthServicesInfoManager.get_auth_service_info(request.user).main_char_id AuthServicesInfoManager.update_main_char_Id(char_id, request.user) # Check if character is in the alliance character_info = EveManager.get_character_by_id(char_id) corporation_info = EveManager.get_corporation_info_by_id(character_info.corporation_id) - + logger.debug("User %s changing main character to %s in corp %s" % (request.user, character_info, corporation_info)) if (settings.IS_CORP and EveManager.get_charater_corporation_id_by_id(char_id) == settings.CORP_ID) or (not settings.IS_CORP and EveManager.get_charater_alliance_id_by_id(char_id) == settings.ALLIANCE_ID): add_member_permission(request.user, 'member') add_user_to_group(request.user, settings.DEFAULT_AUTH_GROUP) add_user_to_group(request.user, generate_corp_group_name(EveManager.get_character_by_id(char_id).corporation_name)) + logger.info("User %s transitioned to full member by chaning main character to %s" % (request.user, character_info)) elif corporation_info != None: if corporation_info.is_blue: add_member_permission(request.user, 'blue_member') add_user_to_group(request.user, settings.DEFAULT_BLUE_GROUP) AuthServicesInfoManager.update_is_blue(True, request.user) + logger.info("User %s transitioned to blue by changing main character to %s" % (request.user, character_info)) else: if check_if_user_has_permission(request.user, 'member'): disable_member(request.user, previousmainid) if check_if_user_has_permission(request.user, 'blue_member'): disable_blue_member(request.user) + logger.info("User %s disabled as new main character %s not member nor blue." % (request.user, character_info)) else: # TODO: disable serivces if check_if_user_has_permission(request.user, 'member'): @@ -128,6 +148,7 @@ def main_character_change(request, char_id): if check_if_user_has_permission(request.user, 'blue_member'): disable_blue_member(request.user) + logger.info("User %s disabled as new main character %s does not have corp model to check." % (request.user, character_indo)) return HttpResponseRedirect("/characters") return HttpResponseRedirect("/characters") @@ -136,14 +157,18 @@ def main_character_change(request, char_id): @login_required @permission_required('auth.corp_stats') def corp_stats_view(request): + logger.debug("corp_stats_view called by user %s" % request.user) # Get the corp the member is in auth_info = AuthServicesInfo.objects.get(user=request.user) + logger.debug("Got user %s authservicesinfo model %s" % (request.user, auth_info)) if EveCharacter.objects.filter(character_id=auth_info.main_char_id).exists(): main_char = EveCharacter.objects.get(character_id=auth_info.main_char_id) + logger.debug("Got user %s main character model %s" % (request.user, main_char)) if EveCorporationInfo.objects.filter(corporation_id=main_char.corporation_id).exists(): current_count = 0 allcharacters = {} corp = EveCorporationInfo.objects.get(corporation_id=main_char.corporation_id) + logger.debug("Got user %s main character's corp model %s" % (request.user, corp)) all_characters = EveCharacter.objects.all() for char in all_characters: if char: @@ -157,4 +182,8 @@ def corp_stats_view(request): "currentCount": current_count, "characters": allcharacters} return render_to_response('registered/corpstats.html', context, context_instance=RequestContext(request)) + else: + logger.error("Unable to locate user %s main character's corp model with id %s. Cannot provide corp stats." % (request.user, main_char.corporation_id)) + else: + logger.error("Unable to locate user %s main character model with id %s. Cannot provide corp stats." % (request.user, auth_info.main_char_id)) return render_to_response('registered/corpstats.html', None, context_instance=RequestContext(request)) diff --git a/groupmanagement/views.py b/groupmanagement/views.py index 44042e5f..f5a6d4ad 100755 --- a/groupmanagement/views.py +++ b/groupmanagement/views.py @@ -12,10 +12,14 @@ from models import HiddenGroup from authentication.managers import AuthServicesInfoManager from eveonline.managers import EveManager +import logging + +logger = logging.getLogger(__name__) @login_required @permission_required('auth.group_management') def group_management(request): + logger.debug("group_management called by user %s" % request.user) acceptrequests = [] leaverequests = [] @@ -24,6 +28,7 @@ def group_management(request): leaverequests.append(grouprequest) else: acceptrequests.append(grouprequest) + logger.debug("Providing user %s with %s acceptrequests and %s leaverequests." % (request.user, len(acceptrequests), len(leaverequests))) render_items = {'acceptrequests': acceptrequests, 'leaverequests': leaverequests} @@ -34,13 +39,16 @@ def group_management(request): @login_required @permission_required('auth.group_management') def group_accept_request(request, group_request_id): + logger.debug("group_accept_request called by user %s for grouprequest id %s" % (request.user, group_request_id)) try: group_request = GroupRequest.objects.get(id=group_request_id) group, created = Group.objects.get_or_create(name=group_request.group.name) group_request.user.groups.add(group) group_request.user.save() group_request.delete() + logger.info("User %s accepted group request from user %s to group %s" % (request.user, group_request.user, group_request.group.name)) except: + logger.exception("Unhandled exception occured while user %s attempting to accept grouprequest id %s." % (request.user, group_request_id), exc_info=True) pass return HttpResponseRedirect("/group/management/") @@ -49,12 +57,15 @@ def group_accept_request(request, group_request_id): @login_required @permission_required('auth.group_management') def group_reject_request(request, group_request_id): + logger.debug("group_reject_request called by user %s for group request id %s" % (request.user, group_request_id)) try: group_request = GroupRequest.objects.get(id=group_request_id) if group_request: + logger.info("User %s rejected group request from user %s for %s" % (request.user, group_request.user, group_request.group.name)) group_request.delete() except: + logger.exception("Unhandled exception occured while user %s attempting to reject group request id %s." % (request.user, group_request_id), exc_info=True) pass return HttpResponseRedirect("/group/management/") @@ -63,13 +74,16 @@ def group_reject_request(request, group_request_id): @login_required @permission_required('auth.group_management') def group_leave_accept_request(request, group_request_id): + logger.debug("group_leave_accept_request called by user %s for group request id %s" % (request.user, group_request_id)) try: group_request = GroupRequest.objects.get(id=group_request_id) group, created = Group.objects.get_or_create(name=group_request.group.name) group_request.user.groups.remove(group) group_request.user.save() group_request.delete() + logger.info("User %s accepted group leave request from user %s to group %s" % (request.user, group_request.user, group_request.group.name)) except: + logger.exception("Unhandled exception occured while user %s attempting to accept group leave request id %s." % (request.user, group_request_id), exc_info=True) pass return HttpResponseRedirect("/group/management/") @@ -78,12 +92,15 @@ def group_leave_accept_request(request, group_request_id): @login_required @permission_required('auth.group_management') def group_leave_reject_request(request, group_request_id): + logger.debug("group_leave_reject_request called by user %s for group request id %s" % (request.user, group_request_id)) try: group_request = GroupRequest.objects.get(id=group_request_id) if group_request: group_request.delete() + logger.info("User %s rejected group leave request from user %s for %s" % (request.user, group_request.user, group_request.group.name)) except: + logger.exception("Unhandled exception occured while user %s attempting to reject group leave request id %s." % (request.user, group_request_id), exc_info=True) pass return HttpResponseRedirect("/group/management/") @@ -91,6 +108,7 @@ def group_leave_reject_request(request, group_request_id): @login_required def groups_view(request): + logger.debug("groups_view called by user %s" % request.user) paired_list = [] for group in Group.objects.all(): @@ -126,6 +144,7 @@ def groups_view(request): @login_required def group_request_add(request, group_id): + logger.debug("group_request_add called by user %s for group_id" % (request.user, group_id)) auth_info = AuthServicesInfoManager.get_auth_service_info(request.user) grouprequest = GroupRequest() grouprequest.status = 'pending' @@ -134,12 +153,14 @@ def group_request_add(request, group_id): grouprequest.main_char = EveManager.get_character_by_id(auth_info.main_char_id) grouprequest.leave_request = False grouprequest.save() + logger.info("Created group request for user %s to group %s" % (request.user, Group.objects.get(id=group_id))) return HttpResponseRedirect("/groups") @login_required def group_request_leave(request, group_id): + logger.debug("group_request_leave called by user %s for group id %s" % (request.user, group_id)) auth_info = AuthServicesInfoManager.get_auth_service_info(request.user) grouprequest = GroupRequest() grouprequest.status = 'pending' @@ -148,5 +169,6 @@ def group_request_leave(request, group_id): grouprequest.main_char = EveManager.get_character_by_id(auth_info.main_char_id) grouprequest.leave_request = True grouprequest.save() + logger.info("Created group leave request for user %s to group %s" % (request.user, Group.objects.get(id=group_id))) return HttpResponseRedirect("/groups") diff --git a/hrapplications/views.py b/hrapplications/views.py index 7345e7f9..3c559d72 100755 --- a/hrapplications/views.py +++ b/hrapplications/views.py @@ -16,13 +16,18 @@ from authentication.models import AuthServicesInfo from django.conf import settings from eveonline.managers import EveManager +import logging + +logger = logging.getLogger(__name__) @login_required def hr_application_management_view(request): + logger.debug("hr_application_management_view called by user %s" % request.user) personal_app = None corp_applications = None if request.user.is_superuser: + logger.debug("User %s is superuser: returning all applications." % request.user) corp_applications = HRApplication.objects.all() else: # Get the corp the member is in @@ -41,6 +46,7 @@ def hr_application_management_view(request): else: corp_applications = None except: + logger.error("Unable to determine user %s main character id %s corp. Returning no corp hrapplications." % (request.user, auth_info.main_char_id)) corp_applications = None context = {'personal_apps': HRApplication.objects.all().filter(user=request.user), 'applications': corp_applications, @@ -52,10 +58,12 @@ def hr_application_management_view(request): @login_required def hr_application_create_view(request): + logger.debug("hr_application_create_view called by user %s" % request.user) success = False if request.method == 'POST': form = HRApplicationForm(request.POST) + logger.debug("Request type POST with form valid: %s" % form.is_valid()) if form.is_valid(): application = HRApplication() application.user = request.user @@ -68,7 +76,9 @@ def hr_application_create_view(request): application.extra = form.cleaned_data['extra'] application.save() success = True + logger.info("Created HRApplication for user %s to corp %s" % (request.user, application.corp)) else: + logger.debug("Providing empty form.") form = HRApplicationForm() context = {'form': form, 'success': success} @@ -78,11 +88,15 @@ def hr_application_create_view(request): @login_required def hr_application_personal_view(request, app_id): + logger.debug("hr_application_personal_view called by user %s for app id %s" % (request.user, app_id)) if HRApplication.objects.filter(id=app_id).exists(): application = HRApplication.objects.get(id=app_id) + logger.debug("Got application id %s: %s" % (app_id, application)) if application.user != request.user: + logger.warn("HRApplication id %s user %s does not match request user %s - returning blank application." % (app_id, application.user, request.user)) application = HRApplication() else: + logger.warn("Unable to locate HRApplication matching id %s - returning blank application to user %s" % (app_id, request.user)) application = HRApplication() context = {'application': application} @@ -92,19 +106,24 @@ def hr_application_personal_view(request, app_id): @login_required def hr_application_personal_removal(request, app_id): + logger.debug("hr_application_personal_removal called by user %s for app id %s" % (request.user, app_id)) if HRApplication.objects.filter(id=app_id).exists(): application = HRApplication.objects.get(id=app_id) if application.user == request.user: application.delete() - + logger.info("Deleted HRApplication with id %s for user %s to corp %s" % (app_id, request.user, application.corp)) + else: + logger.warn("HRapplication id %s user %s does not match request user %s - refusing to delete." % (app_id, application.user, request.user)) return HttpResponseRedirect("/hr_application_management/") @login_required @permission_required('auth.human_resources') def hr_application_view(request, app_id): + logger.debug("hr_application_view called by user %s for app id %s" % (request.user, app_id)) if request.method == 'POST': form = HRApplicationCommentForm(request.POST) + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): auth_info = AuthServicesInfo.objects.get(user=request.user) @@ -114,16 +133,20 @@ def hr_application_view(request, app_id): comment.commenter_character = EveCharacter.objects.get(character_id=auth_info.main_char_id) comment.comment = form.cleaned_data['comment'] comment.save() + logger.info("Saved comment by user %s to hrapplication %s" % (request.user, comment.hrapplication)) else: + logger.debug("Returning blank HRApplication comment form.") form = HRApplicationCommentForm() if HRApplication.objects.filter(id=app_id).exists(): application = HRApplication.objects.get(id=app_id) comments = HRApplicationComment.objects.all().filter(application=application) + logger.debug("Retrieved hrpplication id %s for user %s with comments %s" % (app_id, request.user, commends)) else: application = HRApplication() comments = [] + logger.error("HRAppllication with id %s not found - returning blank applicatin to user %s" % request.user) context = {'application': application, 'comments': comments, 'comment_form': form} @@ -134,10 +157,16 @@ def hr_application_view(request, app_id): @login_required @permission_required('auth.human_resources') def hr_application_remove(request, app_id): + logger.debug("hr_application_remove called by user %s for app id %s" % (request.user, app_id)) if HRApplication.objects.filter(id=app_id).exists(): application = HRApplication.objects.get(id=app_id) if application: + logger.info("Deleted HRApplication id %s on behalf of user %s" % (app_id, request.user)) application.delete() + else: + logger.error("Unable to delete HRApplication with id %s for user %s: application is NoneType" % (app_id, request.user)) + else: + logger.error("Unable to delete HRApplication with id %s for user %s: application not found." % (app_id, request.user)) return HttpResponseRedirect("/hr_application_management/") @@ -145,6 +174,7 @@ def hr_application_remove(request, app_id): @login_required @permission_required('auth.human_resources') def hr_application_approve(request, app_id): + logger.debug("hr_application_approve called by user %s for app id %s" % (request.user, app_id)) if HRApplication.objects.filter(id=app_id).exists(): auth_info = AuthServicesInfo.objects.get(user=request.user) application = HRApplication.objects.get(id=app_id) @@ -152,6 +182,9 @@ def hr_application_approve(request, app_id): application.reviewer_user = request.user application.reviewer_character = EveCharacter.objects.get(character_id=auth_info.main_char_id) application.save() + logger.info("HRApplication for user %s to corp %s approved by %s" % (application.user, application.corp, request.user)) + else: + logger.error("User %s unable to approve HRApplication id %s - hrapplication with that id not found." % (request.user, app_id)) return HttpResponseRedirect("/hr_application_management/") @@ -159,6 +192,7 @@ def hr_application_approve(request, app_id): @login_required @permission_required('auth.human_resources') def hr_application_reject(request, app_id): + logger.debug("hr_application_reject called by user %s for app id %s" % (request.user, app_id)) if HRApplication.objects.filter(id=app_id).exists(): auth_info = AuthServicesInfo.objects.get(user=request.user) application = HRApplication.objects.get(id=app_id) @@ -166,6 +200,9 @@ def hr_application_reject(request, app_id): application.reviewer_user = request.user application.reviewer_character = EveCharacter.objects.get(character_id=auth_info.main_char_id) application.save() + logger.info("HRApplication for user %s to corp %s rejected by %s" % (application.user, application.corp, request.user)) + else: + logger.error("User %s unable to reject HRApplication id %s - hrapplication with that id not found." % (request.user, app_id)) return HttpResponseRedirect("/hr_application_management/") @@ -173,33 +210,42 @@ def hr_application_reject(request, app_id): @login_required @permission_required('auth.human_resources') def hr_application_search(request): + logger.debug("hr_application_search called by user %s" % request.user) if request.method == 'POST': form = HRApplicationSearchForm(request.POST) + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): # Really dumb search and only checks character name # This can be improved but it does the job for now searchstring = form.cleaned_data['search_string'] applications = [] + logger.debug("Searching for application with character name %s for user %s" % (searchstring, request.user)) for application in HRApplication.objects.all(): if searchstring in application.character_name: applications.append(application) + logger.info("Found %s HRApplications for user %s matching search string %s" % (len(applications), request.user, searchstring)) context = {'applications': applications, 'search_form': HRApplicationSearchForm()} return render_to_response('registered/hrapplicationsearchview.html', context, context_instance=RequestContext(request)) else: + logger.debug("Returning empty search form for user %s" % request.user) return HttpResponseRedirect("/hr_application_management/") @login_required @permission_required('auth.human_resources') def hr_application_mark_in_progress(request, app_id): + logger.debug("hr_application_mark_in_progress called by user %s for app id %s" % (request.user, app_id)) if HRApplication.objects.filter(id=app_id).exists(): auth_info = AuthServicesInfo.objects.get(user=request.user) application = HRApplication.objects.get(id=app_id) application.reviewer_inprogress_character = EveCharacter.objects.get(character_id=auth_info.main_char_id) application.save() + logger.info("Marked HRApplication for user %s to corp %s in progress by user %s" % (application.user, application.corp, request.user)) + else: + logger.error("Unable to mark HRApplication id %s in progress by user %s - hrapplication matching id not found." % (app_id, request.user)) return HttpResponseRedirect("/hr_application_view/" + str(app_id)) diff --git a/portal/views.py b/portal/views.py index 7ee8e625..32ec7309 100755 --- a/portal/views.py +++ b/portal/views.py @@ -5,15 +5,20 @@ from django.contrib.auth.decorators import login_required from eveonline.managers import EveManager from authentication.managers import AuthServicesInfoManager +import logging + +logger = logging.getLogger(__name__) # Create your views here. def index_view(request): + logger.debug("index_view called by user %s" % request.user) return render_to_response('public/index.html', None, context_instance=RequestContext(request)) @login_required def dashboard_view(request): + logger.debug("dashboard_view called by user %s" % request.user) render_items = {'characters': EveManager.get_characters_by_owner_id(request.user.id), 'authinfo': AuthServicesInfoManager.get_auth_service_info(request.user)} return render_to_response('registered/dashboard.html', render_items, context_instance=RequestContext(request)) @@ -21,4 +26,5 @@ def dashboard_view(request): @login_required def help_view(request): + logger.debug("help_view called by user %s" % request.user) return render_to_response('registered/help.html', None, context_instance=RequestContext(request)) diff --git a/registration/forms.py b/registration/forms.py index da570c7c..34533811 100644 --- a/registration/forms.py +++ b/registration/forms.py @@ -2,6 +2,9 @@ from django import forms from django.contrib.auth.models import User import re +import logging + +logger = logging.getLogger(__name__) class RegistrationForm(forms.Form): username = forms.CharField(max_length=30, required=True) @@ -12,24 +15,29 @@ class RegistrationForm(forms.Form): def clean(self): if ' ' in self.cleaned_data['username']: + logger.error("RegistrationForm username contains spaces. Raising ValidationError. Username: %s" % self.cleaned_data['username']) raise forms.ValidationError(u'Username cannot contain a space') # We attempt to get the user object if we succeed we know email as been used try: User.objects.get(email=self.cleaned_data['email']) + logger.error("RegistrationForm email already registered. Raising ValidationError") raise forms.ValidationError(u'Email as already been used') except: pass if not re.match("^\w+$", self.cleaned_data['username']): + logger.error("RegistrationForm username contains non-alphanumeric characters. Raising ValueError. Username: %s" % self.cleaned_data['username']) raise forms.ValidationError(u'Username contains illegal characters') if 'password' in self.cleaned_data and 'password_again' in self.cleaned_data: if self.cleaned_data['password'] != self.cleaned_data['password_again']: + logger.error("RegistrationForm password mismatch. Raising ValueError") raise forms.ValidationError(u'Passwords do not match') if 'email' in self.cleaned_data and 'email_again' in self.cleaned_data: if self.cleaned_data['email'] != self.cleaned_data['email_again']: + logger.error("RegistrationForm email mismatch. Raising ValidationError") raise forms.ValidationError(u'Emails do not match') return self.cleaned_data diff --git a/registration/views.py b/registration/views.py index 5ed7b0fb..929b988f 100644 --- a/registration/views.py +++ b/registration/views.py @@ -5,11 +5,15 @@ from django.template import RequestContext from forms import RegistrationForm +import logging + +logger = logging.getLogger(__name__) def register_user_view(request): + logger.debug("register_user_view called by user %s" % request.user) if request.method == 'POST': form = RegistrationForm(request.POST) - + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): if not User.objects.filter(username=form.cleaned_data['username']).exists(): @@ -17,14 +21,19 @@ def register_user_view(request): form.cleaned_data['email'], form.cleaned_data['password']) user.save() + logger.info("Created new user %s" % user) return HttpResponseRedirect("/dashboard") else: + logger.error("Unable to register new user: username %s already exists." % form.cleaned_data['username']) return render_to_response('public/register.html', {'form': form, 'error': True} , context_instance=RequestContext(request)) + else: + logger.debug("Registration form invalid. Returning for user %s to make corrections." % request.user) else: + logger.debug("Returning blank registration form.") form = RegistrationForm() - return render_to_response('public/register.html', {'form': form}, context_instance=RequestContext(request)) \ No newline at end of file + return render_to_response('public/register.html', {'form': form}, context_instance=RequestContext(request)) diff --git a/srp/views.py b/srp/views.py index 2ae7061e..930820f0 100755 --- a/srp/views.py +++ b/srp/views.py @@ -16,6 +16,9 @@ from form import SrpFleetUserRequestForm from form import SrpFleetUpdateCostForm from form import SrpFleetMainUpdateForm +import logging + +logger = logging.getLogger(__name__) def srp_util_test(user): return check_if_user_has_permission(user, 'member') or check_if_user_has_permission(user, 'blue_member') @@ -24,6 +27,7 @@ def srp_util_test(user): @login_required @user_passes_test(srp_util_test) def srp_management(request): + logger.debug("srp_management called by user %s" % request.user) totalcost = 0 runningcost = 0 price_pair = {} @@ -32,7 +36,9 @@ def srp_management(request): totalcost = totalcost + fleet_data.srp_total_amount runningcost = runningcost + fleet_data.srp_total_amount price_pair[fleet_main.id] = runningcost + logger.debug("Determined SRP fleet %s costs %s" % (fleet_main.id, runningcost)) runningcost = 0 + logger.debug("Determined total outstanding SRP cost %s" % totalcost) context = {"srpfleets": SrpFleetMain.objects.filter(fleet_srp_status=""), "totalcost": totalcost, "price_pair": price_pair} @@ -42,6 +48,7 @@ def srp_management(request): @login_required @user_passes_test(srp_util_test) def srp_management_all(request): + logger.debug("srp_management_all called by user %s" % request.user) totalcost = 0 runningcost = 0 price_pair = {} @@ -50,7 +57,9 @@ def srp_management_all(request): totalcost = totalcost + fleet_data.srp_total_amount runningcost = runningcost + fleet_data.srp_total_amount price_pair[fleet_main.id] = runningcost + logger.debug("Determined SRP fleet %s costs %s" % (fleet_main.id, runningcost)) runningcost = 0 + logger.debug("Determined all-time total SRP cost %s" % totalcost) context = {"srpfleets": SrpFleetMain.objects.all(), "totalcost": totalcost, "price_pair": price_pair} return render_to_response('registered/srpmanagement.html', context, context_instance=RequestContext(request)) @@ -59,11 +68,13 @@ def srp_management_all(request): @login_required @user_passes_test(srp_util_test) def srp_fleet_view(request, fleet_id): + logger.debug("srp_fleet_view called by user %s for fleet id %s" % (request.user, fleet_id)) if SrpFleetMain.objects.filter(id=fleet_id).exists(): fleet_main = SrpFleetMain.objects.get(id=fleet_id) totalcost = 0 for fleet_data in SrpUserRequest.objects.filter(srp_fleet_main=fleet_main): totalcost = totalcost + fleet_data.srp_total_amount + logger.debug("Determiend fleet id %s total cost %s" % (fleet_id, totalcost)) context = {"fleet_id": fleet_id, "fleet_status": fleet_main.fleet_srp_status, "srpfleetrequests": SrpUserRequest.objects.filter(srp_fleet_main=fleet_main), @@ -72,18 +83,20 @@ def srp_fleet_view(request, fleet_id): return render_to_response('registered/srpfleetdata.html', context, context_instance=RequestContext(request)) else: + logger.error("Unable to view SRP fleet id %s for user %s - fleet matching id not found." % (fleet_id, request.user)) return HttpResponseRedirect("/srp") @login_required @permission_required('auth.srp_management') def srp_fleet_add_view(request): + logger.debug("srp_fleet_add_view called by user %s" % request.user) completed = False completed_srp_code = "" if request.method == 'POST': form = SrpFleetMainForm(request.POST) - + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) character = EveManager.get_character_by_id(authinfo.main_char_id) @@ -99,8 +112,10 @@ def srp_fleet_add_view(request): completed = True completed_srp_code = srp_fleet_main.fleet_srp_code + logger.info("Created SRP Fleet %s by user %s" % (srp_fleet_main.fleet_name, request.user)) else: + logger.debug("Returning blank SrpFleetMainForm") form = SrpFleetMainForm() render_items = {'form': form, "completed": completed, "completed_srp_code": completed_srp_code} @@ -111,47 +126,59 @@ def srp_fleet_add_view(request): @login_required @permission_required('auth.srp_management') def srp_fleet_remove(request, fleet_id): + logger.debug("srp_fleet_remove called by user %s for fleet id %s" % (request.user, fleet_id)) if SrpFleetMain.objects.filter(id=fleet_id).exists(): srpfleetmain = SrpFleetMain.objects.get(id=fleet_id) srpfleetmain.delete() - + logger.info("SRP Fleet %s deleted by user %s" % (srpfleetmain.fleet_name, request.user)) + else: + logger.error("Unable to delete SRP fleet id %s for user %s - fleet matching id not found." % (fleet_id, request.user)) return HttpResponseRedirect("/srp") @login_required @permission_required('auth.srp_management') def srp_fleet_mark_completed(request, fleet_id): + logger.debug("srp_fleet_mark_completed called by user %s for fleet id %s" % (request.user, fleet_id)) if SrpFleetMain.objects.filter(id=fleet_id).exists(): srpfleetmain = SrpFleetMain.objects.get(id=fleet_id) srpfleetmain.fleet_srp_status = "Completed" srpfleetmain.save() - + logger.info("Marked SRP Fleet %s as completed by user %s" % (srpfleetmain.fleet_name, request.user)) + else: + logger.error("Unable to mark SRP fleet with id %s as completed for user %s - fleet matching id not found." % (fleet_id, request.user)) return HttpResponseRedirect("/srp_fleet_view/" + str(fleet_id)) @login_required @permission_required('auth.srp_management') def srp_fleet_mark_uncompleted(request, fleet_id): + logger.debug("srp_fleet_mark_uncompleted called by user %s for fleet id %s" % (request.user, fleet_id)) if SrpFleetMain.objects.filter(id=fleet_id).exists(): srpfleetmain = SrpFleetMain.objects.get(id=fleet_id) srpfleetmain.fleet_srp_status = "" srpfleetmain.save() - + logger.info("Marked SRP Fleet %s as incomplete for user %s" % (fleet_id, request.user)) + else: + logger.error("Unable to mark SRP Fleet id %s as incomplete for user %s - fleet matching id not found." % (fleet_id, request.user)) return HttpResponseRedirect("/srp_fleet_view/" + str(fleet_id)) @login_required @user_passes_test(srp_util_test) def srp_request_view(request, fleet_srp): + logger.debug("srp_request_view called by user %s for fleet srp code %s" % (request.user, fleet_srp)) completed = False no_srp_code = False srp_code = "" if SrpFleetMain.objects.filter(fleet_srp_code=fleet_srp).exists() is False: no_srp_code = True + logger.error("Unable to locate SRP Fleet using code %s for user %s" % (fleet_srp, request.user)) if request.method == 'POST': form = SrpFleetUserRequestForm(request.POST) + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) @@ -166,8 +193,10 @@ def srp_request_view(request, fleet_srp): srp_request.save() completed = True + logger.info("Created SRP Request on behalf of user %s for fleet name %s" % (request.user, srp_fleet_main.fleet_name)) else: + logger.debug("Returning blank SrpFleetUserRequestForm") form = SrpFleetUserRequestForm() render_items = {'form': form, "completed": completed, "no_srp_code": no_srp_code} @@ -178,14 +207,17 @@ def srp_request_view(request, fleet_srp): @login_required @permission_required('auth.srp_management') def srp_request_remove(request, srp_request_id): + logger.debug("srp_request_remove called by user %s for srp request id %s" % (request.user, srp_request_id)) stored_fleet_view = None if SrpUserRequest.objects.filter(id=srp_request_id).exists(): srpuserrequest = SrpUserRequest.objects.get(id=srp_request_id) stored_fleet_view = srpuserrequest.srp_fleet_main.id srpuserrequest.delete() + logger.info("Deleted SRP request id %s for user %s" % (srp_request_id, request.user)) if stored_fleet_view is None: + logger.error("Unable to delete srp request id %s for user %s - request matching id not found." % (srp_request_id, request.user)) return HttpResponseRedirect("/srp") else: return HttpResponseRedirect("/srp_fleet_view/" + str(stored_fleet_view)) @@ -194,6 +226,7 @@ def srp_request_remove(request, srp_request_id): @login_required @permission_required('auth.srp_management') def srp_request_approve(request, srp_request_id): + logger.debug("srp_request_approve called by user %s for srp request id %s" % (request.user, srp_request_id)) stored_fleet_view = None if SrpUserRequest.objects.filter(id=srp_request_id).exists(): @@ -201,8 +234,9 @@ def srp_request_approve(request, srp_request_id): stored_fleet_view = srpuserrequest.srp_fleet_main.id srpuserrequest.srp_status = "Approved" srpuserrequest.save() - + logger.info("Approved SRP request id %s for character %s by user %s" % (srp_request_id, srpuserrequest.character, request.user)) if stored_fleet_view is None: + logger.error("Unable to approve srp request id %s on behalf of user %s - request matching id not found." % (srp_request_id, request.user)) return HttpResponseRedirect("/srp") else: return HttpResponseRedirect("/srp_fleet_view/" + str(stored_fleet_view)) @@ -211,6 +245,7 @@ def srp_request_approve(request, srp_request_id): @login_required @permission_required('auth.srp_management') def srp_request_reject(request, srp_request_id): + logger.debug("srp_request_reject called by user %s for srp request id %s" % (request.user, srp_request_id)) stored_fleet_view = None if SrpUserRequest.objects.filter(id=srp_request_id).exists(): @@ -218,8 +253,10 @@ def srp_request_reject(request, srp_request_id): stored_fleet_view = srpuserrequest.srp_fleet_main.id srpuserrequest.srp_status = "Rejected" srpuserrequest.save() + logger.info("SRP request id %s for character %s rejected by %s" % (srp_request_id, srpuserrequest.character, request.user)) if stored_fleet_view is None: + logger.error("Unable to reject SRP request id %s on behalf of user %s - request matching id not found." % (srp_request_id, request.user)) return HttpResponseRedirect("/srp") else: return HttpResponseRedirect("/srp_fleet_view/" + str(stored_fleet_view)) @@ -228,22 +265,26 @@ def srp_request_reject(request, srp_request_id): @login_required @permission_required('auth.srp_management') def srp_request_update_amount_view(request, fleet_srp_request_id): + logger.debug("srp_request_update_amount_view called by user %s for fleet srp request id %s" % (request.user, fleet_srp_request_id)) no_srp_code = False srp_code = "" if SrpUserRequest.objects.filter(id=fleet_srp_request_id).exists() is False: + logger.error("Unable to locate SRP request id %s for user %s" % (fleet_srp_request_id, request.user)) no_srp_code = True if request.method == 'POST': form = SrpFleetUpdateCostForm(request.POST) - + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): srp_request = SrpUserRequest.objects.get(id=fleet_srp_request_id) srp_request.srp_total_amount = form.cleaned_data['srp_total_amount'] srp_request.save() + logger.info("Updated srp request id %s total to %s by user %s" % (fleet_srp_request_id, form.cleaned_data['srp_total_amount'], request.user)) return HttpResponseRedirect("/srp_fleet_view/" + str(srp_request.srp_fleet_main.id)) else: + logger.debug("Returning blank SrpFleetUpdateCostForm") form = SrpFleetUpdateCostForm() render_items = {'form': form, "no_srp_code": no_srp_code} @@ -255,19 +296,24 @@ def srp_request_update_amount_view(request, fleet_srp_request_id): @login_required @permission_required('auth.srp_management') def srp_fleet_edit_view(request, fleet_id): + logger.debug("srp_fleet_edit_view called by user %s for fleet id %s" % (request.user, fleet_id)) no_fleet_id = False form = None if SrpFleetMain.objects.filter(id=fleet_id).exists(): if request.method == 'POST': form = SrpFleetMainUpdateForm(request.POST) + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): srpfleetmain = SrpFleetMain.objects.get(id=fleet_id) srpfleetmain.fleet_srp_aar_link = form.cleaned_data['fleet_aar_link'] srpfleetmain.save() + logger.info("User %s edited SRP Fleet %s" % (request.user, srpfleetmain.fleet_name)) return HttpResponseRedirect("/srp") else: + logger.debug("Returning blank SrpFleetMainUpdateForm") form = SrpFleetMainUpdateForm() else: + logger.error("Unable to edit srp fleet id %s for user %s - fleet matching id not found." % (fleet_id, request.user)) no_fleet_id = True render_items = {'form': form, "no_fleet_id": no_fleet_id} diff --git a/timerboard/views.py b/timerboard/views.py index 51296cf4..1d9f0fbb 100755 --- a/timerboard/views.py +++ b/timerboard/views.py @@ -13,6 +13,9 @@ from eveonline.managers import EveManager from form import TimerForm from models import Timer +import logging + +logger = logging.getLogger(__name__) def timer_util_test(user): return check_if_user_has_permission(user, 'member') or check_if_user_has_permission(user, 'blue_member') @@ -22,13 +25,14 @@ def timer_util_test(user): @user_passes_test(timer_util_test) @permission_required('auth.timer_view') def timer_view(request): + logger.debug("timer_view called by user %s" % request.user) timer_list = Timer.objects.all() closest_timer = None if timer_list: closest_timer = \ sorted(list(Timer.objects.all()), key=lambda d: abs(datetime.datetime.now() - d.eve_time.replace(tzinfo=None)))[ 0] - + logger.debug("Determined closest timer is %s" % closest_timer) render_items = {'timers': Timer.objects.all(), 'closest_timer': closest_timer} @@ -38,20 +42,21 @@ def timer_view(request): @login_required @permission_required('auth.timer_management') def add_timer_view(request): + logger.debug("add_timer_view called by user %s" % request.user) if request.method == 'POST': form = TimerForm(request.POST) - + logger.debug("Request type POST contains form valid: %s" % form.is_valid()) if form.is_valid(): # Get character auth_info = AuthServicesInfoManager.get_auth_service_info(request.user) character = EveManager.get_character_by_id(auth_info.main_char_id) corporation = EveManager.get_corporation_info_by_id(character.corporation_id) - + logger.debug("Determined timer add request on behalf of character %s corporation %s" % (character, corporation)) # calculate future time future_time = datetime.timedelta(days=form.cleaned_data['days_left'], hours=form.cleaned_data['hours_left'], minutes=form.cleaned_data['minutes_left']) current_time = datetime.datetime.utcnow() eve_time = current_time + future_time - + logger.debug("Determined timer eve time is %s - current time %s, adding %s" % (eve_time, current_time, future_time)) # handle valid form timer = Timer() timer.details = form.cleaned_data['details'] @@ -65,8 +70,10 @@ def add_timer_view(request): timer.eve_corp = corporation timer.user = request.user timer.save() + logger.info("Created new timer in %s at %s by user %s" % (timer.system, timer.eve_time, request.user)) return HttpResponseRedirect("/timers/") else: + logger.debug("Returning new TimerForm") form = TimerForm() render_items = {'form': form} @@ -77,7 +84,11 @@ def add_timer_view(request): @login_required @permission_required('auth.timer_management') def remove_timer(request, timer_id): + logger.debug("remove_timer called by user %s for timer id %s" % (request.user, timer_id)) if Timer.objects.filter(id=timer_id).exists(): timer = Timer.objects.get(id=timer_id) timer.delete() + logger.debug("Deleting timer id %s by user %s" % (timer_id, request.user)) + else: + logger.error("Unable to delete timer id %s for user %s - timer matching id not found." % (timer_id, request.user)) return HttpResponseRedirect("/timers/") diff --git a/util/__init__.py b/util/__init__.py index c3821670..f9205361 100755 --- a/util/__init__.py +++ b/util/__init__.py @@ -6,6 +6,9 @@ from django.contrib.auth.models import Group from django.contrib.auth.models import Permission from django.conf import settings +import logging + +logger = logging.getLogger(__name__) def bootstrap_permissions(): ct = ContentType.objects.get_for_model(User) @@ -20,18 +23,22 @@ def bootstrap_permissions(): Permission.objects.get_or_create(codename="srp_management", content_type=ct, name="srp_management") Group.objects.get_or_create(name=settings.DEFAULT_AUTH_GROUP) Group.objects.get_or_create(name=settings.DEFAULT_BLUE_GROUP) + logger.info("Bootstrapped permissions for auth and created default groups.") def add_member_permission(user, permission): + logger.debug("Adding permission %s to member %s" % (permission, user)) ct = ContentType.objects.get_for_model(User) stored_permission, created = Permission.objects.get_or_create(codename=permission, content_type=ct, name=permission) user = User.objects.get(username=user.username) user.user_permissions.add(stored_permission) + logger.info("Added permission %s to user %s" % (permission, user)) user.save() def remove_member_permission(user, permission): + logger.debug("Removing permission %s from member %s" % (permission, user)) ct = ContentType.objects.get_for_model(User) stored_permission, created = Permission.objects.get_or_create(codename=permission, content_type=ct, name=permission) @@ -41,6 +48,9 @@ def remove_member_permission(user, permission): if user.has_perm('auth.' + permission): user.user_permissions.remove(stored_permission) user.save() + logger.info("Removed permission %s from member %s" % (permission, user)) + else: + logger.warn("Attempting to remove permission user %s does not have: %s" % (user, permission)) def check_if_user_has_permission(user, permission): diff --git a/util/common_task.py b/util/common_task.py index fe312f95..41002f08 100755 --- a/util/common_task.py +++ b/util/common_task.py @@ -9,40 +9,60 @@ from services.managers.ipboard_manager import IPBoardManager from services.managers.teamspeak3_manager import Teamspeak3Manager from services.managers.discord_manager import DiscordManager +import logging + +logger = logging.getLogger(__name__) def add_user_to_group(user, groupname): + logger.debug("Addung user %s to group %s" % (user, groupname)) user = User.objects.get(username=user.username) group, created = Group.objects.get_or_create(name=groupname) + if created: + logger.info("Created new group %s" % groupname) user.groups.add(group) user.save() + logger.info("Added user %s to group %s" % (user, group)) def remove_user_from_group(user, groupname): + logger.debug("Removing user %s from group %s" % (user, groupname)) user = User.objects.get(username=user.username) group, created = Group.objects.get_or_create(name=groupname) + if created: + logger.warn("Created new group %s during attempt to remove user %s from it. This shouldn't have happened." % (group, user)) if user.groups.filter(name=groupname): user.groups.remove(group) user.save() + logger.info("Removed user %s from group %s" % (user, group)) + else: + logger.warn("Unable to remove user %s from groyp %s - user not in group." % (user, group)) def deactivate_services(user): + logger.debug("Deactivating services for user %s" % user) authinfo = AuthServicesInfoManager.get_auth_service_info(user) if authinfo.mumble_username and authinfo.mumble_username != "": + logger.debug("User %s has mumble account %s. Deleting." % (user, authinfo.mumble_username)) MumbleManager.delete_user(authinfo.mumble_username) AuthServicesInfoManager.update_user_mumble_info("", "", user) if authinfo.jabber_username and authinfo.jabber_username != "": + logger.debug("User %s has jabber account %s. Deleting." % (user, authinfo.jabber_username)) OpenfireManager.delete_user(authinfo.jabber_username) AuthServicesInfoManager.update_user_jabber_info("", "", user) if authinfo.forum_username and authinfo.forum_username != "": + logger.debug("User %s has forum account %s. Deleting." % (user, authinfo.forum_username)) Phpbb3Manager.disable_user(authinfo.forum_username) AuthServicesInfoManager.update_user_forum_info("", "", user) if authinfo.ipboard_username and authinfo.ipboard_username != "": + logger.debug("User %s has ipboard account %s. Deleting." % (user, authinfo.ipboard_username)) IPBoardManager.disable_user(authinfo.ipboard_username) AuthServicesInfoManager.update_user_forum_info("", "", user) if authinfo.teamspeak3_uid and authinfo.teamspeak3_uid != "": + logger.debug("User %s has mumble account %s. Deleting." % (user, authinfo.teamspeak3_uid)) Teamspeak3Manager.delete_user(authinfo.teamspeak3_uid) AuthServicesInfoManager.update_user_teamspeak3_info("", "", user) if authinfo.discord_uid and authinfo.discord_uid != "": + logger.debug("User %s has discord account %s. Deleting." % (user, authinfo.discord_uid)) DiscordManager.delete_user(authinfo.discord_uid) AuthServicesInfoManager.update_user_discord_info("", user)