diff --git a/.gitignore b/.gitignore index 111ee21b..9f48ec85 100644 --- a/.gitignore +++ b/.gitignore @@ -45,7 +45,7 @@ coverage.xml *.pot # Django stuff: -*.log +*.log* # Sphinx documentation docs/_build/ diff --git a/alliance_auth/settings.py.example b/alliance_auth/settings.py.example index 67535b05..dde3385c 100755 --- a/alliance_auth/settings.py.example +++ b/alliance_auth/settings.py.example @@ -188,6 +188,17 @@ EMAIL_HOST_USER = os.environ.get('AA_EMAIL_HOST_USER', '') EMAIL_HOST_PASSWORD = os.environ.get('AA_EMAIL_HOST_PASSWORD', '') EMAIL_USE_TLS = 'True' == os.environ.get('AA_EMAIL_USE_TLS', 'True') +#################### +# Front Page Links +#################### +# KILLBOARD_URL - URL for your killboard. Blank to hide link +# MEDIA_URL - URL for your media page (youtube etc). Blank to hide link +# FORUM_URL - URL for your forums. Blank to hide link +#################### +KILLBOARD_URL = os.environ.get('AA_KILLBOARD_URL', '') +MEDIA_URL = os.environ.get('AA_MEDIA_URL', '') +FORUM_URL = os.environ.get('AA_FORUM_URL', '') + ######################### # Default Group Settings ######################### @@ -279,12 +290,10 @@ JACK_KNIFE_URL = os.environ.get('AA_JACK_KNIFE_URL', 'http://ridetheclown.com/ev ##################### # Forum Configuration ##################### -# FORUM_URL - Forum url location # IPBOARD_ENDPOINT - Api endpoint if using ipboard # IPBOARD_APIKEY - Api key to interact with ipboard # IPBOARD_APIMODULE - Module for alliance auth *leave alone* ##################### -FORUM_URL = os.environ.get('AA_FORUM_URL', "http://yourdomain.com") IPBOARD_ENDPOINT = os.environ.get('AA_IPBOARD_ENDPOINT', 'yourdomain.com/interface/board/index.php') IPBOARD_APIKEY = os.environ.get('AA_IPBOARD_APIKEY', 'somekeyhere') IPBOARD_APIMODULE = 'aa' @@ -347,3 +356,96 @@ TEAMSPEAK3_PUBLIC_URL = os.environ.get('AA_TEAMSPEAK3_PUBLIC_URL', 'yourdomain.c DISCORD_SERVER_ID = os.environ.get('AA_DISCORD_SERVER_ID', '') DISCORD_USER_EMAIL = os.environ.get('AA_DISCORD_USER_EMAIL', '') DISCORD_USER_PASSWORD = os.environ.get('AA_DISCORD_USER_PASSWORD', '') + +##################################### +# Logging Configuration +##################################### +# Set log_file and console level to desired state: +# DEBUG - basically stack trace, explains every step +# INFO - model creation, deletion, updates, etc +# WARN - unexpected function outcomes that do not impact user +# ERROR - unexcpeted function outcomes which prevent user from achieving desired outcome +# EXCEPTION - something critical went wrong, unhandled +##################################### +# Recommended level for log_file is INFO, console is DEBUG +# Change log level of individual apps below to narrow your debugging +##################################### +LOGGING = { + 'version': 1, + 'disable_existing_loggers': False, + 'formatters': { + 'verbose': { + 'format' : "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s", + 'datefmt' : "%d/%b/%Y %H:%M:%S" + }, + 'simple': { + 'format': '%(levelname)s %(message)s' + }, + }, + 'handlers': { + 'log_file': { + 'level': 'INFO', # edit this line to change logging level to file + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': os.path.join(BASE_DIR,'allianceauth.log'), + 'formatter': 'verbose', + 'maxBytes': 1024*1024*5, # edit this line to change max log file size + 'backupCount': 5, # edit this line to change number of log backups + }, + 'console': { + 'level': 'DEBUG', # edit this line to change logging level to console + 'class': 'logging.StreamHandler', + 'formatter': 'verbose', + } + }, + 'loggers': { + 'authentication': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'celerytask': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'eveonline': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'groupmanagement': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'hrapplications': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'portal': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'registration': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'services': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'srp': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'timerboard': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'util': { + 'handlers': ['log_file', 'console'], + 'level': 'DEBUG', + }, + 'django': { + 'handlers': ['log_file', 'console'], + 'level': 'ERROR', + }, + } +} + diff --git a/authentication/managers.py b/authentication/managers.py index 0cea7a07..c79a36cd 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,97 @@ 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)) + else: + 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 78063121..f1c26465 100755 --- a/celerytask/tasks.py +++ b/celerytask/tasks.py @@ -9,7 +9,7 @@ from services.managers.mumble_manager import MumbleManager from services.managers.phpbb3_manager import Phpbb3Manager from services.managers.ipboard_manager import IPBoardManager from services.managers.teamspeak3_manager import Teamspeak3Manager -from services.managers.discord_manager import DiscordManager +from services.managers.discord_manager import DiscordManager, DiscordAPIManager from services.models import AuthTS from services.models import TSgroup from authentication.models import AuthServicesInfo @@ -25,84 +25,105 @@ from util.common_task import generate_corp_group_name from eveonline.models import EveCharacter from eveonline.models import EveCorporationInfo from authentication.managers import AuthServicesInfoManager +from services.models import DiscordAuthToken + +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 = {} @@ -112,157 +133,214 @@ 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) syncgroups = SyncGroupCache.objects.filter(user=user) authserviceinfo = AuthServicesInfo.objects.get(user=user) groups = [] for syncgroup in syncgroups: groups.append(str(syncgroup.groupname)) + 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): + logger.debug("add_to_database for user %s called. groups %s - syncgroups %s" % (user, groups, syncgroups)) authserviceinfo = None try: authserviceinfo = AuthServicesInfo.objects.get(user=user) + logger.debug("Got authservicesinfo object %s" % authserviceinfo) except: + logger.debug("No authservicesinfo object found for user %s" % user) pass if authserviceinfo: authserviceinfo = AuthServicesInfo.objects.get(user=user) if authserviceinfo.teamspeak3_uid and authserviceinfo.teamspeak3_uid != "": - update_teamspeak3_groups(user) + logger.debug("Updating user TS groups.") + update_teamspeak3_groups(user) for group in groups: if authserviceinfo.jabber_username and authserviceinfo.jabber_username != "": if syncgroups.filter(groupname=group.name).filter(servicename="openfire").exists() is not True: + logger.debug("User %s has jabber username %s - missing group %s." % (user, authserviceinfo.jabber_username, group.name)) create_syncgroup_for_user(user, group.name, "openfire") update_jabber_groups(user) if authserviceinfo.mumble_username and authserviceinfo.mumble_username != "": if syncgroups.filter(groupname=group.name).filter(servicename="mumble").exists() is not True: + logger.debug("User %s has mumble username %s - missing group %s." % (user, authserviceinfo.mumble_username, group.name)) create_syncgroup_for_user(user, group.name, "mumble") update_mumble_groups(user) if authserviceinfo.forum_username and authserviceinfo.forum_username != "": if syncgroups.filter(groupname=group.name).filter(servicename="phpbb3").exists() is not True: + logger.debug("User %s has phpbb username %s - missing group %s." % (user, authserviceinfo.forum_username, group.name)) create_syncgroup_for_user(user, group.name, "phpbb3") update_forum_groups(user) if authserviceinfo.ipboard_username and authserviceinfo.ipboard_username != "": if syncgroups.filter(groupname=group.name).filter(servicename="ipboard").exists() is not True: + logger.debug("User %s has ipboard username %s - missing group %s." % (user, authserviceinfo.ipboard_username, group.name)) create_syncgroup_for_user(user, group.name, "ipboard") update_ipboard_groups(user) if authserviceinfo.discord_uid and authserviceinfo.discord_uid != "": if syncgroups.filter(groupname=group.name).filter(servicename="discord").exists() is not True: + logger.debug("User %s has discord uid %s - missing group %s." % (user, authserviceinfo.discord_uid, group.name)) create_syncgroup_for_user(user, group.name, "discord") update_discord_groups(user) def remove_from_databases(user, groups, syncgroups): + logger.debug("remove_from_database for user %s called. groups %s - syncgroups %s" % (user, groups, syncgroups)) authserviceinfo = None try: authserviceinfo = AuthServicesInfo.objects.get(user=user) + logger.debug("Got authservicesinfo object %s" % authserviceinfo) except: + logger.debug("No authservicesinfo object found for user %s" % user) pass if authserviceinfo: update = False for syncgroup in syncgroups: group = groups.filter(name=syncgroup.groupname) - + logger.debug("Got group %s for syncgroup %s" % (group, syncgroup)) if not group: + logger.debug("Deleting syncgroup %s" % syncgroup) syncgroup.delete() update = True if update: + logger.debug("Syncgroups updated. Propogating to services for user %s" % user) if authserviceinfo.jabber_username and authserviceinfo.jabber_username != "": + logger.debug("User %s has jabber username %s - updating groups." % (user, authserviceinfo.jabber_username)) update_jabber_groups(user) if authserviceinfo.mumble_username and authserviceinfo.mumble_username != "": + logger.debug("User %s has mumble username %s - updating groups." % (user, authserviceinfo.mumble_username)) update_mumble_groups(user) if authserviceinfo.forum_username and authserviceinfo.forum_username != "": + logger.debug("User %s has forum username %s - updating groups." % (user, authserviceinfo.forum_username)) update_forum_groups(user) if authserviceinfo.ipboard_username and authserviceinfo.ipboard_username != "": + logger.debug("User %s has ipboard username %s - updating groups." % (user, authserviceinfo.ipboard_username)) update_ipboard_groups(user) if authserviceinfo.teamspeak3_uid and authserviceinfo.teamspeak3_uid != "": + logger.debug("User %s has ts3 uid %s - updating groups." % (user, authserviceinfo.teamspeak3_uid)) update_teamspeak3_groups(user) if authserviceinfo.discord_uid and authserviceinfo.discord_uid != "": + logger.debug("User %s has discord uid %s - updating groups." % (user, authserviceinfo.discord_uid)) update_discord_groups(user) # Run every minute @periodic_task(run_every=crontab(minute="*/1")) def run_databaseUpdate(): + logger.debug("Starting database update.") users = User.objects.all() if (is_teamspeak3_active()): + logger.debug("TS3 installed. Syncing local group objects.") Teamspeak3Manager._sync_ts_group_db() for user in users: + logger.debug("Initiating database update for user %s" % user) groups = user.groups.all() + logger.debug("User has groups %s" % groups) syncgroups = SyncGroupCache.objects.filter(user=user) + logger.debug("User has syncgroups %s" % syncgroups) add_to_databases(user, groups, syncgroups) remove_from_databases(user, groups, syncgroups) +# Run every 2 hours +@periodic_task(run_every=crontab(minute="0", hour="*/2")) +def run_discord_token_cleanup(): + logger.debug("Running validation of all DiscordAuthTokens") + for auth in DiscordAuthToken.objects.all(): + logger.debug("Testing DiscordAuthToken %s" % auth) + if DiscordAPIManager.validate_token(auth.token): + logger.debug("Token passes validation. Retaining %s" % auth) + else: + logger.debug("DiscordAuthToken failed validation. Deleting %s" % auth) + auth.delete() # Run every 3 hours @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) @@ -272,25 +350,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) @@ -299,51 +384,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 @@ -351,36 +450,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) @@ -388,129 +499,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 standings 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..a471aa4d 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 %s" % (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.result) 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_info) + 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 owned by user id %s, not deleting user id %s" % (api_id, apikeypair.user.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 owned by user id%s, not deleting user id %s" % (char, api_id, char.user.id, user_id)) @staticmethod def check_if_character_exist(char_name): diff --git a/eveonline/views.py b/eveonline/views.py index e6da28a0..fc9ed613 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_info)) 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..c916a935 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 to group %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 group %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 %s" % (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..3948d0d0 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.error("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.error("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 on behalf of 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 on behalf of user %s: application is NoneType" % (app_id, request.user)) + else: + logger.error("Unable to delete HRApplication with id %s on behalf of 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,48 @@ 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("Form invalid - returning for user %s to retry." % request.user) + context = {'applications': None, 'search_form': form} + 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/services/admin.py b/services/admin.py index 2026832a..ed775610 100644 --- a/services/admin.py +++ b/services/admin.py @@ -2,6 +2,7 @@ from django.contrib import admin from .models import AuthTS from .models import TSgroup from .models import UserTSgroup +from .models import DiscordAuthToken class AuthTSgroupAdmin(admin.ModelAdmin): fields = ['auth_group','ts_group'] @@ -15,4 +16,6 @@ class UserTSgroupAdmin(admin.ModelAdmin): filter_horizontal = ('ts_group',) admin.site.register(AuthTS, AuthTSgroupAdmin) -admin.site.register(TSgroup, TSgroupAdmin) \ No newline at end of file +admin.site.register(TSgroup, TSgroupAdmin) + +admin.site.register(DiscordAuthToken) diff --git a/services/forms.py b/services/forms.py index 0696c939..65277517 100644 --- a/services/forms.py +++ b/services/forms.py @@ -1,13 +1,20 @@ from django import forms from django.contrib.auth.models import Group +from util import check_if_user_has_permission class JabberBroadcastForm(forms.Form): - allchoices = [] - allchoices.append(('all', 'all')) - for group in Group.objects.all(): - allchoices.append((str(group.name), str(group.name))) - group = forms.ChoiceField(choices=allchoices, widget=forms.Select) + def __init__(self, user, *args, **kwargs): + super(JabberBroadcastForm, self).__init__(*args, **kwargs) + allchoices = [] + if check_if_user_has_permission(user, 'jabber_broadcast_all'): + allchoices.append(('all', 'all')) + for g in Group.objects.all(): + allchoices.append((str(g.name), str(g.name))) + else: + for g in user.groups.all(): + allchoices.append((str(g.name), str(g.name))) + self.fields['group'] = forms.ChoiceField(choices=allchoices, widget=forms.Select) message = forms.CharField(widget=forms.Textarea) diff --git a/services/managers/discord_manager.py b/services/managers/discord_manager.py index 9ab4ff97..f1310b64 100644 --- a/services/managers/discord_manager.py +++ b/services/managers/discord_manager.py @@ -3,33 +3,34 @@ import json from django.conf import settings import re import os +from services.models import DiscordAuthToken + +import logging + +logger = logging.getLogger(__name__) DISCORD_URL = "https://discordapp.com/api" class DiscordAPIManager: - def __init__(self, server_id, email, password): - data = { - "email" : email, - "password": password, - } - custom_headers = {'content-type':'application/json'} - path = DISCORD_URL + "/auth/login" - r = requests.post(path, headers=custom_headers, data=json.dumps(data)) - r.raise_for_status() - self.token = r.json()['token'] + def __init__(self, server_id, email, password, user=None): + self.token = DiscordAPIManager.get_token_by_user(email, password, user) self.email = email self.password = password self.server_id = server_id + logger.debug("Initialized DiscordAPIManager with server id %s" % self.server_id) - def __del__(self): - if hasattr(self, 'token'): - if self.token and self.token != "": - data = {'token': self.token} - path = DISCORD_URL + "/auth/logout" - custom_headers = {'content-type':'application/json'} - r = requests.post(path, headers=custom_headers, data=json.dumps(data)) - r.raise_for_status() + @staticmethod + def validate_token(token): + custom_headers = {'accept': 'application/json', 'authorization': token} + path = DISCORD_URL + "/users/@me" + r = requests.get(path, headers=custom_headers) + if r.status_code == 200: + logger.debug("Token starting with %s passed validation." % token[0:5]) + return True + else: + logger.debug("Token starting with %s failed validation with status code %s" % (token[0:5], r.status_code)) + return False @staticmethod def get_auth_token(): @@ -40,6 +41,7 @@ class DiscordAPIManager: custom_headers = {'content-type':'application/json'} path = DISCORD_URL + "/auth/login" r = requests.post(path, headers=custom_headers, data=json.dumps(data)) + logger.debug("Received status code %s during token generation for settings discord user." % r.status_code) r.raise_for_status() return r.json()['token'] @@ -83,18 +85,21 @@ class DiscordAPIManager: custom_headers = {'authorization': self.token} path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/bans/" + str(user_id) + "?delete-message-days=" + str(delete_message_age) r = requests.put(path, headers=custom_headers) + logger.debug("Received status code %s after banning user %s" % (r.status_code, user_id)) r.raise_for_status() def unban_user(self, user_id): custom_headers = {'authorization': self.token} path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/bans/" + str(user_id) r = requests.delete(path, headers=custom_headers) + logger.debug("Received status code %s after deleting ban for user %s" % (r.status_code, user_id)) r.raise_for_status() def generate_role(self): custom_headers = {'accept':'application/json', 'authorization': self.token} path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/roles" r = requests.post(path, headers=custom_headers) + logger.debug("Received status code %s after generating new role." % r.status_code) r.raise_for_status() return r.json() @@ -108,6 +113,7 @@ class DiscordAPIManager: } path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/roles/" + str(role_id) r = requests.patch(path, headers=custom_headers, data=json.dumps(data)) + logger.debug("Received status code %s after editing role id %s" % (r.status_code, role_id)) r.raise_for_status() return r.json() @@ -125,11 +131,11 @@ class DiscordAPIManager: r.raise_for_status() return r.json() - @staticmethod - def accept_invite(invite_id, token): - custom_headers = {'accept': 'application/json', 'authorization': token} + def accept_invite(self, invite_id): + custom_headers = {'accept': 'application/json', 'authorization': self.token} path = DISCORD_URL + "/invite/" + str(invite_id) r = requests.post(path, headers=custom_headers) + logger.debug("Received status code %s after accepting invite." % r.status_code) r.raise_for_status() return r.json() @@ -143,6 +149,7 @@ class DiscordAPIManager: 'xkcdpass': xkcdpass, } r = requests.post(path, headers=custom_headers, data=json.dumps(data)) + logger.debug("Received status code %s after creating invite." % r.status_code) r.raise_for_status() return r.json() @@ -157,6 +164,7 @@ class DiscordAPIManager: path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/members/" + str(user_id) data = { 'roles': role_ids } r = requests.patch(path, headers=custom_headers, data=json.dumps(data)) + logger.debug("Received status code %s after setting roles of user %s to %s" % (r.status_code, user_id, role_ids)) r.raise_for_status() @staticmethod @@ -197,18 +205,37 @@ class DiscordAPIManager: custom_headers = {'authorization': self.token, 'accept':'application/json'} path = DISCORD_URL + "/guilds/" + str(self.server_id) + "/roles" r = requests.get(path, headers=custom_headers) + logger.debug("Received status code %s after retrieving role list from server." % r.status_code) r.raise_for_status() return r.json() def get_group_id(self, group_name): + logger.debug("Determining role id for group name %s" % group_name) all_roles = self.get_roles() + logger.debug("Retrieved role list for server: %s" % all_roles) for role in all_roles: + logger.debug("Checking role %s" % role) if role['name'] == group_name: + logger.debug("Found role matching name: %s" % role['id']) return role['id'] + logger.debug("Role not found on server. Raising KeyError") raise KeyError('Group not found on server: ' + group_name) @staticmethod - def get_token_by_user(email, password): + def get_token_by_user(email, password, user): + if DiscordAuthToken.objects.filter(email=email).exists(): + auth = DiscordAuthToken.objects.get(email=email) + if not auth.user == user: + raise ValueError("User mismatch while validating DiscordAuthToken for email %s - user %s, requesting user %s" % (email, auth.user, user)) + logger.debug("Discord auth token cached for supplied email starting with %s" % email[0:3]) + auth = DiscordAuthToken.objects.get(email=email, user=user) + if DiscordAPIManager.validate_token(auth.token): + logger.debug("Token still valid. Returning token starting with %s" % auth.token[0:5]) + return auth.token + else: + logger.debug("Token has expired. Deleting.") + auth.delete() + logger.debug("Generating auth token for email starting with %s user %s and password of length %s" % (email[0:3], user, len(password))) data = { "email" : email, "password": password, @@ -216,8 +243,21 @@ class DiscordAPIManager: custom_headers = {'content-type':'application/json'} path = DISCORD_URL + "/auth/login" r = requests.post(path, headers=custom_headers, data=json.dumps(data)) + logger.debug("Received status code %s after generating auth token for custom user." % r.status_code) r.raise_for_status() - return r.json()['token'] + token = r.json()['token'] + auth = DiscordAuthToken(email=email, token=token, user=user) + auth.save() + logger.debug("Created cached token for email starting with %s" % email[0:3]) + return token + + def get_profile(self): + custom_headers = {'accept': 'application/json', 'authorization': self.token} + path = DISCORD_URL + "/users/@me" + r = requests.get(path, headers=custom_headers) + logger.debug("Received status code %s after retrieving user profile with email %s" % (r.status_code, self.email[0:3])) + r.raise_for_status() + return r.json() @staticmethod def get_user_profile(email, password): @@ -225,6 +265,7 @@ class DiscordAPIManager: custom_headers = {'accept': 'application/json', 'authorization': token} path = DISCORD_URL + "/users/@me" r = requests.get(path, headers=custom_headers) + logger.debug("Received status code %s after retrieving user profile with email %s" % (r.status_code, email[0:3])) r.raise_for_status() return r.json() @@ -282,24 +323,34 @@ class DiscordManager: @staticmethod def update_groups(user_id, groups): + logger.debug("Updating groups for user_id %s: %s" % (user_id, groups)) group_ids = [] api = DiscordAPIManager(settings.DISCORD_SERVER_ID, settings.DISCORD_USER_EMAIL, settings.DISCORD_USER_PASSWORD) if len(groups) == 0: + logger.debug("No groups provided - generating empty array of group ids.") group_ids = [] else: for g in groups: try: + logger.debug("Retrieving group id for group %s" % g) group_id = api.get_group_id(g) group_ids.append(group_id) + logger.debug("Got id %s" % group_id) except: + logger.debug("Group id retrieval generated exception - generating new group on discord server.", exc_info=True) group_ids.append(DiscordManager.create_group(g)) + logger.info("Setting discord groups for user %s to %s" % (user_id, group_ids)) api.set_roles(user_id, group_ids) @staticmethod def create_group(groupname): + logger.debug("Creating new group %s" % groupname) api = DiscordAPIManager(settings.DISCORD_SERVER_ID, settings.DISCORD_USER_EMAIL, settings.DISCORD_USER_PASSWORD) new_group = api.generate_role() + logger.debug("Created new role on server with id %s: %s" % (new_group['id'], new_group)) named_group = api.edit_role(new_group['id'], groupname) + logger.debug("Renamed group id %s to %s" % (new_group['id'], groupname)) + logger.info("Created new group on discord server with name %s" % groupname) return named_group['id'] @staticmethod @@ -330,26 +381,36 @@ class DiscordManager: return current_password @staticmethod - def add_user(email, password): + def add_user(email, password, user): try: - api = DiscordAPIManager(settings.DISCORD_SERVER_ID, settings.DISCORD_USER_EMAIL, settings.DISCORD_USER_PASSWORD) - profile = DiscordAPIManager.get_user_profile(email, password) + logger.debug("Adding new user %s to discord with email %s and password of length %s" % (user, email[0:3], len(password))) + server_api = DiscordAPIManager(settings.DISCORD_SERVER_ID, settings.DISCORD_USER_EMAIL, settings.DISCORD_USER_PASSWORD) + user_api = DiscordAPIManager(settings.DISCORD_SERVER_ID, email, password, user=user) + profile = user_api.get_profile() + logger.debug("Got profile for user: %s" % profile) user_id = profile['id'] - if api.check_if_user_banned(user_id): - api.unban_user(user_id) - invite_code = api.create_invite()['code'] - token = DiscordAPIManager.get_token_by_user(email, password) - DiscordAPIManager.accept_invite(invite_code, token) + logger.debug("Determined user id: %s" % user_id) + if server_api.check_if_user_banned(user_id): + logger.debug("User is currently banned. Unbanning %s" % user_id) + server_api.unban_user(user_id) + invite_code = server_api.create_invite()['code'] + logger.debug("Generated invite code beginning with %s" % invite_code[0:5]) + user_api.accept_invite(invite_code) + logger.info("Added user to discord server %s with id %s" % (settings.DISCORD_SERVER_ID, user_id)) return user_id except: + logger.exception("An unhandled exception has occured.", exc_info=True) return "" @staticmethod def delete_user(user_id): try: + logger.debug("Deleting user with id %s from discord server." % user_id) api = DiscordAPIManager(settings.DISCORD_SERVER_ID, settings.DISCORD_USER_EMAIL, settings.DISCORD_USER_PASSWORD) DiscordManager.update_groups(user_id, []) api.ban_user(user_id) + logger.info("Deleted user with id %s from discord server id %s" % (user_id, settings.DISCORD_SERVER_ID)) return True except: + logger.exception("An unhandled exception has occured.", exc_info=True) return False diff --git a/services/managers/eve_api_manager.py b/services/managers/eve_api_manager.py index 498feea1..8df6f6f7 100644 --- a/services/managers/eve_api_manager.py +++ b/services/managers/eve_api_manager.py @@ -4,6 +4,9 @@ import evelink.eve from django.conf import settings +import logging + +logger = logging.getLogger(__name__) class EveApiManager(): def __init__(self): @@ -12,44 +15,51 @@ class EveApiManager(): @staticmethod def get_characters_from_api(api_id, api_key): chars = [] + logger.debug("Getting characters from api id %s" % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) # Should get characters account = evelink.account.Account(api=api) chars = account.characters() except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Retrieved characters %s from api id %s" % (chars, api_id)) return chars @staticmethod def get_corporation_ticker_from_id(corp_id): + logger.debug("Getting ticker for corp id %s" % corp_id) ticker = "" try: api = evelink.api.API() corp = evelink.corp.Corp(api) response = corp.corporation_sheet(corp_id) + logger.debug("Retrieved corp sheet for id %s: %s" % (corp_id, response)) ticker = response[0]['ticker'] except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Determined corp id %s ticker: %s" % (corp_id, ticker)) return ticker @staticmethod def get_alliance_information(alliance_id): results = {} + logger.debug("Getting info for alliance with id %s" % alliance_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) alliance = eve.alliances() results = alliance[0][int(alliance_id)] except evelink.api.APIError as error: - print error - + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Got alliance info %s" % results) return results @staticmethod def get_corporation_information(corp_id): + logger.debug("Getting info for corp with id %s" % corp_id) results = {} try: api = evelink.api.API() @@ -57,171 +67,205 @@ class EveApiManager(): corpinfo = corp.corporation_sheet(corp_id=int(corp_id)) results = corpinfo[0] except evelink.api.APIError as error: - print error - + logger.exception("Unhandled APIError occured.", exc_info=True) + logger.debug("Got corp info %s" % results) return results @staticmethod def check_api_is_type_account(api_id, api_key): + logger.debug("Checking if api id %s is account." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() + logger.debug("API id %s is type %s" % (api_id, info[0]['type'])) return info[0]['type'] == "account" except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False @staticmethod def check_api_is_full(api_id, api_key): + logger.debug("Checking if api id %s meets member requirements." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() - return info[0]['access_mask'] & settings.MEMBER_API_MASK == int(settings.MEMBER_API_MASK) + logger.debug("API has mask %s, required is %s" % (info[0]['access_mask'], settings.MEMBER_API_MASK)) + return info[0]['access_mask'] & int(settings.MEMBER_API_MASK) == int(settings.MEMBER_API_MASK) except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False @staticmethod def check_blue_api_is_full(api_id, api_key): + logger.debug("Checking if api id %s meets blue requirements." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() - return info[0]['access_mask'] & settings.BLUE_API_MASK == int(settings.BLUE_API_MASK) + logger.debug("API has mask %s, required is %s" % (info[0]['access_mask'], settings.BLUE_API_MASK)) + return info[0]['access_mask'] & int(settings.BLUE_API_MASK) == int(settings.BLUE_API_MASK) except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) @staticmethod def get_api_info(api_id, api_key): + logger.debug("Getting api info for key id %s" % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() + logger.debug("Got info for api id %s: %s" % (api_id, info)) return info except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False @staticmethod def api_key_is_valid(api_id, api_key): + logger.debug("Checking if api id %s is valid." % api_id) try: api = evelink.api.API(api_key=(api_id, api_key)) account = evelink.account.Account(api=api) info = account.key_info() + logger.info("Verified api id %s is still valid." % api_id) return True except evelink.api.APIError as error: - return False + logger.exception("APIError occured while validating api id %s" % api_id, exc_info=True) + logger.info("API id %s is invalid." % api_id) return False @staticmethod def check_if_api_server_online(): + logger.debug("Checking if API server online.") try: api = evelink.api.API() server = evelink.server.Server(api=api) info = server.server_status() + logger.info("Verified API server is online and reachable.") return True except evelink.api.APIError as error: - return False + logger.exception("APIError occured while trying to query api server. Possibly offline?", exc_info=True) + logger.warn("Unable to reach API server.") return False @staticmethod def check_if_id_is_corp(corp_id): + logger.debug("Checking if id %s is a corp." % corp_id) try: api = evelink.api.API() corp = evelink.corp.Corp(api=api) corpinfo = corp.corporation_sheet(corp_id=int(corp_id)) results = corpinfo[0] + logger.debug("Confirmed id %s is a corp." % corp_id) return True except evelink.api.APIError as error: - return False + logger.exception("APIError occured while checking if id %s is corp. Possibly not corp?" % corp_id, exc_info=True) + logger.debug("Unable to verify id %s is corp." % corp_id) return False @staticmethod def get_corp_standings(): - if settings.CORP_API_ID != "": + if settings.CORP_API_ID and settings.CORP_API_VCODE: try: + logger.debug("Getting corp standings with api id %s" % settings.CORP_API_ID) api = evelink.api.API(api_key=(settings.CORP_API_ID, settings.CORP_API_VCODE)) corp = evelink.corp.Corp(api=api) corpinfo = corp.contacts() results = corpinfo[0] + logger.debug("Got corp standings from settings: %s" % results) return results except evelink.api.APIError as error: - pass - + logger.exception("Unhandled APIError occured.", exc_info=True) + else: + logger.error("No corp API key supplied in settings. Unable to get standings.") return {} @staticmethod def check_if_id_is_alliance(alliance_id): + logger.debug("Checking if id %s is an alliance." % alliance_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) alliance = eve.alliances() results = alliance[0][int(alliance_id)] if results: + logger.debug("Confirmed id %s is an alliance." % alliance_id) return True except evelink.api.APIError as error: - return False + logger.exception("APIError occured while checking if id %s is an alliance. Possibly not alliance?" % alliance_id, exc_info=True) + logger.debug("Unable to verify id %s is an an alliance." % alliance_id) return False @staticmethod def check_if_id_is_character(character_id): + logger.debug("Checking if id %s is a character." % character_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) results = eve.character_info_from_id(character_id) if results: + logger.debug("Confirmed id %s is a character." % character_id) return True except evelink.api.APIError as error: - return False + logger.exception("APIError occured while checking if id %s is a character. Possibly not character?" % character_id, exc_info=True) + logger.debug("Unable to verify id %s is a character." % character_id) return False @staticmethod def check_if_alliance_exists(alliance_id): + logger.debug("Checking if alliance id %s exists." % alliance_id) try: api = evelink.api.API() eve = evelink.eve.EVE(api=api) alliances = eve.alliances() if int(alliance_id) in alliances[0]: + logger.debug("Verified alliance id %s exists." % alliance_id) return True else: + logger.debug("Verified alliance id %s does not exist." % alliance_id) return False except evelink.api.APIError as error: - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False except ValueError as error: #attempts to catch error resulting from checking alliance_of nonetype models - print error + logger.exception("Unhandled ValueError occured. Possible nonetype alliance model.", exc_info=True) return False + logger.warn("Exception prevented verification of alliance id %s existance. Assuming false." % alliance_id) return False @staticmethod def check_if_corp_exists(corp_id): + logger.debug("Checking if corp id %s exists." % corp_id) try: api = evelink.api.API() corp = evelink.corp.Corp(api=api) corpinfo = corp.corporation_sheet(corp_id=corp_id) if corpinfo[0]['members']['current'] > 0: + logger.debug("Verified corp id %s exists with member count %s" % (corp_id, corpinfo[0]['members']['current'])) return True else: + logger.debug("Verified corp id %s has closed. Member count %s" % (corp_id, corpinfo[0]['members']['current'])) return False except evelink.api.APIError as error: #could be smart and check for error code523 to verify error due to no corp instead of catch-all - print error + logger.exception("Unhandled APIError occured.", exc_info=True) return False + logger.warn("Exception prevented verification of corp id %s existance. Assuming false." % corp_id) return False diff --git a/services/managers/ipboard_manager.py b/services/managers/ipboard_manager.py index a85a146a..16ea220a 100755 --- a/services/managers/ipboard_manager.py +++ b/services/managers/ipboard_manager.py @@ -4,6 +4,9 @@ from hashlib import md5 from django.conf import settings +import logging + +logger = logging.getLogger(__name__) class IPBoardManager: def __init__(self): @@ -39,29 +42,35 @@ class IPBoardManager: def add_user(username, email): """ Add user to service """ sanatized = str(IPBoardManager.__santatize_username(username)) + logger.debug("Adding user to IPBoard with username %s" % sanatized) plain_password = IPBoardManager.__generate_random_pass() password = md5(plain_password).hexdigest() ret = IPBoardManager.exec_xmlrpc('createUser', username=sanatized, email=str(email), display_name=sanatized, md5_passwordHash=password) + logger.info("Added IPBoard user with username %s" % sanatized) return sanatized, plain_password @staticmethod def delete_user(username): """ Delete user """ ret = IPBoardManager.exec_xmlrpc('deleteUser', username=username) + logger.info("Deleted IPBoard user with username %s" % username) return username @staticmethod def disable_user(username): """ Disable user """ ret = IPBoardManager.exec_xmlrpc('disableUser', username=username) + logger.info("Disabled IPBoard user with username %s" % username) return username @staticmethod def update_user(username, email, password): """ Add user to service """ password = md5(password).hexdigest() + logger.debug("Updating IPBoard username %s with email %s and password hash starting with %s" % (username, email, password[0:5])) ret = IPBoardManager.exec_xmlrpc('updateUser', username=username, email=email, md5_passwordHash=password) + logger.info("Updated IPBoard user with username %s" % username) return username @staticmethod @@ -70,6 +79,7 @@ class IPBoardManager: ret = IPBoardManager.exec_xmlrpc('getAllGroups') for group in ret: groups.append(group["g_title"]) + logger.debug("Retrieved group list from IPBoard: %s" % groups) return groups @staticmethod @@ -79,21 +89,25 @@ class IPBoardManager: if type(ret) is list: for group in ret: groups.append(group["g_title"]) + logger.debug("Got user %s IPBoard groups %s" % (username, groups)) return groups @staticmethod def add_group(group): ret = IPBoardManager.exec_xmlrpc('addGroup', group=group) + logger.info("Added IPBoard group %s" % group) return ret @staticmethod def add_user_to_group(username, group): ret = IPBoardManager.exec_xmlrpc('addUserToGroup', username=username, group=group) + logger.info("Added IPBoard user %s to group %s" % (username, group)) return ret @staticmethod def remove_user_from_group(username, group): ret = IPBoardManager.exec_xmlrpc('removeUserFromGroup', username=username, group=group) + logger.info("Removed IPBoard user %s from group %s" % (username, group)) return ret @staticmethod @@ -104,27 +118,27 @@ class IPBoardManager: @staticmethod def update_groups(username, groups): - + logger.debug("Updating IPBoard user %s with groups %s" % (username, groups)) forum_groups = IPBoardManager.get_all_groups() user_groups = set(IPBoardManager.get_user_groups(username)) act_groups = set([g.replace(' ', '-') for g in groups]) addgroups = act_groups - user_groups remgroups = user_groups - act_groups - print addgroups - print remgroups + logger.info("Updating IPBoard groups for user %s - adding %s, removing %s" % (username, addgroups, remgroups)) for g in addgroups: if not g in forum_groups: IPBoardManager.add_group(g) - print username - print g + logger.debug("Adding user %s to IPBoard group %s" % (username, g)) IPBoardManager.add_user_to_group(username, g) for g in remgroups: + logger.debug("Removing user %s from IPBoard group %s" % (username, g)) IPBoardManager.remove_user_from_group(username, g) @staticmethod def update_user_password(username, email): + logger.debug("Settings new IPBoard password for user %s" % username) plain_password = IPBoardManager.__generate_random_pass() IPBoardManager.update_user(username, email, plain_password) - return plain_password \ No newline at end of file + return plain_password diff --git a/services/managers/mumble_manager.py b/services/managers/mumble_manager.py index 5ad28163..4306249a 100755 --- a/services/managers/mumble_manager.py +++ b/services/managers/mumble_manager.py @@ -6,6 +6,9 @@ import django from django.db import connections from django.conf import settings +import logging + +logger = logging.getLogger(__name__) class MumbleManager: SQL_SELECT_USER_MAX_ID = r"SELECT max(user_id)+1 as next_id from murmur_users" @@ -76,30 +79,38 @@ class MumbleManager: for row in rows: out[row[1]] = row[0] + logger.debug("Got mumble groups %s" % out) return out @staticmethod def _get_group(name): + logger.debug("Looking for group name %s in mumble." % name) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_GET_GROUP_FROM_NAME, [settings.MUMBLE_SERVER_ID, name]) row = dbcursor.fetchone() if row: + logger.debug("Found group %s in mumble - %s" % (name, row[0])) return row[0] @staticmethod def _get_user_groups(name): + logger.debug("Getting mumble groups for username %s" % name) dbcursor = connections['mumble'].cursor() user_id = MumbleManager.get_user_id_by_name(name) dbcursor.execute(MumbleManager.SQL_GET_USER_GROUPS, [user_id]) - return [row[0] for row in dbcursor.fetchall()] + out = [row[0] for row in dbcursor.fetchall()] + logger.debug("Got user %s mumble groups %s" % (name, out)) + return out @staticmethod def _add_group(name): + logger.debug("Adding group %s to mumble server." % name) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_SELECT_GROUP_MAX_ID) row = dbcursor.fetchone() groupid = row[0] dbcursor.execute(MumbleManager.SQL_ADD_GROUP, [groupid, settings.MUMBLE_SERVER_ID, name]) + logger.info("Created group %s on mumble server with id %s" % (name, groupid)) return groupid @staticmethod @@ -107,124 +118,142 @@ class MumbleManager: if userid != None: dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_ADD_USER_TO_GROUP, [groupid, settings.MUMBLE_SERVER_ID, userid]) + logger.info("Added user id %s to mumble group id %s" % (userid, groupid)) @staticmethod def _del_user_from_group(userid, groupid): dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_DELETE_USER_FROM_GROUP, [groupid, settings.MUMBLE_SERVER_ID, userid]) + logger.info("Removed user id %s from mumble group id %s" % (userid, groupid)) @staticmethod def get_user_id_by_name(name): + logger.debug("Getting mumble user id for user with name %s" % name) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_SELECT_GET_USER_ID_BY_NAME, [name, settings.MUMBLE_SERVER_ID]) row = dbcursor.fetchone() if row: + logger.debug("Got mumble user id %s for name %s" % (row[0], name)) return row[0] @staticmethod def create_user(corp_ticker, username): + logger.debug("Creating mumble user with username %s and ticker %s" % (username, corp_ticker)) dbcursor = connections['mumble'].cursor() username_clean = MumbleManager.__santatize_username(MumbleManager.__generate_username(username, corp_ticker)) password = MumbleManager.__generate_random_pass() pwhash = MumbleManager._gen_pwhash(password) - + logger.debug("Proceeding with mumble user creation: clean username %s, pwhash starts with %s" % (username_clean, pwhash[0:5])) try: dbcursor.execute(MumbleManager.SQL_SELECT_USER_MAX_ID) user_id = dbcursor.fetchone()[0] dbcursor.execute(MumbleManager.SQL_CREATE_USER, [settings.MUMBLE_SERVER_ID, user_id, username_clean, pwhash]) - + logger.info("Added user to mumble with username %s" % username_clean) return username_clean, password except django.db.utils.IntegrityError as error: - print error + logger.exception("IntegrityError during mumble create_user occured.", exc_info=True) except: - print "Unexpected error:", sys.exc_info()[0] - + logger.exception("Unhandled exception occured.", exc_info=True) + logger.error("Exception prevented creation of mumble user. Returning blank for username, password.") return "", "" @staticmethod def create_blue_user(corp_ticker, username): + logger.debug("Creating mumble blue user with username %s and ticker %s" % (username, corp_ticker)) dbcursor = connections['mumble'].cursor() username_clean = MumbleManager.__santatize_username(MumbleManager.__generate_username_blue(username, corp_ticker)) password = MumbleManager.__generate_random_pass() pwhash = MumbleManager._gen_pwhash(password) - + logger.debug("Proceeding with mumble user creation: clean username %s, pwhash starts with %s" % (username_clean, pwhash[0:5])) try: dbcursor.execute(MumbleManager.SQL_SELECT_USER_MAX_ID) user_id = dbcursor.fetchone()[0] dbcursor.execute(MumbleManager.SQL_CREATE_USER, [settings.MUMBLE_SERVER_ID, user_id, username_clean, pwhash]) - + logger.info("Added blue user to mumble with username %s" % username_clean) return username_clean, password except: - print "Unexpected error:", sys.exc_info()[0] - + logger.exception("Unhandled exception occured.", exc_info=True) + logger.error("Exception prevented creation of mumble blue user. Returning blank for username, password.") return "", "" @staticmethod def check_user_exist(username): + logger.debug("Checking if username %s exists on mumble." % username) dbcursor = connections['mumble'].cursor() dbcursor.execute(MumbleManager.SQL_CHECK_USER_EXIST, [username, settings.MUMBLE_SERVER_ID]) row = dbcursor.fetchone() if row and row[0].lower() == username.lower(): + logger.debug("Found username %s on mumble." % username) return True + logger.debug("Unable to find username %s on mumble." % username) return False @staticmethod def delete_user(username): + logger.debug("Deleting user %s from mumble." % username) dbcursor = connections['mumble'].cursor() if MumbleManager.check_user_exist(username): try: dbcursor.execute(MumbleManager.SQL_DELETE_USER, [username, settings.MUMBLE_SERVER_ID]) + logger.info("Deleted user %s from mumble." % username) return True except: + logger.exception("Exception prevented deletion of user %s from mumble." % username, exc_info=True) return False - + logger.error("User %s not found on mumble. Unable to delete." % username) return False @staticmethod def update_user_password(username): + logger.debug("Updating mumble user %s password." % username) dbcursor = connections['mumble'].cursor() password = MumbleManager.__generate_random_pass() pwhash = MumbleManager._gen_pwhash(password) - + logger.debug("Proceeding with mumble user %s password update - pwhash starts with %s" % (username, pwhash[0:5])) if MumbleManager.check_user_exist(username): try: dbcursor.execute(MumbleManager.SQL_UPDATE_USER_PASSWORD, [pwhash, username, settings.MUMBLE_SERVER_ID]) + logger.info("Updated mumble user %s password." % username) return password except: + logger.exception("Exception prevented updating of mumble user %s password." % username, exc_info=True) return "" - + logger.error("User %s not found on mumble. Unable to update password." % username) return "" @staticmethod def update_groups(username, groups): + logger.debug("Updating mumble user %s groups %s" % (username, groups)) userid = MumbleManager.get_user_id_by_name(username) mumble_groups = MumbleManager._get_groups() user_groups = set(MumbleManager._get_user_groups(username)) act_groups = set([g.replace(' ', '-') for g in groups]) addgroups = act_groups - user_groups remgroups = user_groups - act_groups - + logger.info("Updating mumble user %s groups - adding %s, removing %s" % (username, addgroups, remgroups)) for g in addgroups: if not g in mumble_groups: mumble_groups[g] = MumbleManager._add_group(g) try: + logger.debug("Adding mumble user %s to group %s" % (userid, mumble_groups[g])) MumbleManager._add_user_to_group(userid, mumble_groups[g]) except: - print "Error occurred while adding a mumble to a group" + logger.exception("Exception occured while adding mumble user %s with id %s to group %s with id %s" % (username, userid, g, mumble_groups[g]), exc_info=True) for g in remgroups: try: + logger.debug("Deleting mumble user %s from group %s" % (userid, mumble_groups[g])) MumbleManager._del_user_from_group(userid, mumble_groups[g]) except: - print "Error occurred while removing a mumble user from group" + logger.exception("Exception occured while removing mumble user %s with id %s from group %s with id %s" % (username, userid, g, mumble_groups[g]), exc_info=True) diff --git a/services/managers/openfire_manager.py b/services/managers/openfire_manager.py index aea8bdf2..0e4fdd85 100755 --- a/services/managers/openfire_manager.py +++ b/services/managers/openfire_manager.py @@ -9,6 +9,9 @@ import threading from ofrestapi.users import Users as ofUsers from ofrestapi import exception +import logging + +logger = logging.getLogger(__name__) class OpenfireManager: def __init__(self): @@ -16,6 +19,7 @@ class OpenfireManager: @staticmethod def send_broadcast_threaded(group_name, broadcast_message): + logger.debug("Starting broadcast to %s with message %s" % (group_name, broadcast_message)) broadcast_thread = XmppThread(1, "XMPP Broadcast Thread", 1, group_name, broadcast_message) broadcast_thread.start() @@ -37,55 +41,68 @@ class OpenfireManager: @staticmethod def add_user(username): - + logger.debug("Adding username %s to openfire." % username) try: sanatized_username = OpenfireManager.__santatize_username(username) password = OpenfireManager.__generate_random_pass() api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.add_user(sanatized_username, password) - + logger.info("Added openfire user %s" % username) except exception.UserAlreadyExistsException: # User exist + logger.error("Attempting to add a user %s to openfire which already exists on server." % username) return "", "" return sanatized_username, password @staticmethod def delete_user(username): + logger.debug("Deleting user %s from openfire." % username) try: api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.delete_user(username) + logger.info("Deleted user %s from openfire." % username) return True except exception.UserNotFoundException: + logger.error("Attempting to delete a user %s from openfire which was not found on server." % username) return False @staticmethod def lock_user(username): + logger.debug("Locking openfire user %s" % username) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.lock_user(username) + logger.info("Locked openfire user %s" % username) @staticmethod def unlock_user(username): + logger.debug("Unlocking openfire user %s" % username) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.unlock_user(username) + logger.info("Unlocked openfire user %s" % username) @staticmethod def update_user_pass(username): + logger.debug("Updating openfire user %s password." % username) try: password = OpenfireManager.__generate_random_pass() api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.update_user(username, password=password) + logger.info("Updated openfire user %s password." % username) return password except exception.UserNotFoundException: + logger.error("Unable to update openfire user %s password - user not found on server." % username) return "" @staticmethod def update_user_groups(username, password, groups): + logger.debug("Updating openfire user %s groups %s" % (username, groups)) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) response = api.get_user_groups(username) remote_groups = [] if response: remote_groups = response['groupname'] + logger.debug("Openfire user %s has groups %s" % (username, remote_groups)) add_groups = [] del_groups = [] for g in groups: @@ -94,6 +111,7 @@ class OpenfireManager: for g in remote_groups: if not g in groups: del_groups.append(g) + logger.info("Updating openfire groups for user %s - adding %s, removing %s" % (username, add_groups, del_groups)) if add_groups: api.add_user_groups(username, add_groups) if del_groups: @@ -101,24 +119,28 @@ class OpenfireManager: @staticmethod def delete_user_groups(username, groups): - + logger.debug("Deleting openfire groups %s from user %s" % (groups, username)) api = ofUsers(settings.OPENFIRE_ADDRESS, settings.OPENFIRE_SECRET_KEY) api.delete_user_groups(username, groups) + logger.info("Deleted groups %s from openfire user %s" % (groups, username)) @staticmethod def send_broadcast_message(group_name, broadcast_message): + logger.debug("Sending jabber ping to group %s with message %s" % (group_name, broadcast_message)) # create to address client = xmpp.Client(settings.JABBER_URL) client.connect(server=(settings.JABBER_SERVER, settings.JABBER_PORT)) client.auth(settings.BROADCAST_USER, settings.BROADCAST_USER_PASSWORD, 'broadcast') to_address = group_name + '@' + settings.BROADCAST_SERVICE_NAME + '.' + settings.JABBER_URL + logger.debug("Determined ping to address: %s" % to_address) message = xmpp.Message(to_address, broadcast_message) message.setAttr('type', 'chat') client.send(message) client.Process(1) client.disconnect() + logger.info("Sent jabber ping to group %s" % group_name) class XmppThread (threading.Thread): def __init__(self, threadID, name, counter, group, message,): diff --git a/services/managers/phpbb3_manager.py b/services/managers/phpbb3_manager.py index 26ffea4d..98939e6a 100755 --- a/services/managers/phpbb3_manager.py +++ b/services/managers/phpbb3_manager.py @@ -5,6 +5,11 @@ from datetime import datetime from passlib.apps import phpbb3_context from django.db import connections +import logging + +from django.conf import settings + +logger = logging.getLogger(__name__) class Phpbb3Manager: SQL_ADD_USER = r"INSERT INTO phpbb_users (username, username_clean, " \ @@ -39,6 +44,7 @@ class Phpbb3Manager: @staticmethod def __add_avatar(username, characterid): + logger.debug("Adding EVE character id %s portrait as phpbb avater for user %s" % (characterid, username)) avatar_url = "http://image.eveonline.com/Character/" + characterid + "_64.jpg" cursor = connections['phpbb3'].cursor() userid = Phpbb3Manager.__get_user_id(username) @@ -60,38 +66,46 @@ class Phpbb3Manager: @staticmethod def __get_group_id(groupname): + logger.debug("Getting phpbb3 group id for groupname %s" % groupname) cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_GET_GROUP_ID, [groupname]) row = cursor.fetchone() - + logger.debug("Got phpbb group id %s for groupname %s" % (row[0], groupname)) return row[0] @staticmethod def __get_user_id(username): + logger.debug("Getting phpbb3 user id for username %s" % username) cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_USER_ID_FROM_USERNAME, [username]) row = cursor.fetchone() if row is not None: + logger.debug("Got phpbb user id %s for username %s" % (row[0], username)) return row[0] else: + logger.error("Username %s not found on phpbb. Unable to determine user id." % username) return None @staticmethod def __get_all_groups(): + logger.debug("Getting all phpbb3 groups.") cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_GET_ALL_GROUPS) rows = cursor.fetchall() out = {} for row in rows: out[row[1]] = row[0] - + logger.debug("Got phpbb groups %s" % out) return out @staticmethod def __get_user_groups(userid): + logger.debug("Getting phpbb3 user id %s groups" % userid) cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_GET_USER_GROUPS, [userid]) - return [row[0] for row in cursor.fetchall()] + out = [row[0] for row in cursor.fetchall()] + logger.debug("Got user %s phpbb groups %s" % (userid, out)) + return out @staticmethod def __get_current_utc_date(): @@ -101,36 +115,46 @@ class Phpbb3Manager: @staticmethod def __create_group(groupname): + logger.debug("Creating phpbb3 group %s" % groupname) cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_ADD_GROUP, [groupname, groupname]) + logger.info("Created phpbb group %s" % groupname) return Phpbb3Manager.__get_group_id(groupname) @staticmethod def __add_user_to_group(userid, groupid): + logger.debug("Adding phpbb3 user id %s to group id %s" % (userid, groupid)) try: cursor = connections['phpbb3'].cursor() cursor.execute(Phpbb3Manager.SQL_ADD_USER_GROUP, [groupid, userid, 0]) + logger.info("Added phpbb user id %s to group id %s" % (userid, groupid)) except: + logger.exception("Unable to add phpbb user id %s to group id %s" % (userid, groupid), exc_info=True) pass @staticmethod def __remove_user_from_group(userid, groupid): + logger.debug("Removing phpbb3 user id %s from group id %s" % (userid, groupid)) cursor = connections['phpbb3'].cursor() try: cursor.execute(Phpbb3Manager.SQL_REMOVE_USER_GROUP, [userid, groupid]) + logger.info("Removed phpbb user id %s from group id %s" % (userid, groupid)) except: + logger.exception("Unable to remove phpbb user id %s from group id %s" % (userid, groupid), exc_info=True) pass @staticmethod def add_user(username, email, groups, characterid): + logger.debug("Adding phpbb user with username %s, email %s, groups %s, characterid %s" % (username, email, groups, characterid)) cursor = connections['phpbb3'].cursor() username_clean = Phpbb3Manager.__santatize_username(username) password = Phpbb3Manager.__generate_random_pass() pwhash = Phpbb3Manager.__gen_hash(password) - + logger.debug("Proceeding to add phpbb user %s and pwhash starting with %s" % (username_clean, pwhash[0:5])) # check if the username was simply revoked if Phpbb3Manager.check_user(username_clean): + logger.warn("Unable to add phpbb user with username %s - already exists. Updating user instead." % username) Phpbb3Manager.__update_user_info(username_clean, email, pwhash) else: try: @@ -140,46 +164,52 @@ class Phpbb3Manager: "", ""]) Phpbb3Manager.update_groups(username_clean, groups) Phpbb3Manager.__add_avatar(username_clean, characterid) + logger.info("Added phpbb user %s" % username_clean) except: + logger.exception("Unable to add phpbb user %s" % username_clean, exc_info=True) pass return username_clean, password @staticmethod def disable_user(username): + logger.debug("Disabling phpbb user %s" % username) cursor = connections['phpbb3'].cursor() password = Phpbb3Manager.__gen_hash(Phpbb3Manager.__generate_random_pass()) - revoke_email = "revoked@the99eve.com" + revoke_email = "revoked@" + settings.DOMAIN try: pwhash = Phpbb3Manager.__gen_hash(password) cursor.execute(Phpbb3Manager.SQL_DIS_USER, [revoke_email, pwhash, username]) + logger.info("Disabled phpbb user %s" % username) return True except TypeError as e: - print e + logger.exception("TypeError occured while disabling user %s - failed to disable." % username, exc_info=True) return False @staticmethod def delete_user(username): + logger.debug("Deleting phpbb user %s" % username) cursor = connections['phpbb3'].cursor() if Phpbb3Manager.check_user(username): cursor.execute(Phpbb3Manager.SQL_DEL_USER, [username]) + logger.info("Deleted phpbb user %s" % username) return True + logger.error("Unable to delete phpbb user %s - user not found on phpbb." % username) return False @staticmethod def update_groups(username, groups): userid = Phpbb3Manager.__get_user_id(username) + logger.debug("Updating phpbb user %s with id %s groups %s" % (username, userid, groups)) if userid is not None: forum_groups = Phpbb3Manager.__get_all_groups() user_groups = set(Phpbb3Manager.__get_user_groups(userid)) act_groups = set([g.replace(' ', '-') for g in groups]) addgroups = act_groups - user_groups remgroups = user_groups - act_groups - print username - print addgroups - print remgroups + logger.info("Updating phpbb user %s groups - adding %s, removing %s" % (username, addgroups, remgroups)) for g in addgroups: if not g in forum_groups: forum_groups[g] = Phpbb3Manager.__create_group(g) @@ -190,6 +220,7 @@ class Phpbb3Manager: @staticmethod def remove_group(username, group): + logger.debug("Removing phpbb user %s from group %s" % (username, group)) cursor = connections['phpbb3'].cursor() userid = Phpbb3Manager.__get_user_id(username) if userid is not None: @@ -199,35 +230,45 @@ class Phpbb3Manager: if groupid: try: cursor.execute(Phpbb3Manager.SQL_REMOVE_USER_GROUP, [userid, groupid]) + logger.info("Removed phpbb user %s from group %s" % (username, group)) except: + logger.exception("Exception prevented removal of phpbb user %s with id %s from group %s with id %s" % (username, userid, group, groupid), exc_info=True) pass @staticmethod def check_user(username): + logger.debug("Checking phpbb username %s" % username) cursor = connections['phpbb3'].cursor() - """ Check if the username exists """ cursor.execute(Phpbb3Manager.SQL_USER_ID_FROM_USERNAME, [Phpbb3Manager.__santatize_username(username)]) row = cursor.fetchone() if row: + logger.debug("Found user %s on phpbb" % username) return True + logger.debug("User %s not found on phpbb" % username) return False @staticmethod def update_user_password(username, characterid): + logger.debug("Updating phpbb user %s password" % username) cursor = connections['phpbb3'].cursor() password = Phpbb3Manager.__generate_random_pass() if Phpbb3Manager.check_user(username): pwhash = Phpbb3Manager.__gen_hash(password) + logger.debug("Proceeding to update phpbb user %s password with pwhash starting with %s" % (username, pwhash[0:5])) cursor.execute(Phpbb3Manager.SQL_UPDATE_USER_PASSWORD, [pwhash, username]) Phpbb3Manager.__add_avatar(username, characterid) + logger.info("Updated phpbb user %s password." % username) return password - + logger.error("Unable to update phpbb user %s password - user not found on phpbb." % username) return "" @staticmethod def __update_user_info(username, email, password): + logger.debug("Updating phpbb user %s info: username %s password of length %s" % (username, email, len(password))) cursor = connections['phpbb3'].cursor() try: cursor.execute(Phpbb3Manager.SQL_DIS_USER, [email, password, username]) + logger.info("Updated phpbb user %s info" % username) except: + logger.exception("Unable to update phpbb user %s info." % username, exc_info=True) pass diff --git a/services/managers/teamspeak3_manager.py b/services/managers/teamspeak3_manager.py index 291b58a1..76532fba 100755 --- a/services/managers/teamspeak3_manager.py +++ b/services/managers/teamspeak3_manager.py @@ -2,7 +2,9 @@ from django.conf import settings from services.managers.util.ts3 import TS3Server from services.models import TSgroup +import logging +logger = logging.getLogger(__name__) class Teamspeak3Manager: def __init__(self): @@ -13,6 +15,7 @@ class Teamspeak3Manager: server = TS3Server(settings.TEAMSPEAK3_SERVER_IP, settings.TEAMSPEAK3_SERVER_PORT) server.login(settings.TEAMSPEAK3_SERVERQUERY_USER, settings.TEAMSPEAK3_SERVERQUERY_PASSWORD) server.use(settings.TEAMSPEAK3_VIRTUAL_SERVER) + logger.debug("Got TS3 server instance based on settings.") return server @staticmethod @@ -31,27 +34,34 @@ class Teamspeak3Manager: @staticmethod def _get_userid(uid): + logger.debug("Looking for uid %s on TS3 server." % uid) server = Teamspeak3Manager.__get_created_server() ret = server.send_command('customsearch', {'ident': 'sso_uid', 'pattern': uid}) if ret and 'keys' in ret and 'cldbid' in ret['keys']: + logger.debug("Got userid %s for uid %s" % (ret['keys']['cldbid'], uid)) return ret['keys']['cldbid'] @staticmethod def _group_id_by_name(groupname): server = Teamspeak3Manager.__get_created_server() + logger.debug("Looking for group %s on TS3 server." % groupname) group_cache = server.send_command('servergrouplist') - + logger.debug("Received group cache from server: %s" % group_cache) for group in group_cache: + logger.debug("Checking group %s" % group) if group['keys']['name'] == groupname: + logger.debug("Found group %s, returning id %s" % (groupname, group['keys']['sgid'])) return group['keys']['sgid'] - + logger.debug("Group %s not found on server." % groupname) return None @staticmethod def _create_group(groupname): + logger.debug("Creating group %s on TS3 server." % groupname) server = Teamspeak3Manager.__get_created_server() sgid = Teamspeak3Manager._group_id_by_name(groupname) if not sgid: + logger.debug("Group does not yet exist. Proceeding with creation.") ret = server.send_command('servergroupadd', {'name': groupname}) Teamspeak3Manager.__group_cache = None sgid = ret['keys']['sgid'] @@ -64,72 +74,95 @@ class Teamspeak3Manager: server.send_command('servergroupaddperm', {'sgid': sgid, 'permsid': 'i_group_needed_member_remove_power', 'permvalue': 100, 'permnegated': 0, 'permskip': 0}) + logger.info("Created group on TS3 server with name %s and id %s" % (groupname, sgid)) return sgid @staticmethod def _user_group_list(cldbid): + logger.debug("Retrieving group list for user with id %s" % cldbid) server = Teamspeak3Manager.__get_created_server() groups = server.send_command('servergroupsbyclientid', {'cldbid': cldbid}) + logger.debug("Retrieved group list: %s" % groups) outlist = {} if type(groups) == list: + logger.debug("Recieved multiple groups. Iterating.") for group in groups: + logger.debug("Assigning name/id dict: %s = %s" % (group['keys']['name'], group['keys']['sgid'])) outlist[group['keys']['name']] = group['keys']['sgid'] elif type(groups) == dict: + logger.debug("Recieved single group.") + logger.debug("Assigning name/id dict: %s = %s" % (groups['keys']['name'], groups['keys']['sgid'])) outlist[groups['keys']['name']] = groups['keys']['sgid'] - + logger.debug("Returning name/id pairing: %s" % outlist) return outlist @staticmethod def _group_list(): + logger.debug("Retrieving group list on TS3 server.") server = Teamspeak3Manager.__get_created_server() group_cache = server.send_command('servergrouplist') + logger.debug("Received group cache from server: %s" % group_cache) outlist = {} if group_cache: for group in group_cache: + logger.debug("Assigning name/id dict: %s = %s" % (group['keys']['name'], group['keys']['sgid'])) outlist[group['keys']['name']] = group['keys']['sgid'] else: - print '1024 error' - + logger.error("Received empty group cache while retrieving group cache from TS3 server. 1024 error.") + logger.debug("Returning name/id pairing: %s" % outlist) return outlist @staticmethod def _add_user_to_group(uid, groupid): + logger.debug("Adding group id %s to TS3 user id %s" % (groupid, uid)) server = Teamspeak3Manager.__get_created_server() server_groups = Teamspeak3Manager._group_list() user_groups = Teamspeak3Manager._user_group_list(uid) if not groupid in user_groups.values(): + logger.debug("User does not have group already. Issuing command to add.") server.send_command('servergroupaddclient', {'sgid': str(groupid), 'cldbid': uid}) + logger.info("Added user id %s to group id %s on TS3 server." % (uid, groupid)) @staticmethod def _remove_user_from_group(uid, groupid): + logger.debug("Removing group id %s from TS3 user id %s" % (groupid, uid)) server = Teamspeak3Manager.__get_created_server() server_groups = Teamspeak3Manager._group_list() user_groups = Teamspeak3Manager._user_group_list(uid) if str(groupid) in user_groups.values(): + logger.debug("User is in group. Issuing command to remove.") server.send_command('servergroupdelclient', {'sgid': str(groupid), 'cldbid': uid}) + logger.info("Removed user id %s from group id %s on TS3 server." % (uid, groupid)) @staticmethod def _sync_ts_group_db(): + logger.debug("_sync_ts_group_db function called.") try: remote_groups = Teamspeak3Manager._group_list() local_groups = TSgroup.objects.all() + logger.debug("Comparing remote groups to TSgroup objects: %s" % local_groups) for key in remote_groups: + logger.debug("Typecasting remote_group value at position %s to int: %s" % (key, remote_groups[key])) remote_groups[key] = int(remote_groups[key]) for group in local_groups: + logger.debug("Checking local group %s" % group) if group.ts_group_id not in remote_groups.values(): + logger.debug("Local group id %s not found on server. Deleting model %s" % (group.ts_group_id, group)) TSgroup.objects.filter(ts_group_id=group.ts_group_id).delete() for key in remote_groups: g = TSgroup(ts_group_id=remote_groups[key],ts_group_name=key) q = TSgroup.objects.filter(ts_group_id=g.ts_group_id) if not q: + logger.debug("Local group does not exist for TS group %s. Creating TSgroup model %s" % (remote_groups[key], g)) g.save() except: + logger.exception("An unhandled exception has occured while syncing TS groups.", exc_info=True) pass @staticmethod @@ -138,7 +171,7 @@ class Teamspeak3Manager: corp_ticker)) server = Teamspeak3Manager.__get_created_server() token = "" - + logger.debug("Adding user to TS3 server with cleaned username %s" % username_clean) server_groups = Teamspeak3Manager._group_list() if not settings.DEFAULT_AUTH_GROUP in server_groups: @@ -156,6 +189,7 @@ class Teamspeak3Manager: token = ret['keys']['token'] except: pass + logger.info("Created permission token for user %s on TS3 server" % username_clean) return username_clean, token @@ -165,7 +199,7 @@ class Teamspeak3Manager: corp_ticker)) server = Teamspeak3Manager.__get_created_server() token = "" - + logger.debug("Adding user to TS3 server with cleaned username %s" % username_clean) server_groups = Teamspeak3Manager._group_list() if not settings.DEFAULT_BLUE_GROUP in server_groups: Teamspeak3Manager._create_group(settings.DEFAULT_BLUE_GROUP) @@ -183,6 +217,7 @@ class Teamspeak3Manager: except: pass + logger.info("Created permission token for blue user %s on TS3 server" % username_clean) return username_clean, token @@ -190,16 +225,20 @@ class Teamspeak3Manager: def delete_user(uid): server = Teamspeak3Manager.__get_created_server() user = Teamspeak3Manager._get_userid(uid) + logger.debug("Deleting user %s with id %s from TS3 server." % (user, uid)) if user: for client in server.send_command('clientlist'): if client['keys']['client_database_id'] == user: + logger.debug("Found user %s on TS3 server - issuing deletion command." % user) server.send_command('clientkick', {'clid': client['keys']['clid'], 'reasonid': 5, 'reasonmsg': 'Auth service deleted'}) ret = server.send_command('clientdbdelete', {'cldbid': user}) if ret == '0': + logger.info("Deleted user with id %s from TS3 server." % uid) return True else: + logger.warn("User with id %s not found on TS3 server. Assuming succesful deletion." % uid) return True @staticmethod @@ -211,37 +250,42 @@ class Teamspeak3Manager: @staticmethod def generate_new_permissionkey(uid, username, corpticker): + logger.debug("Re-issuing permission key for user id %s" % uid) Teamspeak3Manager.delete_user(uid) return Teamspeak3Manager.add_user(username, corpticker) @staticmethod def generate_new_blue_permissionkey(uid, username, corpticker): + logger.debug("Re-issuing blue permission key for user id %s" % uid) Teamspeak3Manager.delete_user(uid) return Teamspeak3Manager.add_blue_user(username, corpticker) @staticmethod def update_groups(uid, ts_groups): + logger.debug("Updating uid %s TS3 groups %s" % (uid, ts_groups)) userid = Teamspeak3Manager._get_userid(uid) addgroups = [] remgroups = [] if userid is not None: user_ts_groups = Teamspeak3Manager._user_group_list(userid) + logger.debug("User has groups on TS3 server: %s" % user_ts_groups) for key in user_ts_groups: user_ts_groups[key] = int(user_ts_groups[key]) for ts_group_key in ts_groups: + logger.debug("Checking if user has group %s on TS3 server." % ts_group_key) if ts_groups[ts_group_key] not in user_ts_groups.values(): addgroups.append(ts_groups[ts_group_key]) for user_ts_group_key in user_ts_groups: if user_ts_groups[user_ts_group_key] not in ts_groups.values(): remgroups.append(user_ts_groups[user_ts_group_key]) - print userid - print addgroups - print remgroups + logger.info("Finished checking user id %s TS3 groups - adding %s, removing %s." % (userid, addgroups, remgroups)) for g in addgroups: + logger.debug("Issuing add command for group %s" % g) Teamspeak3Manager._add_user_to_group(userid, g) for g in remgroups: + logger.debug("Issuing remove command for group %s" % g) Teamspeak3Manager._remove_user_from_group(userid, g) diff --git a/services/models.py b/services/models.py index 87a5ad57..2cc7f017 100644 --- a/services/models.py +++ b/services/models.py @@ -1,5 +1,5 @@ from django.db import models -from django.contrib.auth.models import Group +from django.contrib.auth.models import Group, User class TSgroup(models.Model): ts_group_id = models.IntegerField(primary_key=True) @@ -29,4 +29,12 @@ class UserTSgroup(models.Model): verbose_name='User TS Group' def __str__(self): - return self.user.name \ No newline at end of file + return self.user.name + +class DiscordAuthToken(models.Model): + email = models.CharField(max_length=254, unique=True) + token = models.CharField(max_length=254) + user = models.ForeignKey(User, on_delete=models.CASCADE, null=True) + def __str__(self): + output = "Discord Token for email %s user %s" % (self.email, self.user) + return output.encode('utf-8') diff --git a/services/views.py b/services/views.py index dacefebd..6cac1456 100755 --- a/services/views.py +++ b/services/views.py @@ -4,6 +4,7 @@ from django.shortcuts import render_to_response from django.contrib.auth.decorators import login_required from django.contrib.auth.decorators import permission_required from django.contrib.auth.decorators import user_passes_test +from django.contrib.auth.models import Group from eveonline.models import EveCharacter from authentication.models import AuthServicesInfo @@ -30,11 +31,17 @@ from util import check_if_user_has_permission import threading import datetime +import logging + +logger = logging.getLogger(__name__) @login_required def fleet_formatter_view(request): + logger.debug("fleet_formatter_view called by user %s" % request.user) + generated = "" if request.method == 'POST': form = FleetFormatterForm(request.POST) + logger.debug("Received POST request containing form, valid: %s" % form.is_valid()) if form.is_valid(): generated = "Fleet Name: " + form.cleaned_data['fleet_name'] + "\n" generated = generated + "FC: " + form.cleaned_data['fleet_commander'] + "\n" @@ -48,9 +55,10 @@ def fleet_formatter_view(request): generated = generated + "Important: " + form.cleaned_data['important'] + "\n" if form.cleaned_data['comments'] != "": generated = generated + "Why: " + form.cleaned_data['comments'] + "\n" + logger.info("Formatted fleet broadcast for user %s" % request.user) else: form = FleetFormatterForm() - generated = "" + logger.debug("Returning empty form to user %s" % request.user) context = {'form': form, 'generated': generated} @@ -59,12 +67,15 @@ def fleet_formatter_view(request): @login_required @permission_required('auth.jabber_broadcast') def jabber_broadcast_view(request): + logger.debug("jabber_broadcast_view called by user %s" % request.user) success = False if request.method == 'POST': form = JabberBroadcastForm(request.POST) + logger.debug("Received POST request containing form, valid: %s" % form.is_valid()) if form.is_valid(): user_info = AuthServicesInfo.objects.get(user=request.user) main_char = EveCharacter.objects.get(character_id=user_info.main_char_id) + logger.debug("Processing jabber broadcast for user %s with main character %s" % (user_info, main_char)) if user_info.main_char_id != "": message_to_send = form.cleaned_data['message'] + "\n##### SENT BY: " + "[" + main_char.corporation_ticker + "]" + main_char.character_name + " TO: " + form.cleaned_data['group'] + " WHEN: " + datetime.datetime.utcnow().strftime("%Y-%m-%d %H:%M:%S") + " #####\n##### Replies are NOT monitored #####\n" group_to_send = form.cleaned_data['group'] @@ -78,8 +89,10 @@ def jabber_broadcast_view(request): OpenfireManager.send_broadcast_threaded(group_to_send, message_to_send,) success = True + logger.info("Sent jabber broadcast on behalf of user %s" % request.user) else: - form = JabberBroadcastForm() + form = JabberBroadcastForm(request.user) + logger.debug("Generated broadcast form for user %s containing %s groups" % (request.user, len(form.fields['group'].choices))) context = {'form': form, 'success': success} return render_to_response('registered/jabberbroadcast.html', context, context_instance=RequestContext(request)) @@ -87,6 +100,7 @@ def jabber_broadcast_view(request): @login_required def services_view(request): + logger.debug("services_view called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) return render_to_response('registered/services.html', {'authinfo': authinfo}, @@ -100,184 +114,236 @@ def service_blue_alliance_test(user): @login_required @user_passes_test(service_blue_alliance_test) def activate_forum(request): + logger.debug("activate_forum called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) # Valid now we get the main characters character = EveManager.get_character_by_id(authinfo.main_char_id) + logger.debug("Adding phpbb user for user %s with main character %s" % (request.user, character)) result = Phpbb3Manager.add_user(character.character_name, request.user.email, ['REGISTERED'], authinfo.main_char_id) # if empty we failed if result[0] != "": AuthServicesInfoManager.update_user_forum_info(result[0], result[1], request.user) + logger.debug("Updated authserviceinfo for user %s with forum credentials. Updating groups." % request.user) update_forum_groups(request.user) + logger.info("Succesfully activated forum for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to activate forum for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def deactivate_forum(request): + logger.debug("deactivate_forum called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = Phpbb3Manager.disable_user(authinfo.forum_username) remove_all_syncgroups_for_service(request.user, "phpbb") # false we failed if result: AuthServicesInfoManager.update_user_forum_info("", "", request.user) + logger.info("Succesfully deactivated forum for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to activate forum for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def reset_forum_password(request): + logger.debug("reset_forum_password called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = Phpbb3Manager.update_user_password(authinfo.forum_username, authinfo.main_char_id) # false we failed if result != "": AuthServicesInfoManager.update_user_forum_info(authinfo.forum_username, result, request.user) + logger.info("Succesfully reset forum password for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to reset forum password for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def activate_ipboard_forum(request): + logger.debug("activate_ipboard_forum called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) # Valid now we get the main characters character = EveManager.get_character_by_id(authinfo.main_char_id) + logger.debug("Adding ipboard user for user %s with main character %s" % (request.user, character)) result = IPBoardManager.add_user(character.character_name, request.user.email) if result[0] != "": AuthServicesInfoManager.update_user_ipboard_info(result[0], result[1], request.user) + logger.debug("Updated authserviceinfo for user %s with ipboard credentials. Updating groups." % request.user) update_ipboard_groups(request.user) + logger.info("Succesfully activated ipboard for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to activate ipboard for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def deactivate_ipboard_forum(request): + logger.debug("deactivate_ipboard_forum called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = IPBoardManager.disable_user(authinfo.ipboard_username) remove_all_syncgroups_for_service(request.user, "ipboard") # false we failed if result: AuthServicesInfoManager.update_user_ipboard_info("", "", request.user) + logger.info("Succesfully deactivated ipboard for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to deactviate ipboard for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def reset_ipboard_password(request): + logger.debug("reset_ipboard_password called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = IPBoardManager.update_user_password(authinfo.ipboard_username, request.user.email) if result != "": AuthServicesInfoManager.update_user_ipboard_info(authinfo.ipboard_username, result, request.user) + logger.info("Succesfully reset ipboard password for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to reset ipboard password for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def activate_jabber(request): + logger.debug("activate_jabber called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) character = EveManager.get_character_by_id(authinfo.main_char_id) + logger.debug("Adding jabber user for user %s with main character %s" % (request.user, character)) info = OpenfireManager.add_user(character.character_name) # If our username is blank means we already had a user if info[0] is not "": AuthServicesInfoManager.update_user_jabber_info(info[0], info[1], request.user) + logger.debug("Updated authserviceinfo for user %s with jabber credentials. Updating groups." % request.user) update_jabber_groups(request.user) + logger.info("Succesfully activated jabber for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to activate jabber for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def deactivate_jabber(request): + logger.debug("deactivate_jabber called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = OpenfireManager.delete_user(authinfo.jabber_username) remove_all_syncgroups_for_service(request.user, "openfire") # If our username is blank means we failed if result: AuthServicesInfoManager.update_user_jabber_info("", "", request.user) + logger.info("Succesfully deactivated jabber for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to deactivate jabber for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def reset_jabber_password(request): + logger.debug("reset_jabber_password called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = OpenfireManager.update_user_pass(authinfo.jabber_username) # If our username is blank means we failed if result != "": AuthServicesInfoManager.update_user_jabber_info(authinfo.jabber_username, result, request.user) + logger.info("Succesfully reset jabber password for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to reset jabber for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def activate_mumble(request): + logger.debug("activate_mumble called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) character = EveManager.get_character_by_id(authinfo.main_char_id) if check_if_user_has_permission(request.user, "blue_member"): + logger.debug("Adding mumble user for blue user %s with main character %s" % (request.user, character)) result = MumbleManager.create_blue_user(character.corporation_ticker, character.character_name) else: + logger.debug("Adding mumble user for user %s with main character %s" % (request.user, character)) result = MumbleManager.create_user(character.corporation_ticker, character.character_name) # if its empty we failed if result[0] is not "": AuthServicesInfoManager.update_user_mumble_info(result[0], result[1], request.user) + logger.debug("Updated authserviceinfo for user %s with mumble credentials. Updating groups." % request.user) update_mumble_groups(request.user) + logger.info("Succesfully activated mumble for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to activate mumble for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def deactivate_mumble(request): + logger.debug("deactivate_mumble called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = MumbleManager.delete_user(authinfo.mumble_username) remove_all_syncgroups_for_service(request.user, "mumble") # if false we failed if result: AuthServicesInfoManager.update_user_mumble_info("", "", request.user) + logger.info("Succesfully deactivated mumble for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to deactivate mumble for user %s" % request.user) return HttpResponseRedirect("/") @login_required @user_passes_test(service_blue_alliance_test) def reset_mumble_password(request): + logger.debug("reset_mumble_password called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = MumbleManager.update_user_password(authinfo.mumble_username) # if blank we failed if result != "": AuthServicesInfoManager.update_user_mumble_info(authinfo.mumble_username, result, request.user) + logger.info("Succesfully reset mumble password for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to reset mumble password for user %s" % request.user) return HttpResponseRedirect("/") @login_required @user_passes_test(service_blue_alliance_test) def activate_teamspeak3(request): + logger.debug("activate_teamspeak3 called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) character = EveManager.get_character_by_id(authinfo.main_char_id) if check_if_user_has_permission(request.user, "blue_member"): + logger.debug("Adding TS3 user for blue user %s with main character %s" % (request.user, character)) result = Teamspeak3Manager.add_blue_user(character.character_name, character.corporation_ticker) else: + logger.debug("Adding TS3 user for user %s with main character %s" % (request.user, character)) result = Teamspeak3Manager.add_user(character.character_name, character.corporation_ticker) # if its empty we failed if result[0] is not "": AuthServicesInfoManager.update_user_teamspeak3_info(result[0], result[1], request.user) + logger.debug("Updated authserviceinfo for user %s with TS3 credentials. Updating groups." % request.user) update_teamspeak3_groups(request.user) + logger.info("Succesfully activated TS3 for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to activate TS3 for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def deactivate_teamspeak3(request): + logger.debug("deactivate_teamspeak3 called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = Teamspeak3Manager.delete_user(authinfo.teamspeak3_uid) @@ -286,37 +352,45 @@ def deactivate_teamspeak3(request): # if false we failed if result: AuthServicesInfoManager.update_user_teamspeak3_info("", "", request.user) - + logger.info("Succesfully deactivated TS3 for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to deactivate TS3 for user %s" % request.user) return HttpResponseRedirect("/") @login_required @user_passes_test(service_blue_alliance_test) def reset_teamspeak3_perm(request): + logger.debug("reset_teamspeak3_perm called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) character = EveManager.get_character_by_id(authinfo.main_char_id) - + logger.debug("Deleting TS3 user for user %s" % request.user) Teamspeak3Manager.delete_user(authinfo.teamspeak3_uid) remove_all_syncgroups_for_service(request.user, "teamspeak3") if check_if_user_has_permission(request.user, "blue_member"): + logger.debug("Generating new permission key for blue user %s with main character %s" % (request.user, character)) result = Teamspeak3Manager.generate_new_blue_permissionkey(authinfo.teamspeak3_uid, character.character_name, character.corporation_ticker) else: + logger.debug("Generating new permission key for user %s with main character %s" % (request.user, character)) result = Teamspeak3Manager.generate_new_permissionkey(authinfo.teamspeak3_uid, character.character_name, character.corporation_ticker) # if blank we failed if result != "": AuthServicesInfoManager.update_user_teamspeak3_info(result[0], result[1], request.user) + logger.debug("Updated authserviceinfo for user %s with TS3 credentials. Updating groups." % request.user) update_teamspeak3_groups(request.user) + logger.info("Successfully reset TS3 permission key for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccessful attempt to reset TS3 permission key for user %s" % request.user) return HttpResponseRedirect("/") @login_required def fleet_fits(request): + logger.debug("fleet_fits called by user %s" % request.user) context = {} return render_to_response('registered/fleetfits.html', context, context_instance=RequestContext(request)) @@ -324,44 +398,62 @@ context_instance=RequestContext(request)) @login_required @user_passes_test(service_blue_alliance_test) def deactivate_discord(request): + logger.debug("deactivate_discord called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = DiscordManager.delete_user(authinfo.discord_uid) if result: remove_all_syncgroups_for_service(request.user, "discord") AuthServicesInfoManager.update_user_discord_info("", request.user) + logger.info("Succesfully deactivated discord for user %s" % request.user) return HttpResponseRedirect("/services/") + logger.error("Unsuccesful attempt to deactivate discord for user %s" % request.user) return HttpResponseRedirect("/dashboard") @login_required @user_passes_test(service_blue_alliance_test) def reset_discord(request): + logger.debug("reset_discord called by user %s" % request.user) authinfo = AuthServicesInfoManager.get_auth_service_info(request.user) result = DiscordManager.delete_user(authinfo.discord_uid) if result: AuthServicesInfoManager.update_user_discord_info("",request.user) + logger.info("Succesfully deleted discord user for user %s - forwarding to discord activation." % request.user) return HttpResponseRedirect("/activate_discord/") + logger.error("Unsuccessful attempt to reset discord for user %s" % request.user) return HttpResponseRedirect("/services/") @login_required @user_passes_test(service_blue_alliance_test) def activate_discord(request): + logger.debug("activate_discord called by user %s" % request.user) success = False if request.method == 'POST': + logger.debug("Received POST request with form.") form = DiscordForm(request.POST) + logger.debug("Form is valid: %s" % form.is_valid()) if form.is_valid(): email = form.cleaned_data['email'] + logger.debug("Form contains email address beginning with %s" % email[0:3]) password = form.cleaned_data['password'] + logger.debug("Form contains password of length %s" % len(password)) try: - user_id = DiscordManager.add_user(email, password) + user_id = DiscordManager.add_user(email, password, request.user) + logger.debug("Received discord uid %s" % user_id) if user_id != "": AuthServicesInfoManager.update_user_discord_info(user_id, request.user) + logger.debug("Updated discord id %s for user %s" % (user_id, request.user)) update_discord_groups(request.user) + logger.debug("Updated discord groups for user %s." % request.user) success = True + logger.info("Succesfully activated discord for user %s" % request.user) return HttpResponseRedirect("/services/") except: + logger.exception("An unhandled exception has occured.", exc_info=True) pass else: + logger.debug("Request is not type POST - providing empty form.") form = DiscordForm() + logger.debug("Rendering form for user %s with success %s" % (request.user, success)) context = {'form': form, 'success': success} return render_to_response('registered/discord.html', context, 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/stock/templates/public/index.html b/stock/templates/public/index.html index 76821d67..039b7523 100644 --- a/stock/templates/public/index.html +++ b/stock/templates/public/index.html @@ -52,18 +52,27 @@

