From 95998e1ff90aaf1066c08478f5906ae4a1e31043 Mon Sep 17 00:00:00 2001 From: Sami Mokaddem Date: Tue, 2 Jul 2024 13:46:15 +0200 Subject: [PATCH] new: [backend] Added logger --- config.py | 13 ++++++++++++- exercise.py | 24 +++++++++++++----------- inject_evaluator.py | 3 ++- misp_api.py | 6 +++--- server.py | 14 +++++++------- 5 files changed, 37 insertions(+), 23 deletions(-) diff --git a/config.py b/config.py index e64f50f..e146b45 100644 --- a/config.py +++ b/config.py @@ -11,4 +11,15 @@ live_logs_accepted_scope = { 'events': ['add', 'edit', 'delete', 'restSearch',], 'attributes': ['add', 'edit', 'delete', 'restSearch',], 'tags': '*', -} \ No newline at end of file +} + +import logging +logger = logging.getLogger('misp-exercise-dashboard') +format = '[%(levelname)s] %(asctime)s - %(message)s' +formatter = logging.Formatter(format) +logging.basicConfig(filename='misp-exercise-dashboard.log', encoding='utf-8', level=logging.DEBUG, format=format) +# create console handler and set level to debug +ch = logging.StreamHandler() +ch.setLevel(logging.INFO) +ch.setFormatter(formatter) +logger.addHandler(ch) diff --git a/exercise.py b/exercise.py index bbb030e..51fed0d 100644 --- a/exercise.py +++ b/exercise.py @@ -1,6 +1,5 @@ #!/usr/bin/env python3 - import functools import time from collections import defaultdict @@ -9,10 +8,13 @@ import json import re from typing import Union import jq + import db from inject_evaluator import eval_data_filtering, eval_query_comparison import misp_api import config +from config import logger + ACTIVE_EXERCISES_DIR = "active_exercises" @@ -31,7 +33,7 @@ def debounce_check_active_tasks(debounce_seconds: int = 1): func_last_execution_time[key] = now return func(*args, **kwargs) else: - print(f">> Debounced for `{user_id}`") + logger.debug(f">> Debounced for `{user_id}`") return None return wrapper return decorator @@ -40,7 +42,7 @@ def debounce_check_active_tasks(debounce_seconds: int = 1): def load_exercises() -> bool: db.ALL_EXERCISES = read_exercise_dir() if not is_validate_exercises(db.ALL_EXERCISES): - print('Issue while validating exercises') + logger.error('Issue while validating exercises') return False init_inject_flow() init_exercises_tasks() @@ -67,14 +69,14 @@ def is_validate_exercises(exercises: list) -> bool: for exercise in exercises: e_uuid = exercise['exercise']['uuid'] if e_uuid in exercises_uuid: - print(f"Duplicated UUID {e_uuid}. ({exercise['exercise']['name']}, {exercise_by_uuid[e_uuid]['exercise']['name']})") + logger.error(f"Duplicated UUID {e_uuid}. ({exercise['exercise']['name']}, {exercise_by_uuid[e_uuid]['exercise']['name']})") return False exercises_uuid.add(e_uuid) exercise_by_uuid[e_uuid] = exercise for inject in exercise['injects']: t_uuid = inject['uuid'] if t_uuid in tasks_uuid: - print(f"Duplicated UUID {t_uuid}. ({inject['name']}, {task_by_uuid[t_uuid]['name']})") + logger.error(f"Duplicated UUID {t_uuid}. ({inject['name']}, {task_by_uuid[t_uuid]['name']})") return False tasks_uuid.add(t_uuid) task_by_uuid[t_uuid] = inject @@ -86,7 +88,7 @@ def is_validate_exercises(exercises: list) -> bool: try: jq.compile(jq_path) except ValueError as e: - print(f"[{t_uuid} :: {inject['name']}] Could not compile jq path `{jq_path}`\n", e) + logger.error(f"[{t_uuid} :: {inject['name']}] Could not compile jq path `{jq_path}`\n", e) return False return True @@ -298,7 +300,7 @@ def check_inject(user_id: int, inject: dict, data: dict, context: dict) -> bool: if not success: return False mark_task_completed(user_id, inject['exercise_uuid'], inject['uuid']) - print(f"Task success: {inject['uuid']}") + logger.info(f"Task success: {inject['uuid']}") return True @@ -310,10 +312,10 @@ def is_valid_evaluation_context(user_id: int, inject_evaluation: dict, data: dic if inject_evaluation['evaluation_context']['request_is_rest'] == context['request_is_rest']: return True else: - print('Request type does not match state of `request_is_rest`') + logger.debug('Request type does not match state of `request_is_rest`') return False else: - print('Unknown request type') + logger.debug('Unknown request type') return False return False @@ -326,7 +328,7 @@ def inject_checker_router(user_id: int, inject_evaluation: dict, data: dict, con data_to_validate = get_data_to_validate(user_id, inject_evaluation, data) if data_to_validate is None: - print('Could not fetch data to validate') + logger.debug('Could not fetch data to validate') return False if inject_evaluation['evaluation_strategy'] == 'data_filtering': @@ -425,7 +427,7 @@ def check_active_tasks(user_id: int, data: dict, context: dict) -> bool: inject = db.INJECT_BY_UUID[task_uuid] if inject['exercise_uuid'] not in db.SELECTED_EXERCISES: continue - print(f"[{task_uuid}] :: checking: {inject['name']}") + logger.debug(f"[{task_uuid}] :: checking: {inject['name']}") completed = check_inject(user_id, inject, data, context) if completed: succeeded_once = True diff --git a/inject_evaluator.py b/inject_evaluator.py index e336c7d..10a2f26 100644 --- a/inject_evaluator.py +++ b/inject_evaluator.py @@ -3,6 +3,7 @@ from typing import Union import jq import re import operator +from config import logger # .Event.Attribute[] | select(.value == "evil.exe") | .Tag @@ -133,7 +134,7 @@ def eval_data_filtering(user_id: int, inject_evaluation: dict, data: dict) -> bo for evaluation_path, evaluation_config in evaluation_params.items(): data_to_validate = jq_extract(evaluation_path, data, evaluation_config.get('extract_type', 'first')) if data_to_validate is None: - print('Could not extract data') + logger.debug('Could not extract data') return False if not condition_satisfied(evaluation_config, data_to_validate): return False diff --git a/misp_api.py b/misp_api.py index e7f4a18..79b8e5f 100644 --- a/misp_api.py +++ b/misp_api.py @@ -10,7 +10,7 @@ from requests_cache import CachedSession from requests.packages.urllib3.exceptions import InsecureRequestWarning # type: ignore requests.packages.urllib3.disable_warnings(InsecureRequestWarning) -from config import misp_url, misp_apikey, misp_skipssl +from config import misp_url, misp_apikey, misp_skipssl, logger requestSession = CachedSession(cache_name='misp_cache', expire_after=timedelta(seconds=5)) adapterCache = requests.adapters.HTTPAdapter(pool_connections=50, pool_maxsize=50) @@ -29,7 +29,7 @@ def get(url, data={}, api_key=misp_apikey): try: response = requestSession.get(full_url, data=data, headers=headers, verify=not misp_skipssl) except requests.exceptions.ConnectionError as e: - print('Could not perform request on MISP.', e) + logger.info('Could not perform request on MISP.', e) return None return response.json() if response.headers['content-type'].startswith('application/json') else response.text @@ -45,7 +45,7 @@ def post(url, data={}, api_key=misp_apikey): try: response = requestSession.post(full_url, data=json.dumps(data), headers=headers, verify=not misp_skipssl) except requests.exceptions.ConnectionError as e: - print('Could not perform request on MISP.', e) + logger.info('Could not perform request on MISP.', e) return None return response.json() if response.headers['content-type'].startswith('application/json') else response.text diff --git a/server.py b/server.py index 1ff756c..0b1c942 100755 --- a/server.py +++ b/server.py @@ -14,6 +14,7 @@ import exercise as exercise_model import notification as notification_model import db import config +from config import logger import misp_api @@ -57,11 +58,11 @@ app = socketio.WSGIApp(sio, static_files={ @sio.event def connect(sid, environ): - print("Client connected: ", sid) + logger.debug("Client connected: " + sid) @sio.event def disconnect(sid): - print("Client disconnected: ", sid) + logger.debug("Client disconnected: " + sid) @sio.event def get_exercises(sid): @@ -109,7 +110,7 @@ def toggle_verbose_mode(sid, payload): @sio.on('*') def any_event(event, sid, data={}): - print('>> Unhandled event', event) + logger.info('>> Unhandled event', event) def handleMessage(topic, s, message): data = json.loads(message) @@ -180,19 +181,18 @@ def forward_zmq_to_socketio(): while True: message = zsocket.recv_string() topic, s, m = message.partition(" ") - handleMessage(topic, s, m) try: ZMQ_MESSAGE_COUNT += 1 - # handleMessage(topic, s, m) + handleMessage(topic, s, m) except Exception as e: - print('Error handling message', e) + logger.error('Error handling message', e) if __name__ == "__main__": exercises_loaded = exercise_model.load_exercises() if not exercises_loaded: - print('Could not load exercises') + logger.critical('Could not load exercises') sys.exit(1) # Start the forwarding in a separate thread