chg: [logs] add access logs

bin/lib/ail_logger.py

@@ -5,6 +5,7 @@ import os
 import json
 import sys
 import logging
+import logging.handlers
 
 sys.path.append(os.environ['AIL_BIN'])
 ##################################
@@ -16,14 +17,37 @@ config_loader = ConfigLoader()
 r_db = config_loader.get_db_conn("Kvrocks_DB")
 config_loader = None
 
-LOGGING_CONFIG = os.path.join(os.environ['AIL_HOME'], 'configs', 'logging.json')
+LOGGING_CONF_DIR = os.path.join(os.environ['AIL_HOME'], 'configs')
+LOGS_DIR = os.path.join(os.environ['AIL_HOME'], 'logs')
 
 def get_config(name=None):
     if not name:
         name = 'ail.log'
     else:
         name = f'{name}.log'
-    with open(LOGGING_CONFIG, 'r') as f:
+    with open(os.path.join(LOGGING_CONF_DIR, f'logging.json'), 'r') as f:
         config = json.load(f)
-        config['handlers']['file']['filename'] = os.path.join(os.environ['AIL_HOME'], 'logs', name)
+        config['handlers']['file']['filename'] = os.path.join(LOGS_DIR, name)
     return config
+
+def get_access_config(create=False):
+    logger = logging.getLogger('access.log')
+
+    if create:
+        formatter = logging.Formatter('%(asctime)s - %(ip_address)s - %(levelname)s - %(user_id)s - %(message)s')
+
+        # STDOUT
+        handler = logging.StreamHandler()
+        handler.setLevel(logging.INFO)
+        handler.setFormatter(formatter)
+        logger.addHandler(handler)
+
+        # FILE
+        handler = logging.handlers.RotatingFileHandler(filename=os.path.join(LOGS_DIR, f'access.log'),
+                                                       maxBytes=10*1024*1024, backupCount=5)
+        handler.setLevel(logging.INFO)
+        handler.setFormatter(formatter)
+        logger.addHandler(handler)
+
+        logger.propagate = False
+    return logger

bin/lib/ail_users.py

@@ -7,7 +7,6 @@ import pyotp
 import re
 import secrets
 import sys
-
 import segno
 
 from base64 import b64encode
@@ -20,8 +19,13 @@ sys.path.append(os.environ['AIL_BIN'])
 ##################################
 # Import Project packages
 ##################################
+from lib import ail_logger
 from lib.ConfigLoader import ConfigLoader
 
+# LOGS
+
+access_logger = ail_logger.get_access_config()
+
 # Config
 config_loader = ConfigLoader()
 r_serv_db = config_loader.get_db_conn("Kvrocks_DB")
@@ -295,7 +299,7 @@ def disable_user(user_id):
 def enable_user(user_id):
     r_serv_db.srem(f'ail:users:disabled', user_id)
 
-def create_user(user_id, password=None, admin_id=None, chg_passwd=True, role=None, otp=False):  # TODO LOGS
+def create_user(user_id, password=None, admin_id=None, chg_passwd=True, role=None, otp=False):
     # # TODO: check password strength
     if password:
         new_password = password
@@ -568,15 +572,15 @@ def api_get_user_hotp(user_id):
     hotp = get_user_hotp_code(user_id)
     return hotp, 200
 
-def api_logout_user(admin_id, user_id): # TODO LOG ADMIN ID
+def api_logout_user(admin_id, user_id, ip_address):
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
-    print(admin_id)
+    access_logger.info(f'Logout user {user_id}', extra={'user_id': admin_id, 'ip_address': ip_address})
     return user.kill_session(), 200
 
-def api_logout_users(admin_id): # TODO LOG ADMIN ID
+def api_logout_users(admin_id, ip_address):
-    print(admin_id)
+    access_logger.info('Logout all users', extra={'user_id': admin_id, 'ip_address': ip_address})
     return kill_sessions(), 200
 
 def api_disable_user(admin_id, user_id): # TODO LOG ADMIN ID
@@ -597,7 +601,7 @@ def api_enable_user(admin_id, user_id): # TODO LOG ADMIN ID
     print(admin_id)
     enable_user(user_id)
 
-def api_enable_user_otp(user_id):
+def api_enable_user_otp(user_id, ip_address):
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
@@ -607,7 +611,7 @@ def api_enable_user_otp(user_id):
     enable_user_2fa(user_id)
     return user_id, 200
 
