Merge branch 'feature/logging' into develop

geruecht/__init__.py

@@ -4,18 +4,18 @@
     Initialize also a singelton for the AccesTokenControler and start the Thread.
 
 """
-from .logger import getLogger
+from .logger import getDebugLogger
 from geruecht.controller import dbConfig, ldapConfig
 from flask_mysqldb import MySQL
 from flask_ldapconn import LDAPConn
 
-LOGGER = getLogger(__name__)
+DEBUG = getDebugLogger()
-LOGGER.info("Initialize App")
+DEBUG.info("Initialize App")
 
 from flask import Flask
 from flask_cors import CORS
 
-LOGGER.info("Build APP")
+DEBUG.info("Build APP")
 app = Flask(__name__)
 CORS(app)
 app.config['SECRET_KEY'] = '0a657b97ef546da90b2db91862ad4e29'
@@ -40,7 +40,7 @@ from geruecht.user.routes import user
 from geruecht.vorstand.routes import vorstand
 from geruecht.gastro.routes import gastrouser
 
-LOGGER.info("Registrate bluebrints")
+DEBUG.info("Registrate bluebrints")
 app.register_blueprint(baruser)
 app.register_blueprint(finanzer)
 app.register_blueprint(user)

geruecht/baruser/routes.py

@@ -4,10 +4,14 @@ import geruecht.controller.userController as uc
 from datetime import datetime
 from geruecht.model import BAR, MONEY, USER, VORSTAND
 from geruecht.decorator import login_required
+from geruecht.logger import getDebugLogger, getCreditLogger
+
+debug = getDebugLogger()
+creditL = getCreditLogger()
 
 baruser = Blueprint("baruser", __name__)
 
-ldap= lc.LDAPController()
+ldap = lc.LDAPController()
 userController = uc.UserController()
 
 
@@ -22,28 +26,32 @@ def _bar(**kwargs):
             JSON-File with Users, who has amounts in this month
             or ERROR 401 Permission Denied
     """
-    dic = {}
+    debug.info("/bar")
-    users = userController.getAllUsersfromDB()
+    try:
-    for user in users:
+        dic = {}
-        geruecht = None
+        users = userController.getAllUsersfromDB()
-        geruecht = user.getGeruecht(datetime.now().year)
+        for user in users:
-        if geruecht is not None:
+            geruecht = None
-            month = geruecht.getMonth(datetime.now().month)
+            geruecht = user.getGeruecht(datetime.now().year)
-            amount = month[0] - month[1]
+            if geruecht is not None:
-            all = geruecht.getSchulden()
+                all = geruecht.getSchulden()
-            if all != 0:
+                if all != 0:
-                if all >= 0:
+                    if all >= 0:
-                    type = 'credit'
+                        type = 'credit'
-                else:
+                    else:
-                    type = 'amount'
+                        type = 'amount'
-                dic[user.uid] = {"username": user.uid,
+                    dic[user.uid] = {"username": user.uid,
-                                    "firstname": user.firstname,
+                                     "firstname": user.firstname,
-                                    "lastname": user.lastname,
+                                     "lastname": user.lastname,
-                                    "amount": all,
+                                     "amount": all,
-                                    "locked": user.locked,
+                                     "locked": user.locked,
-                                    "type": type
+                                     "type": type
-                                    }
+                                     }
-    return jsonify(dic)
+        debug.debug("return {{ {} }}".format(dic))
+        return jsonify(dic)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
 
 @baruser.route("/baradd", methods=['POST'])
@@ -57,26 +65,34 @@ def _baradd(**kwargs):
             JSON-File with userID and the amount
             or ERROR 401 Permission Denied
     """
-    data = request.get_json()
+    debug.info("/baradd")
-    userID = data['userId']
+    try:
-    amount = int(data['amount'])
+        data = request.get_json()
-
+        userID = data['userId']
-    date = datetime.now()
+        amount = int(data['amount'])
-    userController.addAmount(userID, amount, year=date.year, month=date.month)
+        amountl = amount
-    user = userController.getUser(userID)
+        date = datetime.now()
-    geruecht = user.getGeruecht(year=date.year)
+        userController.addAmount(
-    month = geruecht.getMonth(month=date.month)
+            userID, amount, year=date.year, month=date.month)
-    amount = abs(month[0] - month[1])
+        user = userController.getUser(userID)
-    all = geruecht.getSchulden()
+        geruecht = user.getGeruecht(year=date.year)
-    if all >= 0:
+        month = geruecht.getMonth(month=date.month)
-        type = 'credit'
+        amount = abs(month[0] - month[1])
-    else:
+        all = geruecht.getSchulden()
-        type = 'amount'
+        if all >= 0:
-    dic = user.toJSON()
+            type = 'credit'
-    dic['amount'] = abs(all)
+        else:
-    dic['type'] = type
+            type = 'amount'
-
+        dic = user.toJSON()
-    return jsonify(dic)
+        dic['amount'] = abs(all)
+        dic['type'] = type
+        debug.debug("return {{ {} }}".format(dic))
+        creditL.info("{} Baruser {} {} fügt {} {} {} € Schulden hinzu.".format(
+            date, kwargs['accToken'].user.firstname, kwargs['accToken'].user.lastname, user.firstname, user.lastname, amountl/100))
+        return jsonify(dic)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
 
 @baruser.route("/barGetUsers")
@@ -90,9 +106,16 @@ def _getUsers(**kwargs):
             JSON-File with Users
             or ERROR 401 Permission Denied
     """
-    retVal = {}
+    debug.info("/barGetUsers")
-    retVal = ldap.getAllUser()
+    try:
-    return jsonify(retVal)
+        retVal = {}
+        retVal = ldap.getAllUser()
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @baruser.route("/bar/storno", methods=['POST'])
 @login_required(groups=[BAR])
@@ -105,50 +128,72 @@ def _storno(**kwargs):
                 JSON-File with userID and the amount
                 or ERROR 401 Permission Denied
         """
-    data = request.get_json()
+    debug.info("/bar/storno")
-    userID = data['userId']
+    try:
-    amount = int(data['amount'])
+        data = request.get_json()
+        userID = data['userId']
+        amount = int(data['amount'])
+        amountl = amount
+        date = datetime.now()
+        userController.addCredit(
+            userID, amount, year=date.year, month=date.month)
+        user = userController.getUser(userID)
+        geruecht = user.getGeruecht(year=date.year)
+        month = geruecht.getMonth(month=date.month)
+        amount = abs(month[0] - month[1])
+        all = geruecht.getSchulden()
+        if all >= 0:
+            type = 'credit'
+        else:
+            type = 'amount'
+        dic = user.toJSON()
+        dic['amount'] = abs(all)
+        dic['type'] = type
+        debug.debug("return {{ {} }}".format(dic))
+        creditL.info("{} Baruser {} {} storniert {} € von {} {}".format(
+            date, kwargs['accToken'].user.firstname, kwargs['accToken'].user.lastname, amountl/100, user.firstname, user.lastname))
+        return jsonify(dic)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
-    date = datetime.now()
-    userController.addCredit(userID, amount, year=date.year, month=date.month)
-    user = userController.getUser(userID)
-    geruecht = user.getGeruecht(year=date.year)
-    month = geruecht.getMonth(month=date.month)
-    amount = abs(month[0] - month[1])
-    all = geruecht.getSchulden()
-    if all >= 0:
-        type = 'credit'
-    else:
-        type = 'amount'
-    dic = user.toJSON()
-    dic['amount'] = abs(all)
-    dic['type'] = type
-
-    return jsonify(dic)
 
 @baruser.route("/barGetUser", methods=['POST'])
 @login_required(groups=[BAR])
 def _getUser(**kwargs):
-    data = request.get_json()
+    debug.info("/barGetUser")
-    username = data['userId']
+    try:
-    user = userController.getUser(username)
+        data = request.get_json()
-    amount = user.getGeruecht(datetime.now().year).getSchulden()
+        username = data['userId']
-    if amount >= 0:
+        user = userController.getUser(username)
-        type = 'credit'
+        amount = user.getGeruecht(datetime.now().year).getSchulden()
-    else:
+        if amount >= 0:
-        type = 'amount'
+            type = 'credit'
+        else:
+            type = 'amount'
+
+        retVal = user.toJSON()
+        retVal['amount'] = amount
+        retVal['type'] = type
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
-    retVal = user.toJSON()
-    retVal['amount'] = amount
-    retVal['type'] = type
-    return jsonify(retVal)
 
 @baruser.route("/search", methods=['GET'])
-@login_required(groups=[BAR, MONEY, USER,VORSTAND])
+@login_required(groups=[BAR, MONEY, USER, VORSTAND])
 def _search(**kwargs):
-    retVal = ldap.getAllUser()
+    debug.info("/search")
-    for user in retVal:
+    try:
-        if user['username'] == 'extern':
+        retVal = ldap.getAllUser()
-            retVal.remove(user)
+        for user in retVal:
-            break
+            if user['username'] == 'extern':
-    return jsonify(retVal)
+                retVal.remove(user)
+                break
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500

geruecht/configparser.py

@@ -1,7 +1,7 @@
 import yaml
 import sys
-from .logger import getLogger
+from .logger import getDebugLogger
-LOGGER = getLogger(__name__)
+DEBUG = getDebugLogger()
 
 default = {
     'AccessTokenLifeTime': 1800,
@@ -15,6 +15,7 @@ default = {
     }
 }
 
+
 class ConifgParser():
     def __init__(self, file='config.yml'):
         self.file = file
@@ -22,55 +23,63 @@ class ConifgParser():
             self.config = yaml.safe_load(f)
 
         if 'Database' not in self.config:
-            self.__error__('Wrong Configuration for Database. You should configure databaseconfig with "URL", "user", "passwd", "database"')
+            self.__error__(
+                'Wrong Configuration for Database. You should configure databaseconfig with "URL", "user", "passwd", "database"')
         if 'URL' not in self.config['Database'] or 'user' not in self.config['Database'] or 'passwd' not in self.config['Database'] or 'database' not in self.config['Database']:
-            self.__error__('Wrong Configuration for Database. You should configure databaseconfig with "URL", "user", "passwd", "database"')
+            self.__error__(
+                'Wrong Configuration for Database. You should configure databaseconfig with "URL", "user", "passwd", "database"')
 
         self.db = self.config['Database']
-        LOGGER.debug("Set Databaseconfig: {}".format(self.db))
+        DEBUG.debug("Set Databaseconfig: {}".format(self.db))
 
         if 'LDAP' not in self.config:
-            self.__error__('Wrong Configuration for LDAP. You should configure ldapconfig with "URL" and "dn"')
+            self.__error__(
+                'Wrong Configuration for LDAP. You should configure ldapconfig with "URL" and "dn"')
         if 'URL' not in self.config['LDAP'] or 'dn' not in self.config['LDAP']:
-            self.__error__('Wrong Configuration for LDAP. You should configure ldapconfig with "URL" and "dn"')
+            self.__error__(
+                'Wrong Configuration for LDAP. You should configure ldapconfig with "URL" and "dn"')
         if 'port' not in self.config['LDAP']:
-            LOGGER.info('No Config for port in LDAP found. Set it to default: {}'.format(389))
+            DEBUG.info(
+                'No Config for port in LDAP found. Set it to default: {}'.format(389))
             self.config['LDAP']['port'] = 389
         self.ldap = self.config['LDAP']
-        LOGGER.info("Set LDAPconfig: {}".format(self.ldap))
+        DEBUG.info("Set LDAPconfig: {}".format(self.ldap))
         if 'AccessTokenLifeTime' in self.config:
             self.accessTokenLifeTime = int(self.config['AccessTokenLifeTime'])
-            LOGGER.info("Set AccessTokenLifeTime: {}".format(self.accessTokenLifeTime))
+            DEBUG.info("Set AccessTokenLifeTime: {}".format(
+                self.accessTokenLifeTime))
         else:
             self.accessTokenLifeTime = default['AccessTokenLifeTime']
-            LOGGER.info("No Config for AccessTokenLifetime found. Set it to default: {}".format(self.accessTokenLifeTime))
+            DEBUG.info("No Config for AccessTokenLifetime found. Set it to default: {}".format(
+                self.accessTokenLifeTime))
 
         if 'Mail' not in self.config:
             self.config['Mail'] = default['Mail']
-            LOGGER.info('No Conifg for Mail found. Set it to defaul: {}'.format(self.config['Mail']))
+            DEBUG.info('No Conifg for Mail found. Set it to defaul: {}'.format(
+                self.config['Mail']))
         if 'URL' not in self.config['Mail']:
             self.config['Mail']['URL'] = default['Mail']['URL']
-            LOGGER.info("No Config for URL in Mail found. Set it to default")
+            DEBUG.info("No Config for URL in Mail found. Set it to default")
         if 'port' not in self.config['Mail']:
             self.config['Mail']['port'] = default['Mail']['port']
-            LOGGER.info("No Config for port in Mail found. Set it to default")
+            DEBUG.info("No Config for port in Mail found. Set it to default")
         else:
             self.config['Mail']['port'] = int(self.config['Mail']['port'])
+            DEBUG.info("No Conifg for port in Mail found. Set it to default")
         if 'user' not in self.config['Mail']:
             self.config['Mail']['user'] = default['Mail']['user']
-            LOGGER.info("No Config for user in Mail found. Set it to default")
+            DEBUG.info("No Config for user in Mail found. Set it to default")
         if 'passwd' not in self.config['Mail']:
             self.config['Mail']['passwd'] = default['Mail']['passwd']
-            LOGGER.info("No Config for passwd in Mail found. Set it to default")
+            DEBUG.info("No Config for passwd in Mail found. Set it to default")
         if 'email' not in self.config['Mail']:
             self.config['Mail']['email'] = default['Mail']['email']
-            LOGGER.info("No Config for email in Mail found. Set it to default")
+            DEBUG.info("No Config for email in Mail found. Set it to default")
         if 'crypt' not in self.config['Mail']:
             self.config['Mail']['crypt'] = default['Mail']['crypt']
-            LOGGER.info("No Config for crypt in Mail found. Set it to default")
+            DEBUG.info("No Config for crypt in Mail found. Set it to default")
         self.mail = self.config['Mail']
-        LOGGER.info('Set Mailconfig: {}'.format(self.mail))
+        DEBUG.info('Set Mailconfig: {}'.format(self.mail))
-
 
     def getLDAP(self):
         return self.ldap
@@ -85,8 +94,9 @@ class ConifgParser():
         return self.mail
 
     def __error__(self, msg):
-        LOGGER.error(msg)
+        DEBUG.error(msg, exc_info=True)
         sys.exit(-1)
 
+
 if __name__ == '__main__':
-    ConifgParser()
+    ConifgParser()

geruecht/controller/__init__.py

@@ -1,4 +1,4 @@
-from geruecht.logger import getLogger
+from geruecht.logger import getDebugLogger
 from geruecht.configparser import ConifgParser
 import os
 
@@ -6,7 +6,7 @@ print(os.getcwd())
 
 config = ConifgParser('geruecht/config.yml')
 
-LOGGER = getLogger(__name__)
+LOGGER = getDebugLogger()
 
 class Singleton(type):
     _instances = {}

geruecht/controller/accesTokenController.py

@@ -2,10 +2,12 @@ from geruecht.model.accessToken import AccessToken
 import geruecht.controller as gc
 import geruecht.controller.userController as uc
 from geruecht.model import BAR
-from geruecht.controller import LOGGER
 from datetime import datetime, timedelta
 import hashlib
 from . import Singleton
+from geruecht.logger import getDebugLogger
+
+debug = getDebugLogger()
 
 userController = uc.UserController()
 
@@ -26,18 +28,21 @@ class AccesTokenController(metaclass=Singleton):
 
             Initialize Thread and set tokenList empty.
         """