- -

- - - -

- -

- - - -

+ {% if FORUM_URL %} +

+ + + +

+ {% endif %} + {% if KILLBOARD_URL %} +

+ + + +

+ {% endif %} + {% if MEDIA_URL %} +

+ + + +

+ {% endif %} diff --git a/stock/templates/registration/password_reset_email.html b/stock/templates/registration/password_reset_email.html index 63d42122..1b3d2c05 100644 --- a/stock/templates/registration/password_reset_email.html +++ b/stock/templates/registration/password_reset_email.html @@ -4,12 +4,12 @@ {% trans "Please go to the following page and choose a new password:" %} {% block reset_link %} - https://someurl.com{% url 'password_reset_confirm' uidb64=uid token=token %} + {{domain}}{% url 'password_reset_confirm' uidb64=uid token=token %} {% endblock %} {% trans "Your username, in case you've forgotten:" %} {{ user.get_username }} {% trans "Thanks for using our site!" %} - {% blocktrans %}Your Corporation{% endblocktrans %} + {% blocktrans %}Your IT Team{% endblocktrans %} {% endautoescape %} 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..1d4a35e1 100755 --- a/util/__init__.py +++ b/util/__init__.py @@ -6,12 +6,16 @@ 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) Permission.objects.get_or_create(codename="member", content_type=ct, name="member") Permission.objects.get_or_create(codename="group_management", content_type=ct, name="group_management") Permission.objects.get_or_create(codename="jabber_broadcast", content_type=ct, name="jabber_broadcast") + Permission.objects.get_or_create(codename="jabber_broadcast_all", content_type=ct, name="jabber_broadcast_all") Permission.objects.get_or_create(codename="human_resources", content_type=ct, name="human_resources") Permission.objects.get_or_create(codename="blue_member", content_type=ct, name="blue_member") Permission.objects.get_or_create(codename="corp_stats", content_type=ct, name="corp_stats") @@ -20,18 +24,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 +49,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..c29f5aee 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 group %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) diff --git a/util/context_processors.py b/util/context_processors.py index 3ddbbe92..2d8444a3 100755 --- a/util/context_processors.py +++ b/util/context_processors.py @@ -44,4 +44,6 @@ def domain_url(request): 'TEAMSPEAK3_PUBLIC_URL': settings.TEAMSPEAK3_PUBLIC_URL, 'JACK_KNIFE_URL': settings.JACK_KNIFE_URL, 'DISCORD_SERVER_ID': settings.DISCORD_SERVER_ID, + 'KILLBOARD_URL': settings.KILLBOARD_URL, + 'MEDIA_URL': settings.MEDIA_URL, 'CURRENT_UTC_TIME': timezone.now()}