-def api_disable_user_otp(user_id):
+def api_disable_user_otp(user_id, ip_address):
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
@@ -619,7 +623,7 @@ def api_disable_user_otp(user_id):
     delete_user_otp(user_id)
     return user_id, 200
 
-def api_reset_user_otp(admin_id, user_id):
+def api_reset_user_otp(admin_id, user_id, ip_address): # TODO LOGS
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
@@ -632,24 +636,29 @@ def api_reset_user_otp(admin_id, user_id):
     enable_user_2fa(user_id)
     return user_id, 200
 
-def api_create_user_api_key_self(user_id): # TODO LOG USER ID
+def api_create_user_api_key_self(user_id, ip_address):
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
+    access_logger.info('New api key', extra={'user_id': user_id, 'ip_address': ip_address})
     return user.new_api_key(), 200
 
-def api_create_user_api_key(user_id, admin_id): # TODO LOG ADMIN ID
+def api_create_user_api_key(user_id, admin_id, ip_address):
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
-    print(admin_id)
+    access_logger.info(f'New api key for user {user_id}', extra={'user_id': admin_id, 'ip_address': ip_address})
     return user.new_api_key(), 200
 
-def api_delete_user(user_id, admin_id): # TODO LOG ADMIN ID
+def api_create_user(admin_id, ip_address, user_id, password, role, otp):
+    create_user(user_id, password=password, admin_id=admin_id, role=role, otp=otp)
+    access_logger.info(f'Create user {user_id}', extra={'user_id': admin_id, 'ip_address': ip_address})
+
+def api_delete_user(user_id, admin_id, ip_address):
     user = AILUser(user_id)
     if not user.exists():
         return {'status': 'error', 'reason': 'User not found'}, 404
-    print(admin_id)
+    access_logger.info(f'Delete user {user_id}', extra={'user_id': admin_id, 'ip_address': ip_address})
     return user.delete(), 200
 
 ########################################################################################################################

var/www/Flask_server.py

@@ -83,6 +83,8 @@ if not os.path.isdir(log_dir):
 
 # ========= LOGS =========#
 
+access_logger = ail_logger.get_access_config(create=True)
+
 class FilterLogErrors(logging.Filter):
     def filter(self, record):
         # print(dict(record.__dict__))

var/www/blueprints/root.py

@@ -24,6 +24,7 @@ sys.path.append(os.environ['AIL_BIN'])
 ##################################
 from lib.ail_users import AILUser, kill_sessions, create_user, check_password_strength, check_user_role_integrity
 from lib.ConfigLoader import ConfigLoader
+from lib import ail_logger
 
 
 # Config
@@ -34,6 +35,9 @@ config_loader = None
 # Kill previous sessions
 kill_sessions()
 
+# LOGS
+access_logger = ail_logger.get_access_config()
+
 
 # ============ BLUEPRINT ============
 
@@ -56,6 +60,10 @@ def login():
         login_failed_ip = int(login_failed_ip)
         if login_failed_ip >= 5:
             wait_time = r_cache.ttl(f'failed_login_ip:{current_ip}')
+            username = request.form.get('username')
+            if not username:
+                username = ''
+            access_logger.warning(f'Brute Force', extra={'user_id': username, 'ip_address': current_ip})
             logging_error = f'Max Connection Attempts reached, Please wait {wait_time}s'
             return render_template("login.html", error=logging_error)
 
@@ -68,7 +76,7 @@ def login():
             return render_template("login.html", error='Password is required.')
 
         if username is not None:
-            user = AILUser.get(username)  # TODO ANONYMOUS USER
+            user = AILUser.get(username)
 
             # brute force by user_id
             login_failed_user_id = r_cache.get(f'failed_login_user_id:{username}')
@@ -76,12 +84,14 @@ def login():
                 login_failed_user_id = int(login_failed_user_id)
                 if login_failed_user_id >= 5:
                     wait_time = r_cache.ttl(f'failed_login_user_id:{username}')
+                    access_logger.warning(f'Max login attempts reached', extra={'user_id': user.get_user_id(), 'ip_address': current_ip})
                     logging_error = f'Max Connection Attempts reached, Please wait {wait_time}s'
                     return render_template("login.html", error=logging_error)
 
             if user.exists() and user.check_password(password):
                 if not check_user_role_integrity(user.get_user_id()):
                     logging_error = 'Incorrect User ACL, Please contact your administrator'