-        LOGGER.info("Initialize AccessTokenController")
+        debug.info("init accesstoken controller")
         self.lifetime = gc.accConfig
-
         self.tokenList = []
 
     def checkBar(self, user):
+        debug.info("check if user {{ {} }} is baruser".format(user))
         if (userController.checkBarUser(user)):
             if BAR not in user.group:
+                debug.debug("append bar to user {{ {} }}".format(user))
                 user.group.append(BAR)
         else:
             while BAR in user.group:
+                debug.debug("delete bar from user {{ {} }}".format(user))
                 user.group.remove(BAR)
+        debug.debug("user {{ {} }} groups are {{ {} }}".format(user, user.group))
 
     def validateAccessToken(self, token, group):
         """ Verify Accestoken
@@ -51,28 +56,29 @@ class AccesTokenController(metaclass=Singleton):
             Returns:
                 An the AccesToken for this given Token or False.
         """
-        LOGGER.info("Verify AccessToken with token: {} and group: {}".format(token, group))
+        debug.info("check token {{ {} }} is valid")
         for accToken in self.tokenList:
-            LOGGER.debug("AccessToken is {}".format(accToken))
+            debug.debug("accesstoken is {}".format(accToken))
             endTime = accToken.timestamp + timedelta(seconds=accToken.lifetime)
             now = datetime.now()
-            LOGGER.debug("Check if AccessToken's Endtime {} is bigger then now {}".format(endTime, now))
+            debug.debug("now is {{ {} }}, endtime is {{ {} }}".format(now, endTime))
             if now <= endTime:
-                LOGGER.debug("Check is token {} same as in AccessToken {}".format(token, accToken))
+                debug.debug("check if token {{ {} }} is same as {{ {} }}".format(token, accToken))
                 if accToken == token:
                     self.checkBar(accToken.user)
-                    LOGGER.debug("Check if AccesToken {} has same group {}".format(accToken, group))
+                    debug.debug("check if accestoken {{ {} }} has group {{ {} }}".format(accToken, group))
                     if self.isSameGroup(accToken, group):
                         accToken.updateTimestamp()
-                        LOGGER.info("Found AccessToken {} with token: {} and group: {}".format(accToken, token, group))
+                        debug.debug("found accesstoken {{ {} }} with token: {{ {} }} and group: {{ {} }}".format(accToken, token, group))
                         return accToken
             else:
+                debug.debug("accesstoken is {{ {} }} out of date".format(accToken))
                 self.deleteAccessToken(accToken)
-        LOGGER.info("Found no valid AccessToken with token: {} and group: {}".format(token, group))
+        debug.debug("no valid accesstoken with token: {{ {} }} and group: {{ {} }}".format(token, group))
         return False
 
     def deleteAccessToken(self, accToken):
-        LOGGER.debug("AccessToken {} is no longer valid and will removed".format(accToken))
+        debug.info("delete accesstoken {{ {} }}".format(accToken))
         self.tokenList.remove(accToken)
 
     def createAccesToken(self, user, ldap_conn):
@@ -86,14 +92,13 @@ class AccesTokenController(metaclass=Singleton):
             Returns:
                 A created Token for User
         """
-        LOGGER.info("Create AccessToken")
+        debug.info("creat accesstoken")
         now = datetime.ctime(datetime.now())
         token = hashlib.md5((now + user.dn).encode('utf-8')).hexdigest()
         self.checkBar(user)
         accToken = AccessToken(user, token, ldap_conn, self.lifetime, datetime.now())
-        LOGGER.debug("Add AccessToken {} to current Tokens".format(accToken))
+        debug.debug("accesstoken is {{ {} }}".format(accToken))
         self.tokenList.append(accToken)
-        LOGGER.info("Finished create AccessToken {} with Token {}".format(accToken, token))
         return token
 
     def isSameGroup(self, accToken, groups):
@@ -108,8 +113,7 @@ class AccesTokenController(metaclass=Singleton):
             Returns:
                 A Bool. If the same then True else False
         """
-        print("controll if", accToken, "hase groups", groups)
+        debug.info("check accesstoken {{ {} }} has group {{ {} }}".format(accToken, groups))
-        LOGGER.debug("Check if AccessToken {} has group {}".format(accToken, groups))
         for group in groups:
             if group in accToken.user.group: return True
         return False

geruecht/controller/emailController.py

@@ -3,13 +3,14 @@ from datetime import datetime
 from email.mime.multipart import MIMEMultipart
 from email.mime.text import MIMEText
 from email.header import Header
-from geruecht import getLogger
+from geruecht.logger import getDebugLogger
 
-LOGGER = getLogger('E-MailController')
+debug = getDebugLogger()
 
 class EmailController():
 
     def __init__(self, smtpServer, user, passwd, crypt, port=587, email=""):
+        debug.info("init email controller")
         self.smtpServer = smtpServer
         self.port = port
         self.user = user
@@ -19,33 +20,36 @@ class EmailController():
             self.email = email
         else:
             self.email = user
-        LOGGER.debug('Init EmailController with smtpServer={}, port={}, user={}, crypt={}, email={}'.format(smtpServer, port, user, crypt, self.email))
+        debug.debug("smtpServer is {{ {} }}, port is {{ {} }}, user is {{ {} }}, crypt is {{ {} }}, email is {{ {} }}".format(smtpServer, port, user, crypt, self.email))
 
     def __connect__(self):
-        LOGGER.info('Connect to E-Mail-Server')
+        debug.info('connect to email server')
         if self.crypt == 'SSL':
             self.smtp = smtplib.SMTP_SSL(self.smtpServer, self.port)
             log = self.smtp.ehlo()
-            LOGGER.debug(log)
+            debug.debug("ehlo is {{ {} }}".format(log))
         if self.crypt == 'STARTTLS':
             self.smtp = smtplib.SMTP(self.smtpServer, self.port)
             log = self.smtp.ehlo()
-            LOGGER.debug(log)
+            debug.debug("ehlo is {{ {} }}".format(log))
             log = self.smtp.starttls()
-            LOGGER.debug(log)
+            debug.debug("starttles is {{ {} }}".format(log))
         log = self.smtp.login(self.user, self.passwd)
-        LOGGER.debug(log)
+        debug.debug("login is {{ {} }}".format(log))
 
     def jobTransact(self, user, jobtransact):
+        debug.info("create email jobtransact {{ {} }}for user {{ {} }}".format(jobtransact, user))
         date = '{}.{}.{}'.format(jobtransact['date'].day, jobtransact['date'].month, jobtransact['date'].year)
         from_user = '{} {}'.format(jobtransact['from_user'].firstname, jobtransact['from_user'].lastname)
         subject = 'Bardienstanfrage am {}'.format(date)
         text = MIMEText(
             "Hallo {} {},\n"
             "{} fragt, ob du am {} zum Bardienst teilnehmen willst. Beantworte die Anfrage im Userportal von Flaschengeist.".format(user.firstname, user.lastname, from_user, date), 'utf-8')
+        debug.debug("subject is {{ {} }}, text is {{ {} }}".format(subject, text.as_string()))
         return (subject, text)
 
     def credit(self, user):
+        debug.info("create email credit for user {{ {} }}".format(user))
         subject = Header('Gerücht, bezahle deine Schulden!', 'utf-8')
         sum = user.getGeruecht(datetime.now().year).getSchulden()
         if sum < 0:
@@ -57,12 +61,14 @@ class EmailController():
         text = MIMEText(
             "Hallo {} {},\nDu hast {} im Wert von {:.2f} €. {}\n\nDiese Nachricht wurde automatisch erstellt.".format(
                 user.firstname, user.lastname, type, abs(sum) / 100, add), 'plain', 'utf-8')
+        debug.debug("subject is {{ {} }}, text is {{ {} }}".format(subject, text.as_string()))
         return (subject, text)
 
     def sendMail(self, user, type='credit', jobtransact=None):
+        debug.info("send email to user {{ {} }}".format(user))
         try:
             if user.mail == 'None' or not user.mail:
-                LOGGER.debug("cant send email to {}. Has no email-address. {}".format(user.uid, {'error': True, 'user': {'userId': user.uid, 'firstname': user.firstname, 'lastname': user.lastname}}))
+                debug.warning("user {{ {} }} has no email-address".format(user))
                 raise Exception("no valid Email")
             msg = MIMEMultipart()
             msg['From'] = self.email
@@ -78,10 +84,10 @@ class EmailController():
             msg['Subject'] = subject
             msg.attach(text)
 
-            LOGGER.debug("Send email to {}: '{}'".format(user.uid, msg.as_string()))
+            debug.debug("send email {{ {} }} to user {{ {} }}".format(msg.as_string(), user))
             self.__connect__()
             self.smtp.sendmail(self.email, user.mail, msg.as_string())
-            LOGGER.debug("Sended email to {}. {}".format(user.uid, {'error': False, 'user': {'userId': user.uid, 'firstname': user.firstname, 'lastname': user.lastname}}))
             return {'error': False, 'user': {'userId': user.uid, 'firstname': user.firstname, 'lastname': user.lastname}}
         except Exception:
+            debug.warning("exception in send email", exc_info=True)
             return {'error': True, 'user': {'userId': user.uid, 'firstname': user.firstname, 'lastname': user.lastname}}

geruecht/controller/ldapController.py

@@ -6,7 +6,9 @@ from geruecht.exceptions import PermissionDenied
 from . import Singleton
 from geruecht.exceptions import UsernameExistLDAP, LDAPExcetpion
 from geruecht import ldapConfig
-import traceback
+from geruecht.logger import getDebugLogger
+
+debug = getDebugLogger()
 
 class LDAPController(metaclass=Singleton):
     '''
@@ -14,27 +16,38 @@ class LDAPController(metaclass=Singleton):
     '''
 
     def __init__(self):
