Merge pull request #158 from Adarnof/more_logging

Holiday Goodies

.gitignore

@@ -45,7 +45,7 @@ coverage.xml
 *.pot
 
 # Django stuff:
-*.log
+*.log*
 
 # Sphinx documentation
 docs/_build/

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',
+        },
+    }
+}
+

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)

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("/")
+    logger.info("Successful logout for user %s" % request.user)
+    return HttpResponseRedirect("/")

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()):
+    logger.debug("Updating user %s teamspeak3 groups to %s" % (user, groups))
-        Teamspeak3Manager.update_groups(authserviceinfo.teamspeak3_uid, 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):
+                    logger.debug("Owning corp has an alliance, got info: %s" % alliance_info)
-                        EveManager.create_alliance_info(settings.ALLIANCE_ID, alliance_info['name'], alliance_info['ticker'],
+                    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]:
+                        logger.info("Corp model %s is not owning, member of owning alliance, or in standings. Updating as non-blue." % all_corp_info)
-                            if int(corp_standings[standing_level][int(all_corp_info.corporation_id)][
+                        EveManager.update_corporation_info(corpinfo['id'], corpinfo['members']['current'], None, False)
-                                '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)
                 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()

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

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):

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))

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")

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))

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))

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

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))
+    return render_to_response('public/register.html', {'form': form}, context_instance=RequestContext(request))

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)
+admin.site.register(TSgroup, TSgroupAdmin)
+
+admin.site.register(DiscordAuthToken)

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 = []
+    def __init__(self, user, *args, **kwargs):
-    allchoices.append(('all', 'all'))
+        super(JabberBroadcastForm, self).__init__(*args, **kwargs)
-    for group in Group.objects.all():
+        allchoices = []
-        allchoices.append((str(group.name), str(group.name)))
+        if check_if_user_has_permission(user, 'jabber_broadcast_all'):
-    group = forms.ChoiceField(choices=allchoices, widget=forms.Select)
+            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)
 
 

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):
+    def __init__(self, server_id, email, password, user=None):
-        data = {
+        self.token = DiscordAPIManager.get_token_by_user(email, password, user)
-            "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']
         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):
+    @staticmethod
-        if hasattr(self, 'token'):
+    def validate_token(token):
-            if self.token and self.token != "":
+        custom_headers = {'accept': 'application/json', 'authorization': token}
-                data = {'token': self.token}
+        path = DISCORD_URL + "/users/@me"
-                path = DISCORD_URL + "/auth/logout"
+        r = requests.get(path, headers=custom_headers)
-                custom_headers = {'content-type':'application/json'}
+        if r.status_code == 200:
-                r = requests.post(path, headers=custom_headers, data=json.dumps(data))
+            logger.debug("Token starting with %s passed validation." % token[0:5])
-                r.raise_for_status()
+            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(self, invite_id):
-    def accept_invite(invite_id, token):
+        custom_headers = {'accept': 'application/json', 'authorization': self.token}
-        custom_headers = {'accept': 'application/json', 'authorization': 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)
+            logger.debug("Adding new user %s to discord with email %s and password of length %s" % (user, email[0:3], len(password)))
-            profile = DiscordAPIManager.get_user_profile(email, 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):
+            logger.debug("Determined user id: %s" % user_id)
-                api.unban_user(user_id)
+            if server_api.check_if_user_banned(user_id):
-            invite_code = api.create_invite()['code']
+                logger.debug("User is currently banned. Unbanning %s" % user_id)
-            token = DiscordAPIManager.get_token_by_user(email, password)
+                server_api.unban_user(user_id)
-            DiscordAPIManager.accept_invite(invite_code, token)
+            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

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

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
+        logger.info("Updating IPBoard groups for user %s - adding %s, removing %s" % (username, addgroups, remgroups))
-        print remgroups
         for g in addgroups:
             if not g in forum_groups:
                 IPBoardManager.add_group(g)
-            print username
+            logger.debug("Adding user %s to IPBoard group %s" % (username, g))
-            print 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
+        return plain_password

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)

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,):

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
+            logger.info("Updating phpbb user %s groups - adding %s, removing %s" % (username, addgroups, remgroups))
-            print addgroups
-            print 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

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
+            logger.info("Finished checking user id %s TS3 groups - adding %s, removing %s." % (userid, addgroups, remgroups))
-            print addgroups
-            print 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)
 

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
+        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')

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))

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}

stock/templates/public/index.html

@@ -52,18 +52,27 @@
             <img src="{% static 'img/index_images/auth.png' %}" border="0">
         </a>
     </p>
-
+    {% if FORUM_URL %}
-    <p style="text-align:center">
+        <p style="text-align:center">
-        <a href="/forums/">
+            <a href="{{FORUM_URL}}">
-            <img src="{% static 'img/index_images/forums.png' %}" border="0">
+                <img src="{% static 'img/index_images/forums.png' %}" border="0">
-        </a>
+            </a>
-    </p>
+        </p>
-
+    {% endif %}
-    <p style="text-align:center">
+    {% if KILLBOARD_URL %}
-        <a href="/killboard/">
+        <p style="text-align:center">
-            <img src="{% static 'img/index_images/killboard.png' %}" border="0">
+            <a href="{{KILLBOARD_URL}}">
-        </a>
+                <img src="{% static 'img/index_images/killboard.png' %}" border="0">
-    </p>
+            </a>
+        </p>
+    {% endif %}
+    {% if MEDIA_URL %}
+        <p style="text-align:center">
+            <a href="{{MEDIA_URL}}">
+                <img src="{% static 'img/index_images/media.png' %}" border="0">
+            </a>
+        </p>
+    {% endif %}
 </div>
 </body>
 </html>

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 %}

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/")

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):

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)
 

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()}