+                    access_logger.info(f'Login fail: Invalid ACL', extra={'user_id': user.get_user_id(), 'ip_address': current_ip})
                     return render_template("login.html", error=logging_error)
 
                 if user.is_2fa_enabled():
@@ -92,6 +102,7 @@ def login():
                     if not user.is_2fa_setup():
                         return redirect(url_for('root.setup_2fa'))
                     else:
+                        access_logger.info(f'First Login', extra={'user_id': user.get_user_id(), 'ip_address': current_ip})
                         if next_page and next_page != 'None' and next_page != '/':
                             return redirect(url_for('root.verify_2fa', next=next_page))
                         else:
@@ -102,6 +113,7 @@ def login():
                     user.rotate_session()
                     login_user(user)
                     user.update_last_login()
+                    access_logger.info(f'Login', extra={'user_id': user.get_user_id(), 'ip_address': current_ip})
 
                     if user.request_password_change():
                         return redirect(url_for('root.change_password'))
@@ -124,6 +136,8 @@ def login():
                 r_cache.expire(f'failed_login_user_id:{username}', 300)
                 #
 
+                access_logger.info(f'Login Failed', extra={'user_id': user.get_user_id(), 'ip_address': request.remote_addr})
+
                 logging_error = 'Login/Password Incorrect'
                 return render_template("login.html", error=logging_error)
 
@@ -150,6 +164,7 @@ def verify_2fa():
     if otp_expire < int(time.time()):  # TODO LOG
         session.pop('user_id', None)
         session.pop('otp_expire', None)
+        access_logger.info(f'First Login Expired', extra={'user_id': user_id, 'ip_address': request.remote_addr})
         error = "First Login Expired"
         return redirect(url_for('root.login', error=error))
 
@@ -171,6 +186,8 @@ def verify_2fa():
             login_user(user)
             user.update_last_login()
 
+            access_logger.info(f'2FA login', extra={'user_id': user.get_user_id(), 'ip_address': request.remote_addr})
+
             if user.request_password_change():
                 return redirect(url_for('root.change_password'))
             else:
@@ -180,6 +197,7 @@ def verify_2fa():
                 return redirect(url_for('dashboard.index'))
         else:
             htop_counter = user.get_htop_counter()
+            access_logger.info(f'Invalid OTP', extra={'user_id': user.get_user_id(), 'ip_address': request.remote_addr})
             error = "The OTP is incorrect or has expired"
             return render_template("verify_otp.html", htop_counter=htop_counter, next_page=next_page, error=error)
 
@@ -200,6 +218,7 @@ def setup_2fa():
     if otp_expire < int(time.time()):  # TODO LOG
         session.pop('user_id', None)
         session.pop('otp_expire', None)
+        access_logger.info(f'First Login Expired', extra={'user_id': user_id, 'ip_address': request.remote_addr})
         error = "First Login Expired"
         return redirect(url_for('root.login', error=error))
 
@@ -222,11 +241,14 @@ def setup_2fa():
             login_user(user)
             user.update_last_login()
 
+            access_logger.info(f'2FA login', extra={'user_id': user.get_user_id(), 'ip_address': request.remote_addr})
+
             if user.request_password_change():
                 return redirect(url_for('root.change_password'))
             else:
                 return redirect(url_for('dashboard.index'))
         else:
+            access_logger.info(f'OTP Invalid', extra={'user_id': user.get_user_id(), 'ip_address': request.remote_addr})
             error = "The OTP is incorrect or has expired"
             return redirect(url_for('root.setup_2fa', error=error))
     else:
@@ -252,6 +274,7 @@ def change_password():
             if check_password_strength(password1):
                 user_id = current_user.get_user_id()
                 create_user(user_id, password=password1, chg_passwd=False) # TODO RENAME ME
+                access_logger.info(f'Password change', extra={'user_id': user_id, 'ip_address': request.remote_addr})
                 # update Note
                 # dashboard
                 return redirect(url_for('dashboard.index', update_note=True))
@@ -268,6 +291,7 @@ def change_password():
 @root.route('/logout')
 @login_required
 def logout():