+        debug.info("init ldap controller")
         self.dn = ldapConfig['dn']
         self.ldap = ldap
+        debug.debug("base dn is {{ {} }}".format(self.dn))
+        debug.debug("ldap is {{ {} }}".format(self.ldap))
 
 
     def login(self, username, password):
+        debug.info("login user {{ {} }} in ldap")
         try:
             retVal = self.ldap.authenticate(username, password, 'uid', self.dn)
+            debug.debug("authentification to ldap is {{ {} }}".format(retVal))
             if not retVal:
+                debug.debug("authenification is incorrect")
                 raise PermissionDenied("Invalid Password or Username")
         except Exception as err:
-            traceback.print_exception(err)
+            debug.warning("exception while login into ldap", exc_info=True)
-            raise PermissionDenied("Wrong username or password.")
+            raise PermissionDenied("Invalid Password or Username. {}".format(err))
 
     def bind(self, user, password):
+        debug.info("bind user {{ {} }} to ldap")
         ldap_conn = self.ldap.connect(user.dn, password)
+        debug.debug("ldap_conn is {{ {} }}".format(ldap_conn))
         return ldap_conn
 
     def getUserData(self, username):
+        debug.info("get user data from ldap of user {{ {} }}".format(username))
         try:
+            debug.debug("search user in ldap")
             self.ldap.connection.search('ou=user,{}'.format(self.dn), '(uid={})'.format(username), SUBTREE, attributes=['uid', 'givenName', 'sn', 'mail'])
             user = self.ldap.connection.response[0]['attributes']
+            debug.debug("user is {{ {} }}".format(user))
             retVal = {
                 'dn': self.ldap.connection.response[0]['dn'],
                 'firstname': user['givenName'][0],
@@ -43,20 +56,25 @@ class LDAPController(metaclass=Singleton):
             }
             if user['mail']:
                 retVal['mail'] = user['mail'][0]
+            debug.debug("user is {{ {} }}".format(retVal))
             return retVal
         except:
+            debug.warning("exception in get user data from ldap", exc_info=True)
             raise PermissionDenied("No User exists with this uid.")
 
 
     def getGroup(self, username):
+        debug.info("get group from user {{ {} }}".format(username))
         try:
             retVal = []
             self.ldap.connection.search('ou=user,{}'.format(self.dn), '(uid={})'.format(username), SUBTREE, attributes=['gidNumber'])
             response = self.ldap.connection.response
             main_group_number = self.ldap.connection.response[0]['attributes']['gidNumber']
+            debug.debug("main group number is {{ {} }}".format(main_group_number))
             if main_group_number:
                 group_data = self.ldap.connection.search('ou=group,{}'.format(self.dn), '(gidNumber={})'.format(main_group_number), attributes=['cn'])
                 group_name = self.ldap.connection.response[0]['attributes']['cn'][0]
+                debug.debug("group name is {{ {} }}".format(group_name))
                 if group_name == 'ldap-user':
                     retVal.append(USER)
                 if group_name == 'extern':
@@ -64,8 +82,10 @@ class LDAPController(metaclass=Singleton):
 
             self.ldap.connection.search('ou=group,{}'.format(self.dn), '(memberUID={})'.format(username), SUBTREE, attributes=['cn'])
             groups_data = self.ldap.connection.response
+            debug.debug("groups number is {{ {} }}".format(groups_data))
             for data in groups_data:
                 group_name = data['attributes']['cn'][0]
+                debug.debug("group name is {{ {} }}".format(group_name))
                 if group_name == 'finanzer':
                     retVal.append(MONEY)
                 elif group_name == 'gastro':
@@ -74,9 +94,11 @@ class LDAPController(metaclass=Singleton):
                     retVal.append(BAR)
                 elif group_name == 'vorstand':
                     retVal.append(VORSTAND)
+            debug.debug("groups are {{ {} }}".format(retVal))
             return retVal
         except Exception as err:
-            traceback.print_exc()
+            debug.warning("exception in get groups from ldap", exc_info=True)
+            raise LDAPExcetpion(str(err))
 
     def __isUserInList(self, list, username):
         help_list = []
@@ -87,15 +109,18 @@ class LDAPController(metaclass=Singleton):
         return False
 
     def getAllUser(self):
+        debug.info("get all users from ldap")
         retVal = []
         self.ldap.connection.search('ou=user,{}'.format(self.dn), '(uid=*)', SUBTREE, attributes=['uid', 'givenName', 'sn', 'mail'])
         data = self.ldap.connection.response
+        debug.debug("data is {{ {} }}".format(data))
         for user in data:
             if 'uid' in user['attributes']:
                 username = user['attributes']['uid'][0]
                 firstname = user['attributes']['givenName'][0]
                 lastname = user['attributes']['sn'][0]
                 retVal.append({'username': username, 'firstname': firstname, 'lastname': lastname})
+        debug.debug("users are {{ {} }}".format(retVal))
         return retVal
 
     def searchUser(self, searchString):
@@ -139,10 +164,13 @@ class LDAPController(metaclass=Singleton):
         return retVal
 
     def modifyUser(self, user, conn, attributes):
+        debug.info("modify ldap data from user {{ {} }} with attributes {{ {} }}".format(user, attributes))
         try:
             if 'username' in attributes:
+                debug.debug("change username")
                 conn.search('ou=user,{}'.format(self.dn), '(uid={})'.format(attributes['username']))
                 if conn.entries:
+                    debug.warning("username already exists", exc_info=True)
                     raise UsernameExistLDAP("Username already exists in LDAP")
             #create modifyer
             mody = {}
@@ -157,9 +185,10 @@ class LDAPController(metaclass=Singleton):
             if 'password' in attributes:
                 salted_password = hashed(HASHED_SALTED_MD5, attributes['password'])
                 mody['userPassword'] = [(MODIFY_REPLACE, [salted_password])]
+            debug.debug("modyfier are {{ {} }}".format(mody))
             conn.modify(user.dn, mody)
         except Exception as err:
-            traceback.print_exc()
+            debug.warning("exception in modify user data from ldap", exc_info=True)
             raise LDAPExcetpion("Something went wrong in LDAP: {}".format(err))
 
 

geruecht/controller/userController.py

@@ -1,4 +1,4 @@
-from . import LOGGER, Singleton, ldapConfig, dbConfig, mailConfig
+from . import Singleton, mailConfig
 import geruecht.controller.databaseController as dc
 import geruecht.controller.ldapController as lc
 import geruecht.controller.emailController as ec
@@ -6,219 +6,359 @@ import calendar
 from geruecht.model.user import User
 from geruecht.exceptions import PermissionDenied
 from datetime import datetime, timedelta
-from geruecht.exceptions import UsernameExistLDAP, UsernameExistDB, DatabaseExecption, LDAPExcetpion, DayLocked, TansactJobIsAnswerdException
+from geruecht.exceptions import UsernameExistLDAP, LDAPExcetpion, DayLocked, TansactJobIsAnswerdException
+from geruecht.logger import getDebugLogger
 
 db = dc.DatabaseController()
 ldap = lc.LDAPController()
 emailController = ec.EmailController(mailConfig['URL'], mailConfig['user'], mailConfig['passwd'], mailConfig['crypt'], mailConfig['port'], mailConfig['email'])
 
+debug = getDebugLogger()
+
 class UserController(metaclass=Singleton):
 
     def __init__(self):
+        debug.debug("init UserController")
         pass
 
     def getAllStatus(self):
-        return db.getAllStatus()
+        debug.info("get all status for user")
+        retVal = db.getAllStatus()
+        debug.debug("status are {{ {} }}".format(retVal))
+        return retVal
 
     def getStatus(self, name):
-        return db.getStatus(name)
+        debug.info("get status of user {{ {} }}".format(name))
+        retVal = db.getStatus(name)
+        debug.debug("status of user {{ {} }} is {{ {} }}".format(name, retVal))
+        return retVal
 
     def setStatus(self, name):
-        return db.setStatus(name)
+        debug.info("set status of user {{ {} }}".format(name))
+        retVal = db.setStatus(name)
+        debug.debug("settet status of user {{ {} }} is {{ {} }}".format(name, retVal))
+        return retVal
 
     def deleteStatus(self, status):
+        debug.info("delete status {{ {} }}".format(status))
         db.deleteStatus(status)
 
     def updateStatus(self, status):
-        return db.updateStatus(status)
+        debug.info("update status {{ {} }}".format(status))
+        retVal = db.updateStatus(status)
+        debug.debug("updated status is {{ {} }}".format(retVal))
+        return retVal
 
     def updateStatusOfUser(self, username, status):
-        return db.updateStatusOfUser(username, status)
+        debug.info("update status {{ {} }} of user {{ {} }}".format(status, username))
+        retVal = db.updateStatusOfUser(username, status)
+        debug.debug("updatet status of user {{ {} }} is {{ {} }}".format(username, retVal))
+        return retVal
 
     def updateVotingOfUser(self, username, voting):
-        return db.updateVotingOfUser(username, voting)
+        debug.info("update voting {{ {} }} of user {{ {} }}".format(voting, username))
+        retVal = db.updateVotingOfUser(username, voting)
+        debug.debug("updatet voting of user {{ {} }} is {{ {} }}".format(username, retVal))
+        return retVal
 
     def deleteDrinkType(self, type):
+        debug.info("delete drink type {{ {} }}".format(type))
         db.deleteDrinkType(type)
 
     def updateDrinkType(self, type):
-        return db.updateDrinkType(type)
+        debug.info("update drink type {{ {} }}".format(type))
+        retVal = db.updateDrinkType(type)
+        debug.debug("updated drink type is {{ {} }}".format(retVal))
+        return retVal
 
     def setDrinkType(self, type):
-        return db.setDrinkType(type)
+        debug.info("set drink type {{ {} }}".format(type))
+        retVal = db.setDrinkType(type)
+        debug.debug("seted drink type is {{ {} }}".format(retVal))
+        return retVal
 
     def deletDrinkPrice(self, drink):
+        debug.info("delete drink {{ {} }}".format(drink))
         db.deleteDrink(drink)
 
     def setDrinkPrice(self, drink):
+        debug.info("set drink {{ {} }}".format(drink))
         retVal = db.setDrinkPrice(drink)
+        debug.debug("seted drink is {{ {} }}".format(retVal))
         return retVal
 
     def updateDrinkPrice(self, drink):
+        debug.info("update drink {{ {} }}".format(drink))
         retVal = db.updateDrinkPrice(drink)
+        debug.debug("updated drink is {{ {} }}".format(retVal))
         return retVal
 
     def getAllDrinkTypes(self):
-        return db.getAllDrinkTypes()
+        debug.info("get all drink types")
+        retVal = db.getAllDrinkTypes()
+        debug.debug("all drink types are {{ {} }}".format(retVal))
+        return retVal
 
     def getPricelist(self):
+        debug.info("get all drinks")
         list = db.getPriceList()
+        debug.debug("all drinks are {{ {} }}".format(list))
         return list
 
     def setTransactJob(self, from_user, to_user, date):
+        debug.info("set transact job from {{ {} }} to {{ {} }} on {{ {} }}".format(from_user, to_user, date))
         jobtransact = db.setTransactJob(from_user, to_user, date.date())
+        debug.debug("transact job is {{ {} }}".format(jobtransact))
+        debug.info("send mail with transact job to user")
         emailController.sendMail(jobtransact['to_user'], 'jobtransact', jobtransact)
         return jobtransact
 
     def getTransactJobFromUser(self, user, date):
-        return db.getTransactJobFromUser(user, date.date())
+        debug.info("get transact job from user {{ {} }} on {{ {} }}".format(user, date))
+        retVal = db.getTransactJobFromUser(user, date.date())
+        debug.debug("transact job from user {{ {} }} is {{ {} }}".format(user, retVal))
+        return retVal
 
     def getAllTransactJobFromUser(self, user, date):
-        return db.getAllTransactJobFromUser(user, date.date())
+        debug.info("get all transact job from user {{ {} }} start on {{ {} }}".format(user, date))
+        retVal = db.getAllTransactJobFromUser(user, date.date())
+        debug.debug("all transact job are {{ {} }}".format(retVal))
+        return retVal
 
     def getAllTransactJobToUser(self, user, date):
-        return db.getAllTransactJobToUser(user, date.date())
+        debug.info("get all transact job from to_user {{ {} }} start on {{ {} }}".format(user, date))
+        retVal = db.getAllTransactJobToUser(user, date.date())
+        debug.debug("all transact job are {{ {} }}".format(retVal))
+        return retVal
 
     def getTransactJob(self, from_user, to_user, date):
-        return db.getTransactJob(from_user, to_user, date.date())
+        debug.info("get transact job from user {{ {} }} to user {{ {} }} on {{ {} }}".format(from_user, to_user, date))
+        retVal = db.getTransactJob(from_user, to_user, date.date())
+        debug.debug("transact job is {{ {} }}".format(retVal))
+        return retVal
 
     def deleteTransactJob(self, from_user, to_user, date):
+        debug.info("delete transact job from user {{ {} }} to user {{ {} }} on {{ {} }}".format(from_user, to_user, date))
         transactJob = self.getTransactJob(from_user, to_user, date)
+        debug.debug("transact job is {{ {} }}".format(transactJob))
         if transactJob['answerd']:
+            debug.warning("transactjob {{ {} }} can not delete because is answerd")
             raise TansactJobIsAnswerdException("TransactJob is already answerd")
         db.deleteTransactJob(from_user, to_user, date.date())
 
     def answerdTransactJob(self, from_user, to_user, date, answer):
+        debug.info("answer transact job from user {{ {} }} to user {{ {} }} on {{ {} }} with answer {{ {} }}".format(from_user, to_user, date, answer))
         transactJob = db.updateTransactJob(from_user, to_user, date.date(), answer)
+        debug.debug("transactjob is {{ {} }}".format(transactJob))
         if answer:
+            debug.info("add worker on date {{ {} }}".format(date))
             self.addWorker(to_user.uid, date)
         return transactJob
 
     def setLockedDay(self, date, locked, hard=False):
-        return db.setLockedDay(date.date(), locked, hard)
+        debug.info("set day locked on {{ {} }} with state {{ {} }}".format(date, locked))
+        retVal = db.setLockedDay(date.date(), locked, hard)
+        debug.debug("seted day locked is {{ {} }}".format(retVal))
+        return retVal
 
     def getLockedDay(self, date):
+        debug.info("get locked day on {{ {} }}".format(date))
         now = datetime.now()
+        debug.debug("now is {{ {} }}".format(now))
         oldMonth = False
+        debug.debug("check if date old month or current month")
         for i in range(1, 8):
             if datetime(now.year, now.month, i).weekday() == 2:
                 if now.day < i:
                     oldMonth = True
                     break
+        debug.debug("oldMonth is {{ {} }}".format(oldMonth))
         lockedYear = date.year
         lockedMonth = date.month if date.month < now.month else now.month - 1 if oldMonth else now.month
         daysInMonth = calendar.monthrange(lockedYear, lockedMonth)[1]
         startDay = 1
+        debug.debug("calculate start day of month")
         for i in range(1, 8):
             if datetime(lockedYear, lockedMonth, i).weekday() == 2:
                 startDay = i
                 break
+        debug.debug("start day of month is {{ {} }}".format(startDay))
+        debug.debug("check if date should be locked")
         if lockedYear <= now.year and lockedMonth <= now.month:
             for i in range(startDay, daysInMonth + 1):
+                debug.debug("lock day {{ {} }}".format(datetime(lockedYear, lockedMonth, i)))
                 self.setLockedDay(datetime(lockedYear, lockedMonth, i), True)
             for i in range(1, 8):
                 nextMonth = datetime(lockedYear, lockedMonth + 1, i)
                 if nextMonth.weekday() == 2:
                     break
+                debug.debug("lock day {{ {} }}".format(datetime(lockedYear, lockedMonth, i)))
                 self.setLockedDay(nextMonth, True)
-        return db.getLockedDay(date.date())
+        retVal = db.getLockedDay(date.date())
+        debug.debug("locked day is {{ {} }}".format(retVal))
+        return retVal
 
     def getWorker(self, date, username=None):
+        debug.info("get worker on {{ {} }}".format(username, date))
         if (username):
             user = self.getUser(username)
-            return [db.getWorker(user, date)]
+            debug.debug("user is {{ {} }}".format(user))
-        return db.getWorkers(date)
+            retVal = [db.getWorker(user, date)]
+            debug.debug("worker is {{ {} }}".format(retVal))
+            return retVal
+        retVal = db.getWorkers(date)
+        debug.debug("workers are {{ {} }}".format(retVal))
+        return retVal
 
     def addWorker(self, username, date, userExc=False):
+        debug.info("add job user {{ {} }} on {{ {} }}".format(username, date))
         if (userExc):
+            debug.debug("this is a user execution, check if day is locked")
             lockedDay = self.getLockedDay(date)
             if lockedDay:
                 if lockedDay['locked']:
+                    debug.debug("day is lockey. user cant get job")
                     raise DayLocked("Day is locked. You can't get the Job")
         user = self.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
+        debug.debug("check if user has job on date")
         if (not db.getWorker(user, date)):
+            debug.debug("set job to user")
             db.setWorker(user, date)
-        return self.getWorker(date, username=username)
+        retVal = self.getWorker(date, username=username)
+        debug.debug("worker on date is {{ {} }}".format(retVal))
+        return retVal
 
     def deleteWorker(self, username, date, userExc=False):
+        debug.info("delete worker {{ {} }} on date {{ {} }}".format(username, date))
         user = self.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
         if userExc:
+            debug.debug("is user execution, check if day locked")
             lockedDay = self.getLockedDay(date)
             if lockedDay:
                 if lockedDay['locked']:
+                    debug.debug("day is locked, check if accepted transact job exists")
                     transactJobs = self.getTransactJobFromUser(user, date)
+                    debug.debug("transact job is {{ {} }}".format(transactJobs))
                     found = False
                     for job in transactJobs:
                         if job['accepted'] and job['answerd']:
+                            debug.debug("accepted transact job exists")
                             found = True
                             break
                     if not found:
+                        debug.debug("no accepted transact job found")
                         raise DayLocked("Day is locked. You can't delete the Job")
         db.deleteWorker(user, date)
 
     def lockUser(self, username, locked):
+        debug.info("lock user {{ {} }} for credit with status {{ {} }}".format(username, locked))
         user = self.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
         user.updateData({'locked': locked})
         db.updateUser(user)
-        return self.getUser(username)
+        retVal = self.getUser(username)
+        debug.debug("locked user is {{ {} }}".format(retVal))
+        return retVal
 
     def updateConfig(self, username, data):
+        debug.info("update config of user {{ {} }} with config {{ {} }}".format(username, data))
         user = self.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
         user.updateData(data)
         db.updateUser(user)
-        return self.getUser(username)
+        retVal = self.getUser(username)
+        debug.debug("updated config of user is {{ {} }}".format(retVal))
+        return retVal
 
     def __updateDataFromLDAP(self, user):
+        debug.info("update data from ldap for user {{ {} }}".format(user))
         groups = ldap.getGroup(user.uid)
+        debug.debug("ldap gorups are {{ {} }}".format(groups))
         user_data = ldap.getUserData(user.uid)
+        debug.debug("ldap data is {{ {} }}".format(user_data))
         user_data['gruppe'] = groups
         user_data['group'] = groups
         user.updateData(user_data)
         db.updateUser(user)
 
     def autoLock(self, user):
+        debug.info("start autolock of user {{ {} }}".format(user))
         if user.autoLock:
-            if user.getGeruecht(year=datetime.now().year).getSchulden() <= (-1*user.limit):
+            debug.debug("autolock is active")
+            credit = user.getGeruecht(year=datetime.now().year).getSchulden()
+            limit = -1*user.limit
+            if credit <= limit:
+                debug.debug("credit {{ {} }} is more than user limit {{ {} }}".format(credit, limit))
+                debug.debug("lock user")
                 user.updateData({'locked': True})
+                debug.debug("send mail to user")
                 emailController.sendMail(user)
             else:
+                debug.debug("cretid {{ {} }} is less than user limit {{ {} }}".format(credit, limit))
+                debug.debug("unlock user")
                 user.updateData({'locked': False})
         db.updateUser(user)
 
     def addAmount(self, username, amount, year, month, finanzer=False):
+        debug.info("add amount {{ {} }} to user {{ {} }} no month {{ {} }}, year {{ {} }}".format(amount, username, month, year))
         user = self.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
         if user.uid == 'extern':
+            debug.debug("user is extern user, so exit add amount")
             return
         if not user.locked or finanzer:
+            debug.debug("user is not locked {{ {} }} or is finanzer execution {{ {} }}".format(user.locked, finanzer))
             user.addAmount(amount, year=year, month=month)
             creditLists = user.updateGeruecht()
+            debug.debug("creditList is {{ {} }}".format(creditLists))
             for creditList in creditLists:
+                debug.debug("update creditlist {{ {} }}".format(creditList))
                 db.updateCreditList(creditList)
+        debug.debug("do autolock")
         self.autoLock(user)
-        return user.getGeruecht(year)
+        retVal = user.getGeruecht(year)
+        debug.debug("updated creditlists is {{ {} }}".format(retVal))
+        return retVal
 
     def addCredit(self, username, credit, year, month):
+        debug.info("add credit {{ {} }} to user {{ {} }} on month {{ {} }}, year {{ {} }}".format(credit, username, month, year))
         user = self.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
         if user.uid == 'extern':
+            debug.debug("user is extern user, so exit add credit")
             return
         user.addCredit(credit, year=year, month=month)
         creditLists = user.updateGeruecht()
+        debug.debug("creditlists are {{ {} }}".format(creditLists))
         for creditList in creditLists:
+            debug.debug("update creditlist {{ {} }}".format(creditList))
             db.updateCreditList(creditList)
+        debug.debug("do autolock")
         self.autoLock(user)
-        return user.getGeruecht(year)
+        retVal = user.getGeruecht(year)
+        debug.debug("updated creditlists are {{ {} }}".format(retVal))
+        return retVal
 
     def getAllUsersfromDB(self):
+        debug.info("get all users from database")
         users = db.getAllUser()
+        debug.debug("users are {{ {} }}".format(users))
         for user in users:
             try:
+                debug.debug("update data from ldap")
                 self.__updateDataFromLDAP(user)
             except:
                 pass
+            debug.debug("update creditlists")
             self.__updateGeruechte(user)
-        return db.getAllUser(extern=True)
+        retVal = db.getAllUser(extern=True)
+        debug.debug("all users are {{ {} }}".format(retVal))
+        return retVal
 
     def checkBarUser(self, user):
+        debug.info("check if user {{ {} }} is baruser")
         date = datetime.now()
         zero = date.replace(hour=0, minute=0, second=0, microsecond=0)
         end = zero + timedelta(hours=12)
@@ -226,59 +366,84 @@ class UserController(metaclass=Singleton):
         if date > zero and end > date:
              startdatetime = startdatetime - timedelta(days=1)
         enddatetime = startdatetime + timedelta(days=1)
+        debug.debug("startdatetime is {{ {} }} and enddatetime is {{ {} }}".format(startdatetime, end))
         result = False
         if date >= startdatetime and date < enddatetime:
             result = db.getWorker(user, startdatetime)
+        debug.debug("worker is {{ {} }}".format(result))
         return True if result else False
 
 
     def getUser(self, username):
+        debug.info("get user {{ {} }}".format(username))
         user = db.getUser(username)
+        debug.debug("user is {{ {} }}".format(user))
         groups = ldap.getGroup(username)
+        debug.debug("groups are {{ {} }}".format(groups))
         user_data = ldap.getUserData(username)
+        debug.debug("user data from ldap is {{ {} }}".format(user_data))
         user_data['gruppe'] = groups
         user_data['group'] = groups
         if user is None:
+            debug.debug("user not exists in database -> insert into database")
             user = User(user_data)
             db.insertUser(user)
         else:
+            debug.debug("update database with user")
             user.updateData(user_data)
             db.updateUser(user)
         user = db.getUser(username)
         self.__updateGeruechte(user)
+        debug.debug("user is {{ {} }}".format(user))
         return user
 
     def __updateGeruechte(self, user):
+        debug.debug("update creditlists")
         user.getGeruecht(datetime.now().year)
         creditLists = user.updateGeruecht()
+        debug.debug("creditlists are {{ {} }}".format(creditLists))
         if user.getGeruecht(datetime.now().year).getSchulden() != 0:
             for creditList in creditLists:
+                debug.debug("update creditlist {{ {} }}".format(creditList))
                 db.updateCreditList(creditList)
 
     def sendMail(self, username):
+        debug.info("send mail to user {{ {} }}".format(username))
         if type(username) == User:
             user = username
         if type(username) == str:
             user = db.getUser(username)
-        return emailController.sendMail(user)
+        retVal = emailController.sendMail(user)
+        debug.debug("send mail is {{ {} }}".format(retVal))
+        return retVal
 
     def sendAllMail(self):
+        debug.info("send mail to all user")
         retVal = []
         users = db.getAllUser()
+        debug.debug("users are {{ {} }}".format(users))
         for user in users:
             retVal.append(self.sendMail(user))
+        debug.debug("send mails are {{ {} }}".format(retVal))
         return retVal
 
     def modifyUser(self, user, ldap_conn, attributes):
+        debug.info("modify user {{ {} }} with attributes {{ {} }} with ldap_conn {{ {} }}".format(user, attributes, ldap_conn))
         try:
             if 'username' in attributes:
+                debug.debug("change username, so change first in database")
                 db.changeUsername(user, attributes['username'])
             ldap.modifyUser(user, ldap_conn, attributes)
             if 'username' in attributes:
-                return self.getUser(attributes['username'])
+                retVal = self.getUser(attributes['username'])
+                debug.debug("user is {{ {} }}".format(retVal))
+                return retVal
             else:
-                return self.getUser(user.uid)
+                retVal = self.getUser(user.uid)
+                debug.debug("user is {{ {} }}".format(retVal))
+                return retVal
         except UsernameExistLDAP as err:
+            debug.debug("username exists on ldap, rechange username on database", exc_info=True)
             db.changeUsername(user, user.uid)
             raise Exception(err)
         except LDAPExcetpion as err:
@@ -289,11 +454,14 @@ class UserController(metaclass=Singleton):
             raise Exception(err)
 
     def loginUser(self, username, password):
+        debug.info("login user {{ {} }}".format(username))
         try:
             user = self.getUser(username)
+            debug.debug("user is {{ {} }}".format(user))
             user.password = password
             ldap.login(username, password)
             ldap_conn = ldap.bind(user, password)
             return user, ldap_conn
         except PermissionDenied as err:
+            debug.debug("permission is denied", exc_info=True)
             raise err

geruecht/decorator.py

@@ -1,4 +1,8 @@
 from functools import wraps
+from .logger import getDebugLogger
+DEBUG = getDebugLogger()
+
+
 def login_required(**kwargs):
     import geruecht.controller.accesTokenController as ac
     from geruecht.model import BAR, USER, MONEY, GASTRO
@@ -7,15 +11,22 @@ def login_required(**kwargs):
     groups = [USER, BAR, GASTRO, MONEY]
     if "groups" in kwargs:
         groups = kwargs["groups"]
+    DEBUG.debug("groups are {{ {} }}".format(groups))
+
     def real_decorator(func):
         @wraps(func)
         def wrapper(*args, **kwargs):
             token = request.headers.get('Token')
+            DEBUG.debug("token is {{ {} }}".format(token))
             accToken = accessController.validateAccessToken(token, groups)
+            DEBUG.debug("accToken is {{ {} }}".format(accToken))
             kwargs['accToken'] = accToken
             if accToken:
+                DEBUG.debug("token {{ {} }} is valid".format(token))
                 return func(*args, **kwargs)
             else:
-                return jsonify({"error": "error", "message": "permission denied"}), 401
+                DEBUG.warning("token {{ {} }} is not valid".format(token))
+                return jsonify({"error": "error",
+                                "message": "permission denied"}), 401
         return wrapper
-    return real_decorator
+    return real_decorator

geruecht/finanzer/__init__.py

@@ -1,3 +1 @@
-from geruecht import getLogger
 
-LOGGER = getLogger(__name__)

geruecht/finanzer/routes.py

@@ -1,10 +1,12 @@
 from flask import Blueprint, request, jsonify
-from geruecht.finanzer import LOGGER
 from datetime import datetime
 import geruecht.controller.userController as uc
 from geruecht.model import MONEY
 from geruecht.decorator import login_required
-import time
+from geruecht.logger import getDebugLogger, getCreditLogger
+
+debug = getDebugLogger()
+creditL = getCreditLogger()
 
 finanzer = Blueprint("finanzer", __name__)
 
@@ -22,16 +24,20 @@ def _getFinanzer(**kwargs):
             A JSON-File with Users
             or ERROR 401 Permission Denied.
     """
-    LOGGER.debug("Get all Useres")
+    debug.info("/getFinanzerMain")
-    users = userController.getAllUsersfromDB()
+    try:
-    dic = {}
+        users = userController.getAllUsersfromDB()
-    for user in users:
+        dic = {}
-        LOGGER.debug("Add User {} to ReturnValue".format(user))
+        for user in users:
-        dic[user.uid] = user.toJSON()
+            dic[user.uid] = user.toJSON()
-        dic[user.uid]['creditList'] = {credit.year: credit.toJSON() for credit in user.geruechte}
+            dic[user.uid]['creditList'] = {
-        LOGGER.debug("ReturnValue is {}".format(dic))
+                credit.year: credit.toJSON() for credit in user.geruechte}
-    LOGGER.info("Send main for Finanzer")
+        debug.debug("return {{ {} }}".format(dic))
-    return jsonify(dic)
+        return jsonify(dic)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @finanzer.route("/finanzerAddAmount", methods=['POST'])
 @login_required(groups=[MONEY])
@@ -46,28 +52,33 @@ def _addAmount(**kwargs):
             JSON-File with geruecht of year
             or ERROR 401 Permission Denied
     """
-    data = request.get_json()
+    debug.info("/finanzerAddAmount")
-    LOGGER.debug("Get data {}".format(data))
-    userID = data['userId']
-    amount = int(data['amount'])
-    LOGGER.debug("UserID is {} and amount is {}".format(userID, amount))
     try:
-        year = int(data['year'])
+        data = request.get_json()
-    except KeyError as er:
+        userID = data['userId']
-        LOGGER.error("KeyError in year. Year is set to default.")
+        amount = int(data['amount'])
-        year = datetime.now().year
+        try:
-    try:
+            year = int(data['year'])
-        month = int(data['month'])
+        except KeyError:
-    except KeyError as er:
+            year = datetime.now().year
-        LOGGER.error("KeyError in month. Month is set to default.")
+        try:
-        month = datetime.now().month
+            month = int(data['month'])
-    LOGGER.debug("Year is {} and Month is {}".format(year, month))
+        except KeyError:
-    userController.addAmount(userID, amount, year=year, month=month, finanzer=True)
+            month = datetime.now().month
-    user = userController.getUser(userID)
+        userController.addAmount(
-    retVal = {str(geruecht.year): geruecht.toJSON() for geruecht in user.geruechte}
+            userID, amount, year=year, month=month, finanzer=True)
-    retVal['locked'] = user.locked
+        user = userController.getUser(userID)
-    LOGGER.info("Send updated Geruecht")
+        retVal = {str(geruecht.year): geruecht.toJSON()
-    return jsonify(retVal)
+                  for geruecht in user.geruechte}
+        retVal['locked'] = user.locked
+        debug.debug("return {{ {} }}".format(retVal))
+        creditL.info("{} Finanzer {} {} fügt {} {} {} € Schulden hinzu.".format(datetime(year, month, 1).date(
+        ), kwargs['accToken'].user.firstname, kwargs['accToken'].user.lastname, user.firstname, user.lastname, amount/100))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @finanzer.route("/finanzerAddCredit", methods=['POST'])
 @login_required(groups=[MONEY])
@@ -82,79 +93,114 @@ def _addCredit(**kwargs):
             JSON-File with geruecht of year
             or ERROR 401 Permission Denied
     """
-    data = request.get_json()
+    debug.info("/finanzerAddCredit")
-    print(data)
-    LOGGER.debug("Get data {}".format(data))
-    userID = data['userId']
-    credit = int(data['credit'])
-    LOGGER.debug("UserID is {} and credit is {}".format(userID, credit))
-
     try:
-        year = int(data['year'])
+        data = request.get_json()
-    except KeyError as er:
+        userID = data['userId']
-        LOGGER.error("KeyError in year. Year is set to default.")
+        credit = int(data['credit'])
-        year = datetime.now().year
-    try:
-        month = int(data['month'])
-    except KeyError as er:
-        LOGGER.error("KeyError in month. Month is set to default.")
-        month = datetime.now().month
 
-    LOGGER.debug("Year is {} and Month is {}".format(year, month))
+        try:
-    userController.addCredit(userID, credit, year=year, month=month).toJSON()
+            year = int(data['year'])
-    user = userController.getUser(userID)
+        except KeyError:
-    retVal = {str(geruecht.year): geruecht.toJSON() for geruecht in user.geruechte}
+            year = datetime.now().year
-    retVal['locked'] = user.locked
+        try:
-    LOGGER.info("Send updated Geruecht")
+            month = int(data['month'])
-    return jsonify(retVal)
+        except KeyError:
+            month = datetime.now().month
+
+        userController.addCredit(
+            userID, credit, year=year, month=month).toJSON()
+        user = userController.getUser(userID)
+        retVal = {str(geruecht.year): geruecht.toJSON()
+                  for geruecht in user.geruechte}
+        retVal['locked'] = user.locked
+        debug.debug("return {{ {} }}".format(retVal))
+        creditL.info("{} Finanzer {} {} fügt {} {} {} € Guthaben hinzu.".format(datetime(year, month, 1).date(
+        ), kwargs['accToken'].user.firstname, kwargs['accToken'].user.lastname, user.firstname, user.lastname,  credit / 100))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
 
 @finanzer.route("/finanzerLock", methods=['POST'])
 @login_required(groups=[MONEY])
 def _finanzerLock(**kwargs):
-    data = request.get_json()
+    debug.info("/finanzerLock")
-    username = data['userId']
+    try:
-    locked = bool(data['locked'])
+        data = request.get_json()
-    retVal = userController.lockUser(username, locked).toJSON()
+        username = data['userId']
-    return jsonify(retVal)
+        locked = bool(data['locked'])
+        retVal = userController.lockUser(username, locked).toJSON()
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
 
 @finanzer.route("/finanzerSetConfig", methods=['POST'])
 @login_required(groups=[MONEY])
 def _finanzerSetConfig(**kwargs):
-    data = request.get_json()
+    debug.info("/finanzerSetConfig")
-    username = data['userId']
+    try:
-    autoLock = bool(data['autoLock'])
+        data = request.get_json()
-    limit = int(data['limit'])
+        username = data['userId']
-    retVal = userController.updateConfig(username, {'lockLimit': limit, 'autoLock': autoLock}).toJSON()
+        autoLock = bool(data['autoLock'])
-    return jsonify(retVal)
+        limit = int(data['limit'])
+        retVal = userController.updateConfig(
+            username, {'lockLimit': limit, 'autoLock': autoLock}).toJSON()
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @finanzer.route("/finanzerAddUser", methods=['POST'])
 @login_required(groups=[MONEY])
 def _finanzerAddUser(**kwargs):
-    data = request.get_json()
+    debug.info("/finanzerAddUser")
-    username = data['userId']
+    try:
-    userController.getUser(username)
+        data = request.get_json()
-    LOGGER.debug("Get all Useres")
+        username = data['userId']
-    users = userController.getAllUsersfromDB()
+        userController.getUser(username)
-    dic = {}
+        users = userController.getAllUsersfromDB()
-    for user in users:
+        dic = {}
-        LOGGER.debug("Add User {} to ReturnValue".format(user))
+        for user in users:
-        dic[user.uid] = user.toJSON()
+            dic[user.uid] = user.toJSON()
-        dic[user.uid]['creditList'] = {credit.year: credit.toJSON() for credit in user.geruechte}
+            dic[user.uid]['creditList'] = {
-        LOGGER.debug("ReturnValue is {}".format(dic))
+                credit.year: credit.toJSON() for credit in user.geruechte}
-    return jsonify(dic), 200
+        debug.debug("return {{ {} }}".format(dic))
+        return jsonify(dic), 200
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @finanzer.route("/finanzerSendOneMail", methods=['POST'])
 @login_required(groups=[MONEY])
 def _finanzerSendOneMail(**kwargs):
-    data = request.get_json()
+    debug.info("/finanzerSendOneMail")
-    username = data['userId']
+    try:
-    retVal = userController.sendMail(username)
+        data = request.get_json()
-    return jsonify(retVal)
+        username = data['userId']
+        retVal = userController.sendMail(username)
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @finanzer.route("/finanzerSendAllMail", methods=['GET'])
 @login_required(groups=[MONEY])
 def _finanzerSendAllMail(**kwargs):
-    retVal = userController.sendAllMail()
+    debug.info("/finanzerSendAllMail")
-    return jsonify(retVal)
+    try:
+        retVal = userController.sendAllMail()
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500

geruecht/gastro/routes.py

@@ -2,70 +2,96 @@ from flask import request, jsonify, Blueprint
 from geruecht.decorator import login_required
 import geruecht.controller.userController as uc
 from geruecht.model import GASTRO
+from geruecht.logger import getCreditLogger, getDebugLogger
+
+debug = getDebugLogger()
 
 gastrouser = Blueprint('gastrouser', __name__)
 
 userController = uc.UserController()
 
+
 @gastrouser.route('/gastro/setDrink', methods=['POST'])
 @login_required(groups=[GASTRO])
 def setDrink(**kwargs):
+    debug.info("/gastro/setDrink")
     try:
         data = request.get_json()
         retVal = userController.setDrinkPrice(data)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @gastrouser.route('/gastro/updateDrink', methods=['POST'])
 @login_required(groups=[GASTRO])
 def updateDrink(**kwargs):
+    debug.info("/gastro/updateDrink")
     try:
         data = request.get_json()
         retVal = userController.updateDrinkPrice(data)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @gastrouser.route('/gastro/deleteDrink', methods=['POST'])
 @login_required(groups=[GASTRO])
 def deleteDrink(**kwargs):
+    debug.info("/gastro/dleteDrink")
     try:
         data = request.get_json()
         id = data['id']
-        retVal = userController.deletDrinkPrice({"id": id})
+        userController.deletDrinkPrice({"id": id})
+        debug.debug("return ok")
         return jsonify({"ok": "ok"})
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @gastrouser.route('/gastro/setDrinkType', methods=['POST'])
 @login_required(groups=[GASTRO])
 def setType(**kwark):
+    debug.info("/gastro/setDrinkType")
     try:
         data = request.get_json()
         name = data['name']
         retVal = userController.setDrinkType(name)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @gastrouser.route('/gastro/updateDrinkType', methods=['POST'])
 @login_required(groups=[GASTRO])
 def updateType(**kwargs):
+    debug.info("/gastro/updateDrinkType")
     try:
         data = request.get_json()
         retVal = userController.updateDrinkType(data)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @gastrouser.route('/gastro/deleteDrinkType', methods=['POST'])
 @login_required(groups=[GASTRO])
 def deleteType(**kwargs):
+    debug.info("/gastro/deleteDrinkType")
     try:
         data = request.get_json()
         userController.deleteDrinkType(data)
+        debug.debug("return ok")
         return jsonify({"ok": "ok"})
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
-

geruecht/logger.py

@@ -1,21 +1,27 @@
 import logging
-from logging.handlers import WatchedFileHandler
+import logging.config
-import sys
+import yaml
+from os import path
 
-FORMATTER = logging.Formatter("%(asctime)s — %(name)s — %(levelname)s — %(message)s")
+if not path.exists("geruecht/log/debug"):
+    a = path.join(path.curdir, "geruecht", "log", "debug")
 
-logFileHandler = WatchedFileHandler("testlog.log")
+if not path.exists("geruecht/log/info"):
-logFileHandler.setFormatter(FORMATTER)
+    b = path.join(path.curdir, "geruecht", "log", "info")
 
-logStreamHandler = logging.StreamHandler(stream=sys.stdout)
-logStreamHandler.setFormatter(FORMATTER)
 
-def getLogger(logger_name):
+with open("geruecht/logging.yml", 'rt') as file:
-    logger = logging.getLogger(logger_name)
+    config = yaml.safe_load(file.read())
-    logger.setLevel(logging.DEBUG)
+logging.config.dictConfig(config)
-    logger.addHandler(logFileHandler)
-    logger.addHandler(logStreamHandler)
 
-    logger.propagate = False
 
-    return logger
+def getDebugLogger():
+    return logging.getLogger("debug_logger")
+
+
+def getCreditLogger():
+    return logging.getLogger("credit_logger")
+
+
+def getJobsLogger():
+    return logging.getLogger("jobs_logger")

geruecht/logging.yml

@@ -0,0 +1,57 @@
+version: 1
+disable_existing_loggers: True
+
+formatters:
+  debug:
+    format: "%(asctime)s — %(filename)s - %(funcName)s - %(lineno)d - %(threadName)s - %(name)s — %(levelname)s — %(message)s"
+
+  simple:
+    format: "%(asctime)s - %(name)s - %(message)s"
+
+handlers:
+  console:
+    class: logging.StreamHandler
+    level: DEBUG
+    formatter: debug
+    stream: ext://sys.stdout
+
+  debug:
+    class: logging.handlers.WatchedFileHandler
+    level: DEBUG
+    formatter: debug
+    filename: geruecht/log/debug/debug.log
+    encoding: utf8
+
+  credit:
+    class: logging.handlers.WatchedFileHandler
+    level: INFO
+    formatter: simple
+    filename: geruecht/log/info/geruecht.log
+    encoding: utf8
+
+  jobs:
+    class: logging.handlers.WatchedFileHandler
+    level: INFO
+    formatter: simple
+    filename: geruecht/log/info/jobs.log
+    encoding: utf8
+
+loggers:
+  debug_logger:
+    level: DEBUG
+    handlers: [console, debug]
+    propagate: no
+
+  credit_logger:
+    level: INFO
+    handlers: [credit]
+    propagate: no
+
+  jobs_logger:
+    level: INFO
+    handlers: [jobs]
+    propagate: no
+
+root:
+  level: INFO
+  handlers: [console, debug]

geruecht/model/accessToken.py

@@ -1,7 +1,7 @@
 from datetime import datetime
-from geruecht import getLogger
+from geruecht.logger import getDebugLogger
 
-LOGGER = getLogger(__name__)
+debug = getDebugLogger()
 
 class AccessToken():
     """ Model for an AccessToken
@@ -27,19 +27,20 @@ class AccessToken():
                 token: Is a String to verify later
                 timestamp: Default current time, but can set to an other datetime-Object.
         """
-        LOGGER.debug("Initialize AccessToken")
+        debug.debug("init accesstoken")
         self.user = user
         self.timestamp = timestamp
         self.lifetime = lifetime
         self.token = token
         self.ldap_conn = ldap_conn
+        debug.debug("accesstoken is {{ {} }}".format(self))
 
     def updateTimestamp(self):
         """ Update the Timestamp
 
             Update the Timestamp to the current Time.
         """
-        LOGGER.debug("Update Timestamp")
+        debug.debug("update timestamp from accesstoken {{ {} }}".format(self))
         self.timestamp = datetime.now()
 
     def __eq__(self, token):
@@ -49,7 +50,7 @@ class AccessToken():
         return other - self.timestamp
 
     def __str__(self):
-        return "AccessToken({}, {}, {}".format(self.user, self.token, self.timestamp)
+        return "AccessToken(user={}, token={}, timestamp={}, lifetime={}".format(self.user, self.token, self.timestamp, self.lifetime)
 
     def __repr__(self):
-        return "AccessToken({}, {}, {}".format(self.user, self.token, self.timestamp)
+        return "AccessToken(user={}, token={}, timestamp={}, lifetime={}".format(self.user, self.token, self.timestamp, self.lifetime)

geruecht/model/creditList.py

@@ -1,7 +1,8 @@
 from datetime import datetime
-from geruecht import getLogger
+from geruecht.logger import getDebugLogger
+
+debug = getDebugLogger()
 
-LOGGER = getLogger(__name__)
 def create_empty_data():
     empty_data = {'id': 0,
             'jan_guthaben': 0,
@@ -46,7 +47,7 @@ class CreditList():
             user_id:    id from the User.
     """
     def __init__(self, data):
-        LOGGER.debug("Initialize Geruecht")
+        debug.debug("init creditlist")
         self.id = int(data['id'])
 
         self.jan_guthaben = int(data['jan_guthaben'])
@@ -91,6 +92,8 @@ class CreditList():
 
         self.user_id = int(data['user_id'])
 
+        debug.debug("credit list is {{ {} }}".format(self))
+
     def getSchulden(self):
         """ Get Schulden
 
@@ -104,7 +107,7 @@ class CreditList():
             Returns:
                 double of the calculated amount
         """
-        LOGGER.debug("Calculate amount")
+        debug.info("calculate amount")
         jan = self.jan_guthaben - self.jan_schulden
         feb = self.feb_guthaben - self.feb_schulden
         maer = self.maer_guthaben - self.maer_schulden
@@ -119,7 +122,7 @@ class CreditList():
         dez = self.dez_guthaben - self.dez_schulden
 
         sum = jan + feb + maer + apr + mai + jun + jul + aug + sep + okt + nov + dez - self.last_schulden
-        LOGGER.debug("Calculated amount is {}".format(sum))
+        debug.debug("amount is {{ {} }}".format(sum))
         return sum
 
     def getMonth(self, month=datetime.now().month):
@@ -134,7 +137,7 @@ class CreditList():
             Returns:
                 double (credit, amount)
         """
-        LOGGER.debug("Get Credit and Amount from Month {}".format(month))
+        debug.info("get credit and amount from month {{ {} }}".format(month))
         retValue = None
 
         if month == 1:
@@ -161,7 +164,7 @@ class CreditList():
             retValue = (self.nov_guthaben, self.nov_schulden)
         elif month == 12:
             retValue = (self.dez_guthaben, self.dez_schulden)
-        LOGGER.debug("Credit and Amount is {}".format(retValue))
+        debug.debug("credit and amount is {{ {} }}".format(retValue))
         return retValue
 
     def addAmount(self, amount, month=datetime.now().month):
@@ -177,7 +180,7 @@ class CreditList():
             Returns:
                 double (credit, amount)
         """
-        LOGGER.debug("Add Amount in Month {}".format(month))
+        debug.info("add amount in month {{ {} }}".format(month))
         if month == 1:
             self.jan_schulden += amount
             retValue = (self.jan_guthaben, self.jan_schulden)
@@ -214,7 +217,7 @@ class CreditList():
         elif month == 12:
             self.dez_schulden += amount
             retValue = (self.dez_guthaben, self.dez_schulden)
-        LOGGER.debug("Credit and Amount is {}".format(retValue))
+        debug.debug("credit and amount is {{ {} }}".format(retValue))
         return retValue
 
     def addCredit(self, credit, month=datetime.now().month):
@@ -230,7 +233,7 @@ class CreditList():
             Returns:
                 double (credit, amount)
         """
-        LOGGER.debug("Add Credit in Month {}".format(month))
+        debug.info("add credit in month {{ {} }}".format(month))
         if month == 1:
             self.jan_guthaben += credit
             retValue = (self.jan_guthaben, self.jan_schulden)
@@ -267,7 +270,7 @@ class CreditList():
         elif month == 12:
             self.dez_guthaben += credit
             retValue = (self.dez_guthaben, self.dez_schulden)
-        LOGGER.debug("Credit and Amount is {}".format(retValue))
+        debug.debug("credit and amount is {{ {} }}".format(retValue))
         return retValue
 
     def toJSON(self):

geruecht/model/user.py

@@ -1,8 +1,8 @@
-from geruecht.logger import getLogger
+from geruecht.logger import getDebugLogger
 from geruecht.model.creditList import CreditList, create_empty_data
 from datetime import datetime
 
-LOGGER = getLogger(__name__)
+debug = getDebugLogger()
 
 
 class User():
@@ -20,6 +20,7 @@ class User():
             password: salted hashed password for the User.
     """
     def __init__(self, data):
+        debug.info("init user")
         if 'id' in data:
             self.id = int(data['id'])
         self.uid = data['uid']
@@ -58,8 +59,10 @@ class User():
         if 'creditLists' in data:
             self.geruechte = data['creditLists']
         self.password = ''
+        debug.debug("user is {{ {} }}".format(self))
 
     def updateData(self, data):
+        debug.info("update data of user")
         if 'dn' in data:
             self.dn = data['dn']
         if 'firstname' in data:
@@ -98,14 +101,14 @@ class User():
             Returns:
                 the created geruecht
         """
-        LOGGER.debug("Create Geruecht for user {} in year {}".format(self, year))
+        debug.info("create creditlist for user {{ {} }} in year {{ {} }}".format(self, year))
         data = create_empty_data()
         data['user_id'] = self.id
         data['last_schulden'] = amount
         data['year_date'] = year
         credit = CreditList(data)
         self.geruechte.append(credit)
-        LOGGER.debug("Created Geruecht {}".format(credit))
+        debug.debug("creditlist is {{ {} }}".format(credit))
         return credit
 
     def getGeruecht(self, year=datetime.now().year):
@@ -120,13 +123,12 @@ class User():
             Returns:
                 the geruecht of the year
         """
-        LOGGER.debug("Iterate through Geruechte of User {}".format(self))
+        debug.info("get creditlist from user on year {{ {} }}".format(year))
         for geruecht in self.geruechte:
-            LOGGER.debug("Check if Geruecht {} has year {}".format(geruecht, year))
             if geruecht.year == year:
-                LOGGER.debug("Find Geruecht {} for User {}".format(geruecht, self))
+                debug.debug("creditlist is {{ {} }} for user {{ {} }}".format(geruecht, self))
                 return geruecht
-        LOGGER.debug("No Geruecht found for User {}. Will create one".format(self))
+        debug.debug("no creditlist found for user {{ {} }}".format(self))
         geruecht = self.createGeruecht(year=year)
 
         return self.getGeruecht(year=year)
@@ -145,7 +147,7 @@ class User():
             Returns:
                 double (credit, amount)
         """
-        LOGGER.debug("Add amount to User {} in year {} and month {}".format(self, year, month))
+        debug.info("add amount to user {{ {} }} in year {{ {} }} and month {{ {} }}".format(self, year, month))
         geruecht = self.getGeruecht(year=year)
         retVal = geruecht.addAmount(amount, month=month)
 
@@ -165,7 +167,7 @@ class User():
             Returns:
                 double (credit, amount)
         """
-        LOGGER.debug("Add credit to User {} in year {} and month {}".format(self, year, month))
+        debug.info("add credit to user {{ {} }} in year {{ {} }} and month {{ {} }}".format(self, year, month))
         geruecht = self.getGeruecht(year=year)
         retVal = geruecht.addCredit(credit, month=month)
 
@@ -176,7 +178,7 @@ class User():
 
             This function iterate through the geruechte, which sorted by year and update the last_schulden of the geruecht.
         """
-        LOGGER.debug("Update all Geruechte ")
+        debug.info("update all creditlists ")
         self.geruechte.sort(key=self.sortYear)
 
         for index, geruecht in enumerate(self.geruechte):

geruecht/routes.py

@@ -1,4 +1,5 @@
-from geruecht import app, LOGGER
+from geruecht import app
+from geruecht.logger import getDebugLogger
 from geruecht.decorator import login_required
 from geruecht.exceptions import PermissionDenied
 import geruecht.controller.accesTokenController as ac
@@ -9,111 +10,139 @@ from flask import request, jsonify
 accesTokenController = ac.AccesTokenController()
 userController = uc.UserController()
 
-def login(user, password):
+debug = getDebugLogger()
-    return user.login(password)
 
 
-@app.route("/valid")
-def _valid():
-    token = request.headers.get("Token")
-    accToken = accesTokenController.validateAccessToken(token, [MONEY])
-    if accToken:
-        return jsonify(accToken.user.toJSON())
-    accToken = accesTokenController.validateAccessToken(token, [BAR])
-    if accToken:
-        return jsonify(accToken.user.toJSON())
-    accToken = accesTokenController.validateAccessToken(token, [GASTRO])
-    if accToken:
-        return jsonify(accToken.user.toJSON())
-    accToken = accesTokenController.validateAccessToken(token, [USER])
-    if accToken:
-        return jsonify(accToken.user.toJSON())
-    return jsonify({"error": "permission denied"}), 401
-
 @app.route("/pricelist", methods=['GET'])
 def _getPricelist():
     try:
+        debug.info("get pricelist")
         retVal = userController.getPricelist()
-        print(retVal)
+        debug.info("return pricelist {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
-        return jsonify({"error": str(err)})
+        debug.warning("exception in get pricelist.", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @app.route('/drinkTypes', methods=['GET'])
 def getTypes():
     try:
+        debug.info("get drinktypes")
         retVal = userController.getAllDrinkTypes()
+        debug.info("return drinktypes {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.warning("exception in get drinktypes.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route('/getAllStatus', methods=['GET'])
 @login_required(groups=[USER, MONEY, GASTRO, BAR, VORSTAND])
 def _getAllStatus(**kwargs):
     try:
+        debug.info("get all status for users")
         retVal = userController.getAllStatus()
+        debug.info("return all status for users {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.warning("exception in get all status for users.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route('/getStatus', methods=['POST'])
 @login_required(groups=[USER, MONEY, GASTRO, BAR, VORSTAND])
 def _getStatus(**kwargs):
     try:
+        debug.info("get status from user")
         data = request.get_json()
         name = data['name']
+        debug.info("get status from user {{ {} }}".format(name))
         retVal = userController.getStatus(name)
+        debug.info(
+            "return status from user {{ {} }} : {{ {} }}".format(name, retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.warning("exception in get status from user.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route('/getUsers', methods=['GET'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _getUsers(**kwargs):
     try:
+        debug.info("get all users from database")
         users = userController.getAllUsersfromDB()
+        debug.debug("users are {{ {} }}".format(users))
         retVal = [user.toJSON() for user in users]
+        debug.info("return all users from database {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.warning(
+            "exception in get all users from database.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route("/getLifeTime", methods=['GET'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND, EXTERN, USER])
 def _getLifeTime(**kwargs):
     try:
+        debug.info("get lifetime of accesstoken")
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
-            return jsonify({"value": accToken.lifetime})
+            debug.debug("accessToken is {{ {} }}".format(accToken))
+            retVal = {"value": accToken.lifetime}
+            debug.info(
+                "return get lifetime from accesstoken {{ {} }}".format(retVal))
+            return jsonify(retVal)
     except Exception as err:
+        debug.info("exception in get lifetime of accesstoken.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route("/saveLifeTime", methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND, EXTERN, USER])
 def _saveLifeTime(**kwargs):
     try:
+        debug.info("save lifetime for accessToken")
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
-
+            debug.debug("accessToken is {{ {} }}".format(accToken))
             data = request.get_json()
             lifetime = data['value']
+            debug.debug("lifetime is {{ {} }}".format(lifetime))
+            debug.info("set lifetime {{ {} }} to accesstoken {{ {} }}".format(
+                lifetime, accToken))
             accToken.lifetime = lifetime
+            debug.info("update accesstoken timestamp")
             accToken.updateTimestamp()
-
+            retVal = {"value": accToken.lifetime}
-            return jsonify({"value": accToken.lifetime})
+            debug.info(
+                "return save lifetime for accessToken {{ {} }}".format(retVal))
+            return jsonify(retVal)
     except Exception as err:
+        debug.warning(
+            "exception in save lifetime for accesstoken.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route("/logout", methods=['GET'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND, EXTERN, USER])
 def _logout(**kwargs):
     try:
+        debug.info("logout user")
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
+            debug.debug("accesstoken is {{ {} }}".format(accToken))
+            debug.info("delete accesstoken")
             accesTokenController.deleteAccessToken(accToken)
+            debug.info("return ok logout user")
             return jsonify({"ok": "ok"})
     except Exception as err:
+        debug.warning("exception in logout user.", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @app.route("/login", methods=['POST'])
 def _login():
     """ Login User
@@ -124,25 +153,29 @@ def _login():
         Returns:
             A JSON-File with createt Token or Errors
     """
-    LOGGER.info("Start log in.")
+    debug.info("Start log in.")
     data = request.get_json()
-    print(data)
-    LOGGER.debug("JSON from request: {}".format(data))
     username = data['username']
     password = data['password']
-    LOGGER.info("search {} in database".format(username))
+    debug.debug("username is {{ {} }}".format(username))
     try:
+        debug.info("search {{ {} }} in database".format(username))
         user, ldap_conn = userController.loginUser(username, password)
+        debug.debug("user is {{ {} }}".format(user))
         user.password = password
         token = accesTokenController.createAccesToken(user, ldap_conn)
-        dic = accesTokenController.validateAccessToken(token, [USER, EXTERN]).user.toJSON()
+        debug.debug("accesstoken is {{ {} }}".format(token))
+        debug.info("validate accesstoken")
+        dic = accesTokenController.validateAccessToken(
+            token, [USER, EXTERN]).user.toJSON()
         dic["token"] = token
         dic["accessToken"] = token
-        LOGGER.info("User {} success login.".format(username))
+        debug.info("User {{ {} }} success login.".format(username))
+        debug.info("return login {{ {} }}".format(dic))
         return jsonify(dic)
     except PermissionDenied as err:
+        debug.warning("permission denied exception in logout", exc_info=True)
         return jsonify({"error": str(err)}), 401
-    except Exception as err:
+    except Exception:
+        debug.warning("exception in logout.", exc_info=True)
         return jsonify({"error": "permission denied"}), 401
-    LOGGER.info("User {} does not exist.".format(username))
-    return jsonify({"error": "wrong username"}), 401

geruecht/user/routes.py

@@ -4,41 +4,57 @@ import geruecht.controller.userController as uc
 from geruecht.model import USER
 from datetime import datetime
 from geruecht.exceptions import DayLocked
+from geruecht.logger import getDebugLogger, getCreditLogger, getJobsLogger
 
 user = Blueprint("user", __name__)
 
 userController = uc.UserController()
 
+debug = getDebugLogger()
+creditL = getCreditLogger()
+jobL = getJobsLogger()
 
 @user.route("/user/main")
 @login_required(groups=[USER])
 def _main(**kwargs):
-    if 'accToken' in kwargs:
+    debug.info("/user/main")
-        accToken = kwargs['accToken']
+    try:
-        accToken.user = userController.getUser(accToken.user.uid)
+        if 'accToken' in kwargs:
-        retVal = accToken.user.toJSON()
+            accToken = kwargs['accToken']
-        retVal['creditList'] = {credit.year: credit.toJSON() for credit in accToken.user.geruechte}
+            accToken.user = userController.getUser(accToken.user.uid)
-        return jsonify(retVal)
+            retVal = accToken.user.toJSON()
-    return jsonify("error", "something went wrong"), 500
+            retVal['creditList'] = {credit.year: credit.toJSON() for credit in accToken.user.geruechte}
+            debug.debug("return {{ {} }}".format(retVal))
+            return jsonify(retVal)
+    except Exception:
+        debug.debug("exception", exc_info=True)
+        return jsonify("error", "something went wrong"), 500
 
 @user.route("/user/addAmount", methods=['POST'])
 @login_required(groups=[USER])
 def _addAmount(**kwargs):
-    if 'accToken' in kwargs:
+    debug.info("/user/addAmount")
-        accToken = kwargs['accToken']
+    try:
-        data = request.get_json()
+        if 'accToken' in kwargs:
-        amount = int(data['amount'])
+            accToken = kwargs['accToken']
-        date = datetime.now()
+            data = request.get_json()
-        userController.addAmount(accToken.user.uid, amount, year=date.year, month=date.month)
+            amount = int(data['amount'])
-        accToken.user = userController.getUser(accToken.user.uid)
+            date = datetime.now()
-        retVal = accToken.user.toJSON()
+            userController.addAmount(accToken.user.uid, amount, year=date.year, month=date.month)
-        retVal['creditList'] = {credit.year: credit.toJSON() for credit in accToken.user.geruechte}
+            accToken.user = userController.getUser(accToken.user.uid)
-        return jsonify(retVal)
+            retVal = accToken.user.toJSON()
-    return jsonify({"error": "something went wrong"}), 500
+            retVal['creditList'] = {credit.year: credit.toJSON() for credit in accToken.user.geruechte}
+            debug.debug("return {{ {} }}".format(retVal))
+            creditL.info("{} {} {} fügt sich selbst {} € Schulden hinzu".format(date, accToken.user.firstname, accToken.user.lastname, amount/100))
+            return jsonify(retVal)
+    except Exception:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": "something went wrong"}), 500
 
 @user.route("/user/saveConfig", methods=['POST'])
 @login_required(groups=[USER])
 def _saveConfig(**kwargs):
+    debug.info("/user/saveConfig")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -46,47 +62,55 @@ def _saveConfig(**kwargs):
             accToken.user = userController.modifyUser(accToken.user, accToken.ldap_conn, data)
             retVal = accToken.user.toJSON()
             retVal['creditList'] = {credit.year: credit.toJSON() for credit in accToken.user.geruechte}
+            debug.debug("return {{ {} }}".format(retVal))
             return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/job", methods=['POST'])
 @login_required(groups=[USER])
 def _getUser(**kwargs):
-    data = request.get_json()
+    debug.info("/user/job")
-    day = data['day']
+    try:
-    month = data['month']
+        data = request.get_json()
-    year = data['year']
+        day = data['day']
-    date = datetime(year, month, day, 12)
+        month = data['month']
-    lockedDay = userController.getLockedDay(date)
+        year = data['year']
-    if not lockedDay:
+        date = datetime(year, month, day, 12)
-        lockedDay = {
+        lockedDay = userController.getLockedDay(date)
-            'date': {
+        if not lockedDay:
-                'year': year,
+            lockedDay = {
-                'month': month,
+                'date': {
-                'day': day
+                    'year': year,
-            },
+                    'month': month,
-            'locked': False
+                    'day': day
+                },
+                'locked': False
+            }
+        else:
+            lockedDay = {
+                'date': {
+                    'year': year,
+                    'month': month,
+                    'day': day
+                },
+                'locked': lockedDay['locked']
+            }
+        retVal = {
+            'worker': userController.getWorker(date),
+            'day': lockedDay
         }
-    else:
+        debug.debug("retrun {{ {} }}".format(retVal))
-        lockedDay = {
+        return jsonify(retVal)
-            'date': {
+    except Exception as err:
-                'year': year,
+        debug.debug("exception", exc_info=True)
-                'month': month,
+        return jsonify({"error": str(err)}), 500
-                'day': day
-            },
-            'locked': lockedDay['locked']
-        }
-    retVal = {
-        'worker': userController.getWorker(date),
-        'day': lockedDay
-    }
-    print(retVal)
-    return jsonify(retVal)
 
 @user.route("/user/addJob", methods=['POST'])
 @login_required(groups=[USER])
 def _addUser(**kwargs):
+    debug.info("/user/addJob")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -97,16 +121,20 @@ def _addUser(**kwargs):
             year = data['year']
             date = datetime(year,month,day,12)
             retVal = userController.addWorker(user.uid, date, userExc=True)
-            print(retVal)
+            debug.debug("return {{ {} }}".format(retVal))
+            jobL.info("Mitglied {} {} schreib sich am {} zum Dienst ein.".format(user.firstname, user.lastname, date.date()))
             return jsonify(retVal)
     except DayLocked as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({'error': str(err)}), 403
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({'error': str(err)}), 409
 
 @user.route("/user/deleteJob", methods=['POST'])
 @login_required(groups=[USER])
 def _deletJob(**kwargs):
+    debug.info("/user/deleteJob")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -117,15 +145,20 @@ def _deletJob(**kwargs):
             year = data['year']
             date = datetime(year,month,day,12)
             userController.deleteWorker(user.uid, date, True)
+            debug.debug("return ok")
+            jobL.info("Mitglied {} {} entfernt sich am {} aus dem Dienst".format(user.firstname, user.lastname, date.date()))
             return jsonify({"ok": "ok"})
     except DayLocked as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 403
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/transactJob", methods=['POST'])
 @login_required(groups=[USER])
 def _transactJob(**kwargs):
+    debug.info("/user/transactJob")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -138,17 +171,22 @@ def _transactJob(**kwargs):
             date = datetime(year, month, day, 12)
             to_user = userController.getUser(username)
             retVal = userController.setTransactJob(user, to_user, date)
+            from_userl = retVal['from_user']
+            to_userl = retVal['to_user']
             retVal['from_user'] = retVal['from_user'].toJSON()
             retVal['to_user'] = retVal['to_user'].toJSON()
             retVal['date'] = {'year': year, 'month': month, 'day': day}
-            print(retVal)
+            debug.debug("return {{ {} }}".format(retVal))
+            jobL.info("Mitglied {} {} sendet Dienstanfrage an Mitglied {} {} am {}".format(from_userl.firstname, from_userl.lastname, to_userl.firstname, to_userl.lastname, date.date()))
             return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/answerTransactJob", methods=['POST'])
 @login_required(groups=[USER])
 def _answer(**kwargs):
+    debug.info("/user/answerTransactJob")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -162,17 +200,22 @@ def _answer(**kwargs):
             date = datetime(year, month, day, 12)
             from_user = userController.getUser(username)
             retVal = userController.answerdTransactJob(from_user, user, date, answer)
+            from_userl = retVal['from_user']
+            to_userl = retVal['to_user']
             retVal['from_user'] = retVal['from_user'].toJSON()
             retVal['to_user'] = retVal['to_user'].toJSON()
             retVal['date'] = {'year': year, 'month': month, 'day': day}
-            print(retVal)
+            debug.debug("return {{ {} }}".format(retVal))
+            jobL.info("Mitglied {} {} beantwortet Dienstanfrage von {} {} am {} mit {}".format(to_userl.firstname, to_userl.lastname, from_userl.firstname, from_userl.lastname, date.date(), 'JA' if answer else 'NEIN'))
             return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/jobRequests", methods=['POST'])
 @login_required(groups=[USER])
 def _requests(**kwargs):
+    debug.info("/user/jobRequests")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -188,14 +231,16 @@ def _requests(**kwargs):
                 data['to_user'] = data['to_user'].toJSON()
                 data_date = data['date']
                 data['date'] = {'year': data_date.year, 'month': data_date.month, 'day': data_date.day}
-            print(retVal)
+            debug.debug("return {{ {} }}".format(retVal))
             return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/getTransactJobs", methods=['POST'])
 @login_required(groups=[USER])
 def _getTransactJobs(**kwargs):
+    debug.info("/user/getTransactJobs")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -211,14 +256,16 @@ def _getTransactJobs(**kwargs):
                 data['to_user'] = data['to_user'].toJSON()
                 data_date = data['date']
                 data['date'] = {'year': data_date.year, 'month': data_date.month, 'day': data_date.day}
-            print(retVal)
+            debug.debug("return {{ {} }}".format(retVal))
             return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/deleteTransactJob", methods=['POST'])
 @login_required(groups=[USER])
 def _deleteTransactJob(**kwargs):
+    debug.info("/user/deleteTransactJob")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -231,8 +278,11 @@ def _deleteTransactJob(**kwargs):
             date = datetime(year, month, day, 12)
             to_user = userController.getUser(username)
             userController.deleteTransactJob(from_user, to_user, date)
+            debug.debug("return ok")
+            jobL.info("Mitglied {} {} entfernt Dienstanfrage an {} {} am {}".format(from_user.firstname, from_user.lastname, to_user.firstname, to_user.lastname, date.date()))
             return jsonify({"ok": "ok"})
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
 @user.route("/user/storno", methods=['POST'])
@@ -246,6 +296,8 @@ def _storno(**kwargs):
                 JSON-File with userID and the amount
                 or ERROR 401 Permission Denied
         """
+
+    debug.info("/user/storno")
     try:
         if 'accToken' in kwargs:
             accToken = kwargs['accToken']
@@ -258,6 +310,9 @@ def _storno(**kwargs):
             accToken.user = userController.getUser(accToken.user.uid)
             retVal = accToken.user.toJSON()
             retVal['creditList'] = {credit.year: credit.toJSON() for credit in accToken.user.geruechte}
+            debug.debug("return {{ {} }}".format(retVal))
+            creditL.info("{} {} {} storniert {} €".format(date, user.firstname, user.lastname, amount/100))
             return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409

geruecht/vorstand/routes.py

@@ -4,133 +4,179 @@ import geruecht.controller.userController as uc
 import geruecht.controller.ldapController as lc
 from geruecht.decorator import login_required
 from geruecht.model import MONEY, GASTRO, VORSTAND
-import time
+from geruecht.logger import getDebugLogger, getJobsLogger
+
+debug = getDebugLogger()
+jobL = getJobsLogger()
 
 vorstand = Blueprint("vorstand", __name__)
 userController = uc.UserController()
-ldap= lc.LDAPController()
+ldap = lc.LDAPController()
+
 
 @vorstand.route('/um/setStatus', methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _setStatus(**kwargs):
+    debug.info("/um/setStatus")
     try:
         data = request.get_json()
         name = data['name']
         retVal = userController.setStatus(name)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @vorstand.route('/um/updateStatus', methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _updateStatus(**kwargs):
+    debug.info("/um/updateStatus")
     try:
         data = request.get_json()
         retVal = userController.updateStatus(data)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @vorstand.route('/um/deleteStatus', methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _deleteStatus(**kwargs):
+    debug.info("/um/deleteStatus")
     try:
         data = request.get_json()
         userController.deleteStatus(data)
+        debug.debug("return ok")
         return jsonify({"ok": "ok"})
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 409
 
+
 @vorstand.route('/um/updateStatusUser', methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _updateStatusUser(**kwargs):
+    debug.info("/um/updateStatusUser")
     try:
         data = request.get_json()
         username = data['username']
         status = data['status']
         retVal = userController.updateStatusOfUser(username, status).toJSON()
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @vorstand.route('/um/updateVoting', methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _updateVoting(**kwargs):
+    debug.info("/um/updateVoting")
     try:
         data = request.get_json()
         username = data['username']
         voting = data['voting']
         retVal = userController.updateVotingOfUser(username, voting).toJSON()
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({"error": str(err)}), 500
 
+
 @vorstand.route("/sm/addUser", methods=['POST', 'GET'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _addUser(**kwargs):
+    debug.info("/sm/addUser")
+    try:
+        data = request.get_json()
+        user = data['user']
+        day = data['day']
+        month = data['month']
+        year = data['year']
+        date = datetime(year, month, day, 12)
+        retVal = userController.addWorker(user['username'], date)
+        debug.debug("retrun {{ {} }}".format(retVal))
+        userl = userController.getUser(user['username'])
+        jobL.info("Vorstand {} {} schreibt Mitglied {} {} am {} zum Dienst ein".format(
+            kwargs['accToken'].user.firstname, kwargs['accToken'].user.lastname, userl.firstname, userl.lastname, date.date()))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
 
-    if request.method == 'GET':
-        return "<h1>HEllo World</h1>"
-
-    data = request.get_json()
-    user = data['user']
-    day = data['day']
-    month = data['month']
-    year = data['year']
-    date = datetime(year,month,day,12)
-    retVal = userController.addWorker(user['username'], date)
-    print(retVal)
-    return jsonify(retVal)
 
 @vorstand.route("/sm/getUser", methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _getUser(**kwargs):
-    data = request.get_json()
+    debug.info("/sm/getUser")
-    day = data['day']
+    try:
-    month = data['month']
+        data = request.get_json()
-    year = data['year']
+        day = data['day']
-    date = datetime(year, month, day, 12)
+        month = data['month']
-    lockedDay = userController.getLockedDay(date)
+        year = data['year']
-    if not lockedDay:
+        date = datetime(year, month, day, 12)
-        lockedDay = {
+        lockedDay = userController.getLockedDay(date)
-            'date': {
+        if not lockedDay:
-                'year': year,
+            lockedDay = {
-                'month': month,
+                'date': {
-                'day': day
+                    'year': year,
-            },
+                    'month': month,
-            'locked': False
+                    'day': day
+                },
+                'locked': False
+            }
+        else:
+            lockedDay = {
+                'date': {
+                    'year': year,
+                    'month': month,
+                    'day': day
+                },
+                'locked': lockedDay['locked']
+            }
+        retVal = {
+            'worker': userController.getWorker(date),
+            'day': lockedDay
         }
-    else:
+        debug.debug("return {{ {} }}".format(retVal))
-        lockedDay = {
+        return jsonify(retVal)
-            'date': {
+    except Exception as err:
-                'year': year,
+        debug.debug("exception", exc_info=True)
-                'month': month,
+        return jsonify({"error": str(err)}), 500
-                'day': day
+
-            },
-            'locked': lockedDay['locked']
-        }
-    retVal = {
-        'worker': userController.getWorker(date),
-        'day': lockedDay
-    }
-    print(retVal)
-    return  jsonify(retVal)
 
 @vorstand.route("/sm/deleteUser", methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _deletUser(**kwargs):
-    data = request.get_json()
+    debug.info("/sm/deletUser")
-    user = data['user']
+    try:
-    day = data['day']
+        data = request.get_json()
-    month = data['month']
+        user = data['user']
-    year = data['year']
+        day = data['day']
-    date = datetime(year, month, day, 12)
+        month = data['month']
-    userController.deleteWorker(user['username'], date)
+        year = data['year']
-    return jsonify({"ok": "ok"})
+        date = datetime(year, month, day, 12)
+        userController.deleteWorker(user['username'], date)
+        debug.debug("return ok")
+        user = userController.getUser(user['username'])
+        jobL.info("Vorstand {} {} entfernt Mitglied {} {} am {} vom Dienst".format(
+            kwargs['accToken'].user.firstname, kwargs['accToken'].user.lastname, user.firstname, user.lastname, date.date()))
+        return jsonify({"ok": "ok"})
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500
+
 
 @vorstand.route("/sm/lockDay", methods=['POST'])
 @login_required(groups=[MONEY, GASTRO, VORSTAND])
 def _lockDay(**kwargs):
+    debug.info("/sm/lockDay")
     try:
         data = request.get_json()
         year = data['year']
@@ -157,13 +203,21 @@ def _lockDay(**kwargs):
                 },
                 'locked': lockedDay['locked']
             }
-        print(retVal)
+        debug.debug("return {{ {} }}".format(retVal))
         return jsonify(retVal)
     except Exception as err:
+        debug.debug("exception", exc_info=True)
         return jsonify({'error': err}), 409
 
+
 @vorstand.route("/sm/searchWithExtern", methods=['GET'])
 @login_required(groups=[VORSTAND])
 def _search(**kwargs):
-    retVal = ldap.getAllUser()
+    debug.info("/sm/searchWithExtern")
-    return jsonify(retVal)
+    try:
+        retVal = ldap.getAllUser()
+        debug.debug("return {{ {} }}".format(retVal))
+        return jsonify(retVal)
+    except Exception as err:
+        debug.debug("exception", exc_info=True)
+        return jsonify({"error": str(err)}), 500