+    access_logger.info(f'Logout', extra={'user_id': current_user.get_user_id(), 'ip_address': request.remote_addr})
     current_user.kill_session()
     logout_user()
     return redirect(url_for('root.login'))

var/www/blueprints/settings_b.py

@@ -92,7 +92,7 @@ def user_hotp():
 @login_read_only
 def user_otp_enable_self():
     user_id = current_user.get_user_id()
-    r = ail_users.api_enable_user_otp(user_id)
+    r = ail_users.api_enable_user_otp(user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     current_user.kill_session()
@@ -103,7 +103,7 @@ def user_otp_enable_self():
 @login_read_only
 def user_otp_disable_self():
     user_id = current_user.get_user_id()
-    r = ail_users.api_disable_user_otp(user_id)
+    r = ail_users.api_disable_user_otp(user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     current_user.kill_session()
@@ -114,7 +114,7 @@ def user_otp_disable_self():
 @login_admin
 def user_otp_reset_self():  # TODO ask for password ?
     user_id = current_user.get_user_id()
-    r = ail_users.api_reset_user_otp(user_id, user_id)
+    r = ail_users.api_reset_user_otp(user_id, user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else:
@@ -126,7 +126,7 @@ def user_otp_reset_self():  # TODO ask for password ?
 @login_admin
 def user_otp_enable():
     user_id = request.args.get('user_id')
-    r = ail_users.api_enable_user_otp(user_id)
+    r = ail_users.api_enable_user_otp(user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     user = ail_users.AILUser.get(user_id)
@@ -138,7 +138,7 @@ def user_otp_enable():
 @login_admin
 def user_otp_disable():
     user_id = request.args.get('user_id')
-    r = ail_users.api_disable_user_otp(user_id)
+    r = ail_users.api_disable_user_otp(user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     user = ail_users.AILUser.get(user_id)
@@ -151,7 +151,7 @@ def user_otp_disable():
 def user_otp_reset():  # TODO ask for password ?
     user_id = request.args.get('user_id')
     admin_id = current_user.get_user_id()
-    r = ail_users.api_reset_user_otp(admin_id, user_id)
+    r = ail_users.api_reset_user_otp(admin_id, user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else:
@@ -164,7 +164,7 @@ def user_otp_reset():  # TODO ask for password ?
 @login_read_only
 def new_token_user_self():
     user_id = current_user.get_user_id()
-    r = ail_users.api_create_user_api_key_self(user_id)
+    r = ail_users.api_create_user_api_key_self(user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else:
@@ -176,7 +176,7 @@ def new_token_user_self():
 def new_token_user():
     user_id = request.args.get('user_id')
     admin_id = current_user.get_user_id()
-    r = ail_users.api_create_user_api_key(user_id, admin_id)
+    r = ail_users.api_create_user_api_key(user_id, admin_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else:
@@ -188,7 +188,7 @@ def new_token_user():
 def user_logout():
     user_id = request.args.get('user_id') # TODO LOGS
     admin_id = current_user.get_user_id()
-    r = ail_users.api_logout_user(admin_id, user_id)
+    r = ail_users.api_logout_user(admin_id, user_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else:
@@ -199,7 +199,7 @@ def user_logout():
 @login_admin
 def users_logout():
     admin_id = current_user.get_user_id() # TODO LOGS
-    r = ail_users.api_logout_users(admin_id)
+    r = ail_users.api_logout_users(admin_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else:
@@ -271,7 +271,7 @@ def create_user_post():
                     if not password1 and not password2:
                         password = None
                         str_password = 'Password not changed'
-                ail_users.create_user(email, password=password, admin_id=admin_id, role=role, otp=enable_2_fa)
+                ail_users.api_create_user(admin_id, request.remote_addr, email, password, role, enable_2_fa)
                 new_user = {'email': email, 'password': str_password, 'otp': enable_2_fa}
                 return render_template("create_user.html", new_user=new_user, meta={}, all_roles=all_roles, acl_admin=True)
 
@@ -288,7 +288,7 @@ def create_user_post():
 def delete_user():
     user_id = request.args.get('user_id')
     admin_id = current_user.get_user_id()
-    r = ail_users.api_delete_user(user_id, admin_id)
+    r = ail_users.api_delete_user(user_id, admin_id, request.remote_addr)
     if r[1] != 200:
         return create_json_response(r[0], r[1])
     else: